search

ovn-org / ovn-kubernetes

A robust Kubernetes networking platform
https://ovn-kubernetes.io/
Apache License 2.0
815 stars 338 forks source link

Race detected in `Hybrid Overlay Node Linux Operations`: `updates itself, windows tunnel and pod flows when distributed router MAC is updated` #3924

Closed martinkennelly closed 11 months ago

martinkennelly commented 12 months ago

See on PR #3913 

2023-09-24T13:19:41.2583348Z Hybrid Overlay Node Linux Operations 
2023-09-24T13:19:41.2584060Z   node updates itself, windows tunnel and pod flows when distributed router MAC is updated
2023-09-24T13:19:41.2584857Z   /home/runner/work/ovn-kubernetes/ovn-kubernetes/go-controller/pkg/testing/testing.go:18
2023-09-24T13:19:41.2667808Z I0924 13:19:41.265605   26813 config.go:2246] Default config: {MTU:1400 RoutableMTU:0 ConntrackZone:64000 EncapType:geneve EncapIP: EncapPort:6081 InactivityProbe:100000 OpenFlowProbe:180 OfctrlWaitBeforeClear:0 MonitorAll:true LFlowCacheEnable:true LFlowCacheLimit:0 LFlowCacheLimitKb:0 RawClusterSubnets:10.130.0.0/15/24 ClusterSubnets:[10.130.0.0/15/24] EnableUDPAggregation:false Zone:global}
2023-09-24T13:19:41.2669555Z I0924 13:19:41.265695   26813 config.go:2247] Logging config: {File: CNIFile:/var/log/ovn-kubernetes/ovn-k8s-cni-overlay.log LibovsdbFile: Level:5 LogFileMaxSize:100 LogFileMaxBackups:5 LogFileMaxAge:5 ACLLoggingRateLimit:20}
2023-09-24T13:19:41.2670509Z I0924 13:19:41.265827   26813 config.go:2248] Monitoring config: {RawNetFlowTargets: RawSFlowTargets: RawIPFIXTargets: NetFlowTargets:[] SFlowTargets:[] IPFIXTargets:[]}
2023-09-24T13:19:41.2671235Z I0924 13:19:41.265863   26813 config.go:2249] IPFIX config: {Sampling:400 CacheActiveTimeout:60 CacheMaxFlows:0}
2023-09-24T13:19:41.2672249Z I0924 13:19:41.265894   26813 config.go:2250] CNI config: {ConfDir:/etc/cni/net.d Plugin:ovn-k8s-cni-overlay}
2023-09-24T13:19:41.2674959Z I0924 13:19:41.265923   26813 config.go:2251] Kubernetes config: {BootstrapKubeconfig: CertDir: CertDuration:10m0s Kubeconfig: CACert: CAData:[] APIServer:http://localhost:8443 Token: TokenFile: CompatServiceCIDR: RawServiceCIDRs:172.16.1.0/24 ServiceCIDRs:[172.16.1.0/24] OVNConfigNamespace:ovn-kubernetes OVNEmptyLbEvents:false PodIP: RawNoHostSubnetNodes:kubernetes.io/os=windows NoHostSubnetNodes:&LabelSelector{MatchLabels:map[string]string{kubernetes.io/os: windows,},MatchExpressions:[]LabelSelectorRequirement{},} HostNetworkNamespace: PlatformType: HealthzBindAddress: CompatMetricsBindAddress: CompatOVNMetricsBindAddress: CompatMetricsEnablePprof:false DNSServiceNamespace:kube-system DNSServiceName:kube-dns}
2023-09-24T13:19:41.2678331Z I0924 13:19:41.266014   26813 config.go:2252] Gateway config: {Mode: Interface: EgressGWInterface: NextHop: VLANID:0 NodeportEnable:false DisableSNATMultipleGWs:false V4JoinSubnet:100.64.0.0/16 V6JoinSubnet:fd98::/64 V4MasqueradeSubnet:169.254.169.0/29 V6MasqueradeSubnet:fd69::/125 MasqueradeIPs:{V4OVNMasqueradeIP:169.254.169.1 V6OVNMasqueradeIP:fd69::1 V4HostMasqueradeIP:169.254.169.2 V6HostMasqueradeIP:fd69::2 V4HostETPLocalMasqueradeIP:169.254.169.3 V6HostETPLocalMasqueradeIP:fd69::3 V4DummyNextHopMasqueradeIP:169.254.169.4 V6DummyNextHopMasqueradeIP:fd69::4 V4OVNServiceHairpinMasqueradeIP:169.254.169.5 V6OVNServiceHairpinMasqueradeIP:fd69::5} DisablePacketMTUCheck:false RouterSubnet: SingleNode:false DisableForwarding:false AllowNoUplink:false}
2023-09-24T13:19:41.2680246Z I0924 13:19:41.266094   26813 config.go:2253] OVN North config: {Address:unix:/var/run/ovn/ovnnb_db.sock PrivKey: Cert: CACert: CertCommonName: Scheme:unix ElectionTimer:0 northbound:true exec:0xc0002e0300}
2023-09-24T13:19:41.2681146Z I0924 13:19:41.266136   26813 config.go:2254] OVN South config: {Address:unix:/var/run/ovn/ovnsb_db.sock PrivKey: Cert: CACert: CertCommonName: Scheme:unix ElectionTimer:0 northbound:false exec:0xc0002e0300}
2023-09-24T13:19:41.2691871Z I0924 13:19:41.266175   26813 config.go:2255] Hybrid Overlay config: {Enabled:true RawClusterSubnets:10.0.0.1/16/23 ClusterSubnets:[10.0.0.0/16/23] VXLANPort:4789}
2023-09-24T13:19:41.2692701Z I0924 13:19:41.266215   26813 config.go:2256] Ovnkube Node config: {Mode:full DPResourceDeviceIdsMap:map[] MgmtPortNetdev: MgmtPortDPResourceName:}
2023-09-24T13:19:41.2693510Z I0924 13:19:41.266249   26813 config.go:2257] Ovnkube Cluster Manager config: {V4TransitSwitchSubnet:168.254.0.0/16 V6TransitSwitchSubnet:fd97::/64}
2023-09-24T13:19:41.2697849Z I0924 13:19:41.268290   26813 reflector.go:287] Starting reflector *v1.Pod (0s) from k8s.io/client-go/informers/factory.go:150
2023-09-24T13:19:41.2698698Z I0924 13:19:41.268299   26813 reflector.go:287] Starting reflector *v1.Node (0s) from k8s.io/client-go/informers/factory.go:150
2023-09-24T13:19:41.2699497Z I0924 13:19:41.268322   26813 reflector.go:323] Listing and watching *v1.Pod from k8s.io/client-go/informers/factory.go:150
2023-09-24T13:19:41.2700332Z I0924 13:19:41.268335   26813 reflector.go:323] Listing and watching *v1.Node from k8s.io/client-go/informers/factory.go:150
2023-09-24T13:19:41.2700893Z I0924 13:19:41.268379   26813 node.go:161] Starting Hybrid Overlay Node Controller
2023-09-24T13:19:41.2701371Z I0924 13:19:41.268403   26813 node.go:165] Starting Hybrid Overlay Node workers
2023-09-24T13:19:41.2701840Z I0924 13:19:41.268461   26813 node.go:189] Started Hybrid Overlay Node workers
2023-09-24T13:19:41.2702350Z I0924 13:19:41.268490   26813 ovn_node_linux.go:650] Starting hybrid overlay OpenFlow sync thread
2023-09-24T13:19:41.2702863Z I0924 13:19:41.268506   26813 ovn_node_linux.go:651] Running initial OpenFlow sync
2023-09-24T13:19:41.2703527Z I0924 13:19:41.268544   26813 ovs.go:164] Exec(63): /fake-bin/ovs-ofctl dump-flows --no-stats br-ext table=20
2023-09-24T13:19:41.2703997Z I0924 13:19:41.268583   26813 ovs.go:167] Exec(63): stdout: ""
2023-09-24T13:19:41.2704575Z I0924 13:19:41.268617   26813 ovs.go:168] Exec(63): stderr: ""
2023-09-24T13:19:41.2705248Z I0924 13:19:41.268665   26813 ovs.go:164] Exec(64): /fake-bin/ovs-ofctl -O OpenFlow13 --bundle replace-flows br-ext -
2023-09-24T13:19:41.2705726Z I0924 13:19:41.268694   26813 ovs.go:167] Exec(64): stdout: ""
2023-09-24T13:19:41.2706210Z I0924 13:19:41.268718   26813 ovs.go:168] Exec(64): stderr: ""
2023-09-24T13:19:41.2706639Z I0924 13:19:41.268697   26813 informer.go:203] Starting node informer queue
2023-09-24T13:19:41.2707116Z I0924 13:19:41.268755   26813 informer.go:205] Waiting for node informer caches to sync
2023-09-24T13:19:41.2707592Z I0924 13:19:41.268787   26813 shared_informer.go:341] caches populated
2023-09-24T13:19:41.2708047Z I0924 13:19:41.268803   26813 informer.go:211] Starting 10 node queue workers
2023-09-24T13:19:41.2708502Z I0924 13:19:41.268851   26813 informer.go:222] Started node queue workers
2023-09-24T13:19:41.2708929Z I0924 13:19:41.268861   26813 ovn_node_linux.go:227] Add Node mynode
2023-09-24T13:19:41.2709377Z I0924 13:19:41.268942   26813 informer.go:203] Starting pod informer queue
2023-09-24T13:19:41.2709959Z I0924 13:19:41.268962   26813 informer.go:205] Waiting for pod informer caches to sync
2023-09-24T13:19:41.2710429Z I0924 13:19:41.268987   26813 shared_informer.go:341] caches populated
2023-09-24T13:19:41.2711153Z I0924 13:19:41.268995   26813 ovs.go:164] Exec(65): /fake-bin/ovn-nbctl --timeout=15 get logical_switch mynode other-config:subnet
2023-09-24T13:19:41.2711670Z I0924 13:19:41.269034   26813 ovs.go:167] Exec(65): stdout: "1.2.3.0/24"
2023-09-24T13:19:41.2712070Z I0924 13:19:41.269059   26813 ovs.go:168] Exec(65): stderr: ""
2023-09-24T13:19:41.2713450Z I0924 13:19:41.269089   26813 ovn_node_linux.go:321] Found node mynode subnet 1.2.3.0/24
2023-09-24T13:19:41.2715153Z I0924 13:19:41.269141   26813 ovs.go:164] Exec(66): /fake-bin/ovs-vsctl --timeout=15 --may-exist add-br br-ext -- set Bridge br-ext fail_mode=secure -- set Interface br-ext mtu_request=1400
2023-09-24T13:19:41.2715751Z I0924 13:19:41.269161   26813 ovs.go:167] Exec(66): stdout: ""
2023-09-24T13:19:41.2716249Z I0924 13:19:41.269178   26813 ovs.go:168] Exec(66): stderr: ""
2023-09-24T13:19:41.2716692Z I0924 13:19:41.269002   26813 informer.go:211] Starting 1 pod queue workers
2023-09-24T13:19:41.2717156Z I0924 13:19:41.269428   26813 informer.go:222] Started pod queue workers
2023-09-24T13:19:41.2718511Z I0924 13:19:41.271220   26813 ovs.go:164] Exec(67): /fake-bin/ovs-vsctl --timeout=15 --if-exists get interface br-ext mac_in_use
2023-09-24T13:19:41.2719013Z I0924 13:19:41.271265   26813 ovs.go:167] Exec(67): stdout: "10:11:12:13:14:15"
2023-09-24T13:19:41.2719423Z I0924 13:19:41.271292   26813 ovs.go:168] Exec(67): stderr: ""
2023-09-24T13:19:41.2720142Z I0924 13:19:41.271334   26813 ovs.go:164] Exec(68): /fake-bin/ovs-vsctl --timeout=15 set bridge br-ext other-config:hwaddr=10:11:12:13:14:15
2023-09-24T13:19:41.2720640Z I0924 13:19:41.271358   26813 ovs.go:167] Exec(68): stdout: ""
2023-09-24T13:19:41.2721017Z I0924 13:19:41.271377   26813 ovs.go:168] Exec(68): stderr: ""
2023-09-24T13:19:41.2730563Z I0924 13:19:41.272829   26813 ovs.go:164] Exec(69): /fake-bin/ovs-vsctl --timeout=15 --may-exist add-port br-int int -- --may-exist add-port br-ext ext -- set Interface int type=patch options:peer=ext external-ids:iface-id=int-mynode -- set Interface ext type=patch options:peer=int
2023-09-24T13:19:41.2731365Z I0924 13:19:41.272866   26813 ovs.go:167] Exec(69): stdout: ""
2023-09-24T13:19:41.2733354Z I0924 13:19:41.272892   26813 ovs.go:168] Exec(69): stderr: ""
2023-09-24T13:19:41.2736081Z I0924 13:19:41.273450   26813 ovs.go:164] Exec(70): /fake-bin/ovs-vsctl --timeout=15 --may-exist add-port br-ext ext-vxlan -- set interface ext-vxlan type=vxlan options:remote_ip="flow" options:key="flow" options:dst_port=4789
2023-09-24T13:19:41.2736755Z I0924 13:19:41.273483   26813 ovs.go:167] Exec(70): stdout: ""
2023-09-24T13:19:41.2738714Z I0924 13:19:41.273504   26813 ovs.go:168] Exec(70): stderr: ""
2023-09-24T13:19:41.2749519Z I0924 13:19:41.274819   26813 ovn_node_linux.go:731] Flow sync requested
2023-09-24T13:19:41.2753572Z I0924 13:19:41.274854   26813 ovn_node_linux.go:641] Hybrid overlay setup complete for node mynode
2023-09-24T13:19:41.2754300Z I0924 13:19:41.274883   26813 informer.go:319] Successfully synced 'mynode'
2023-09-24T13:19:41.2755206Z I0924 13:19:41.274945   26813 ovs.go:164] Exec(71): /fake-bin/ovs-ofctl dump-flows --no-stats br-ext table=20
2023-09-24T13:19:41.2755686Z I0924 13:19:41.274976   26813 ovs.go:167] Exec(71): stdout: ""
2023-09-24T13:19:41.2756060Z I0924 13:19:41.275000   26813 ovs.go:168] Exec(71): stderr: ""
2023-09-24T13:19:41.2760265Z I0924 13:19:41.275793   26813 ovs.go:164] Exec(72): /fake-bin/ovs-ofctl -O OpenFlow13 --bundle replace-flows br-ext -
2023-09-24T13:19:41.2764148Z I0924 13:19:41.275847   26813 ovs.go:167] Exec(72): stdout: ""
2023-09-24T13:19:41.2764569Z I0924 13:19:41.276173   26813 ovs.go:168] Exec(72): stderr: ""
2023-09-24T13:19:41.2793051Z I0924 13:19:41.278946   26813 ovn_node_linux.go:227] Add Node node1
2023-09-24T13:19:41.2794112Z I0924 13:19:41.278995   26813 ovn_node_linux.go:246] Add hybridOverlay Node node1
2023-09-24T13:19:41.2796197Z I0924 13:19:41.279305   26813 ovn_node_linux.go:161] Setting up hybrid overlay tunnel to node node1
2023-09-24T13:19:41.2798197Z I0924 13:19:41.279483   26813 ovn_node_linux.go:731] Flow sync requested
2023-09-24T13:19:41.2800416Z I0924 13:19:41.279528   26813 informer.go:319] Successfully synced 'node1'
2023-09-24T13:19:41.2803863Z I0924 13:19:41.279646   26813 ovs.go:164] Exec(73): /fake-bin/ovs-ofctl dump-flows --no-stats br-ext table=20
2023-09-24T13:19:41.2804341Z I0924 13:19:41.279697   26813 ovs.go:167] Exec(73): stdout: ""
2023-09-24T13:19:41.2804730Z I0924 13:19:41.279728   26813 ovs.go:168] Exec(73): stderr: ""
2023-09-24T13:19:41.2805377Z I0924 13:19:41.279856   26813 ovs.go:164] Exec(74): /fake-bin/ovs-ofctl -O OpenFlow13 --bundle replace-flows br-ext -
2023-09-24T13:19:41.2805860Z I0924 13:19:41.279904   26813 ovs.go:167] Exec(74): stdout: ""
2023-09-24T13:19:41.2806437Z I0924 13:19:41.279936   26813 ovs.go:168] Exec(74): stderr: ""
2023-09-24T13:19:41.2898141Z I0924 13:19:41.289540   26813 ovn_node_linux.go:731] Flow sync requested
2023-09-24T13:19:41.2900292Z I0924 13:19:41.289659   26813 ovs.go:164] Exec(75): /fake-bin/ovs-ofctl dump-flows --no-stats br-ext table=20
2023-09-24T13:19:41.2900811Z I0924 13:19:41.289705   26813 ovs.go:167] Exec(75): stdout: ""
2023-09-24T13:19:41.2901212Z I0924 13:19:41.289729   26813 ovs.go:168] Exec(75): stderr: ""
2023-09-24T13:19:41.2901896Z I0924 13:19:41.289806   26813 ovs.go:164] Exec(76): /fake-bin/ovs-ofctl -O OpenFlow13 --bundle replace-flows br-ext -
2023-09-24T13:19:41.2902384Z I0924 13:19:41.289832   26813 ovs.go:167] Exec(76): stdout: ""
2023-09-24T13:19:41.2902774Z I0924 13:19:41.289852   26813 ovs.go:168] Exec(76): stderr: ""
2023-09-24T13:19:41.2903217Z I0924 13:19:41.289574   26813 ovn_node_linux.go:116] Pod pod1 wired for Hybrid Overlay
2023-09-24T13:19:41.2903832Z I0924 13:19:41.289886   26813 informer.go:319] Successfully synced 'test/pod1'
2023-09-24T13:19:41.3000792Z I0924 13:19:41.299872   26813 ovn_node_linux.go:227] Add Node mynode
2023-09-24T13:19:41.3002100Z I0924 13:19:41.300045   26813 ovn_node_linux.go:731] Flow sync requested
2023-09-24T13:19:41.3003198Z I0924 13:19:41.300074   26813 informer.go:319] Successfully synced 'mynode'
2023-09-24T13:19:41.3004603Z I0924 13:19:41.300124   26813 ovs.go:164] Exec(77): /fake-bin/ovs-ofctl dump-flows --no-stats br-ext table=20
2023-09-24T13:19:41.3005150Z I0924 13:19:41.300152   26813 ovs.go:167] Exec(77): stdout: ""
2023-09-24T13:19:41.3005548Z I0924 13:19:41.300175   26813 ovs.go:168] Exec(77): stderr: ""
2023-09-24T13:19:41.3006395Z I0924 13:19:41.300237   26813 ovs.go:164] Exec(78): /fake-bin/ovs-ofctl -O OpenFlow13 --bundle replace-flows br-ext -
2023-09-24T13:19:41.3006876Z I0924 13:19:41.300259   26813 ovs.go:167] Exec(78): stdout: ""
2023-09-24T13:19:41.3007266Z I0924 13:19:41.300279   26813 ovs.go:168] Exec(78): stderr: ""
2023-09-24T13:19:41.3112810Z I0924 13:19:41.310709   26813 node.go:192] Shutting down Hybrid Overlay Node workers
2023-09-24T13:19:41.3124783Z I0924 13:19:41.310724   26813 informer.go:226] Shutting down node queue workers
2023-09-24T13:19:41.3125498Z I0924 13:19:41.310792   26813 informer.go:226] Shutting down pod queue workers
2023-09-24T13:19:41.3125955Z I0924 13:19:41.310826   26813 watch.go:183] Stopping fake watcher.
2023-09-24T13:19:41.3126648Z I0924 13:19:41.310849   26813 watch.go:183] Stopping fake watcher.
2023-09-24T13:19:41.3127451Z I0924 13:19:41.310877   26813 reflector.go:293] Stopping reflector *v1.Pod (0s) from k8s.io/client-go/informers/factory.go:150
2023-09-24T13:19:41.3128284Z I0924 13:19:41.310888   26813 reflector.go:293] Stopping reflector *v1.Node (0s) from k8s.io/client-go/informers/factory.go:150
2023-09-24T13:19:41.3128851Z I0924 13:19:41.310830   26813 ovn_node_linux.go:663] Shutting down OpenFlow sync thread
2023-09-24T13:19:41.3129332Z I0924 13:19:41.310948   26813 informer.go:229] Shut down pod queue workers
2023-09-24T13:19:41.3129902Z I0924 13:19:41.310984   26813 informer.go:229] Shut down node queue workers
2023-09-24T13:19:41.3130380Z I0924 13:19:41.311077   26813 node.go:194] Shut down Hybrid Overlay Node workers
2023-09-24T13:19:41.3130814Z •
2023-09-24T13:19:41.3131543Z JUnit path was configured: /home/runner/work/ovn-kubernetes/ovn-kubernetes/go-controller/_artifacts/junit-hybrid-overlay_pkg_controller.xml
2023-09-24T13:19:41.3131937Z 
2023-09-24T13:19:41.3132494Z JUnit report was created: /home/runner/work/ovn-kubernetes/ovn-kubernetes/go-controller/_artifacts/junit-hybrid-overlay_pkg_controller.xml
2023-09-24T13:19:41.3132889Z 
2023-09-24T13:19:41.3133142Z Ran 10 of 10 Specs in 2.524 seconds
2023-09-24T13:19:41.3133795Z SUCCESS! -- 10 Passed | 0 Failed | 0 Pending | 0 Skipped
2023-09-24T13:19:41.3134396Z     testing.go:1319: race detected during execution of test
2023-09-24T13:19:41.3134922Z --- FAIL: TestHybridOverlayControllerSuite (2.54s)
2023-09-24T13:19:41.3135281Z === CONT  
2023-09-24T13:19:41.3135827Z     testing.go:1319: race detected during execution of test
npinaeva commented 11 months ago

https://github.com/ovn-org/ovn-kubernetes/actions/runs/6410372547/job/17403543689?pr=3949

trozet commented 11 months ago

I'm seeing data races as well. There are some issues with hybrid overlay. Working on a fix...

2023-10-10T13:12:11.8338229Z WARNING: DATA RACE
2023-10-10T13:12:11.8338659Z Read at 0x00c0006bf000 by goroutine 131:
2023-10-10T13:12:11.8339521Z   github.com/ovn-org/ovn-kubernetes/go-controller/hybrid-overlay/pkg/controller.(*NodeController).AddNode()
2023-10-10T13:12:11.8340694Z       /home/runner/work/ovn-kubernetes/ovn-kubernetes/go-controller/hybrid-overlay/pkg/controller/ovn_node_linux.go:230 +0x1bc
2023-10-10T13:12:11.8341573Z   github.com/ovn-org/ovn-kubernetes/go-controller/hybrid-overlay/pkg/controller.NewNode.func1()
2023-10-10T13:12:11.8342667Z       /home/runner/work/ovn-kubernetes/ovn-kubernetes/go-controller/hybrid-overlay/pkg/controller/node.go:116 +0x9c
2023-10-10T13:12:11.8343915Z   github.com/ovn-org/ovn-kubernetes/go-controller/pkg/informer.(*eventHandler).syncHandler()
2023-10-10T13:12:11.8345395Z       /home/runner/work/ovn-kubernetes/ovn-kubernetes/go-controller/pkg/informer/informer.go:360 +0x3c6
2023-10-10T13:12:11.8346703Z   github.com/ovn-org/ovn-kubernetes/go-controller/pkg/informer.(*eventHandler).processNextWorkItem.func1()
2023-10-10T13:12:11.8348030Z       /home/runner/work/ovn-kubernetes/ovn-kubernetes/go-controller/pkg/informer/informer.go:305 +0x196
2023-10-10T13:12:11.8349064Z   github.com/ovn-org/ovn-kubernetes/go-controller/pkg/informer.(*eventHandler).processNextWorkItem()
2023-10-10T13:12:11.8350082Z       /home/runner/work/ovn-kubernetes/ovn-kubernetes/go-controller/pkg/informer/informer.go:322 +0x64
2023-10-10T13:12:11.8350892Z   github.com/ovn-org/ovn-kubernetes/go-controller/pkg/informer.(*eventHandler).runWorker()
2023-10-10T13:12:11.8351892Z       /home/runner/work/ovn-kubernetes/ovn-kubernetes/go-controller/pkg/informer/informer.go:273 +0x2e
2023-10-10T13:12:11.8353127Z   github.com/ovn-org/ovn-kubernetes/go-controller/pkg/informer.(*eventHandler).runWorker-fm()
2023-10-10T13:12:11.8353575Z       <autogenerated>:1 +0x39
2023-10-10T13:12:11.8353954Z   k8s.io/apimachinery/pkg/util/wait.BackoffUntil.func1()
2023-10-10T13:12:11.8354885Z       /home/runner/work/ovn-kubernetes/ovn-kubernetes/go-controller/vendor/k8s.io/apimachinery/pkg/util/wait/backoff.go:226 +0x48
2023-10-10T13:12:11.8355530Z   k8s.io/apimachinery/pkg/util/wait.BackoffUntil()
2023-10-10T13:12:11.8356819Z       /home/runner/work/ovn-kubernetes/ovn-kubernetes/go-controller/vendor/k8s.io/apimachinery/pkg/util/wait/backoff.go:227 +0xce
2023-10-10T13:12:11.8357467Z   k8s.io/apimachinery/pkg/util/wait.JitterUntil()
2023-10-10T13:12:11.8358510Z       /home/runner/work/ovn-kubernetes/ovn-kubernetes/go-controller/vendor/k8s.io/apimachinery/pkg/util/wait/backoff.go:204 +0x10d
2023-10-10T13:12:11.8358953Z   k8s.io/apimachinery/pkg/util/wait.Until()
2023-10-10T13:12:11.8359936Z       /home/runner/work/ovn-kubernetes/ovn-kubernetes/go-controller/vendor/k8s.io/apimachinery/pkg/util/wait/backoff.go:161 +0xd7
2023-10-10T13:12:11.8361022Z   github.com/ovn-org/ovn-kubernetes/go-controller/pkg/informer.(*eventHandler).Run.func1()
2023-10-10T13:12:11.8362046Z       /home/runner/work/ovn-kubernetes/ovn-kubernetes/go-controller/pkg/informer/informer.go:218 +0x91
2023-10-10T13:12:11.8362333Z 
2023-10-10T13:12:11.8362515Z Previous write at 0x00c0006bf000 by goroutine 124:
2023-10-10T13:12:11.8363284Z   github.com/ovn-org/ovn-kubernetes/go-controller/hybrid-overlay/pkg/controller.(*NodeController).EnsureHybridOverlayBridge()
2023-10-10T13:12:11.8364498Z       /home/runner/work/ovn-kubernetes/ovn-kubernetes/go-controller/hybrid-overlay/pkg/controller/ovn_node_linux.go:510 +0x6e4
2023-10-10T13:12:11.8365281Z   github.com/ovn-org/ovn-kubernetes/go-controller/hybrid-overlay/pkg/controller.(*NodeController).AddNode()
2023-10-10T13:12:11.8366260Z       /home/runner/work/ovn-kubernetes/ovn-kubernetes/go-controller/hybrid-overlay/pkg/controller/ovn_node_linux.go:244 +0x464
2023-10-10T13:12:11.8367292Z   github.com/ovn-org/ovn-kubernetes/go-controller/hybrid-overlay/pkg/controller.NewNode.func1()
2023-10-10T13:12:11.8368734Z       /home/runner/work/ovn-kubernetes/ovn-kubernetes/go-controller/hybrid-overlay/pkg/controller/node.go:116 +0x9c
2023-10-10T13:12:11.8369622Z   github.com/ovn-org/ovn-kubernetes/go-controller/pkg/informer.(*eventHandler).syncHandler()
2023-10-10T13:12:11.8370477Z       /home/runner/work/ovn-kubernetes/ovn-kubernetes/go-controller/pkg/informer/informer.go:360 +0x3c6
2023-10-10T13:12:11.8371209Z   github.com/ovn-org/ovn-kubernetes/go-controller/pkg/informer.(*eventHandler).processNextWorkItem.func1()
2023-10-10T13:12:11.8372740Z       /home/runner/work/ovn-kubernetes/ovn-kubernetes/go-controller/pkg/informer/informer.go:305 +0x196
2023-10-10T13:12:11.8373929Z   github.com/ovn-org/ovn-kubernetes/go-controller/pkg/informer.(*eventHandler).processNextWorkItem()
2023-10-10T13:12:11.8374735Z       /home/runner/work/ovn-kubernetes/ovn-kubernetes/go-controller/pkg/informer/informer.go:322 +0x64
2023-10-10T13:12:11.8375345Z   github.com/ovn-org/ovn-kubernetes/go-controller/pkg/informer.(*eventHandler).runWorker()
2023-10-10T13:12:11.8376128Z       /home/runner/work/ovn-kubernetes/ovn-kubernetes/go-controller/pkg/informer/informer.go:273 +0x2e
2023-10-10T13:12:11.8377022Z   github.com/ovn-org/ovn-kubernetes/go-controller/pkg/informer.(*eventHandler).runWorker-fm()
2023-10-10T13:12:11.8377452Z       <autogenerated>:1 +0x39
2023-10-10T13:12:11.8377802Z   k8s.io/apimachinery/pkg/util/wait.BackoffUntil.func1()
2023-10-10T13:12:11.8378678Z       /home/runner/work/ovn-kubernetes/ovn-kubernetes/go-controller/vendor/k8s.io/apimachinery/pkg/util/wait/backoff.go:226 +0x48
2023-10-10T13:12:11.8379160Z   k8s.io/apimachinery/pkg/util/wait.BackoffUntil()
2023-10-10T13:12:11.8379989Z       /home/runner/work/ovn-kubernetes/ovn-kubernetes/go-controller/vendor/k8s.io/apimachinery/pkg/util/wait/backoff.go:227 +0xce
2023-10-10T13:12:11.8380462Z   k8s.io/apimachinery/pkg/util/wait.JitterUntil()
2023-10-10T13:12:11.8381306Z       /home/runner/work/ovn-kubernetes/ovn-kubernetes/go-controller/vendor/k8s.io/apimachinery/pkg/util/wait/backoff.go:204 +0x10d
2023-10-10T13:12:11.8381760Z   k8s.io/apimachinery/pkg/util/wait.Until()
2023-10-10T13:12:11.8382895Z       /home/runner/work/ovn-kubernetes/ovn-kubernetes/go-controller/vendor/k8s.io/apimachinery/pkg/util/wait/backoff.go:161 +0xd7
2023-10-10T13:12:11.8383771Z   github.com/ovn-org/ovn-kubernetes/go-controller/pkg/informer.(*eventHandler).Run.func1()
2023-10-10T13:12:11.8384749Z       /home/runner/work/ovn-kubernetes/ovn-kubernetes/go-controller/pkg/informer/informer.go:218 +0x91
2023-10-10T13:12:11.8385124Z 
2023-10-10T13:12:11.8385424Z Goroutine 131 (running) created at:
2023-10-10T13:12:11.8385959Z   github.com/ovn-org/ovn-kubernetes/go-controller/pkg/informer.(*eventHandler).Run()
2023-10-10T13:12:11.8386750Z       /home/runner/work/ovn-kubernetes/ovn-kubernetes/go-controller/pkg/informer/informer.go:216 +0x624
2023-10-10T13:12:11.8387409Z   github.com/ovn-org/ovn-kubernetes/go-controller/hybrid-overlay/pkg/controller.(*Node).Run.func1()
2023-10-10T13:12:11.8388248Z       /home/runner/work/ovn-kubernetes/ovn-kubernetes/go-controller/hybrid-overlay/pkg/controller/node.go:169 +0xea
2023-10-10T13:12:11.8388529Z 
2023-10-10T13:12:11.8388665Z Goroutine 124 (running) created at:
2023-10-10T13:12:11.8389201Z   github.com/ovn-org/ovn-kubernetes/go-controller/pkg/informer.(*eventHandler).Run()
2023-10-10T13:12:11.8390049Z       /home/runner/work/ovn-kubernetes/ovn-kubernetes/go-controller/pkg/informer/informer.go:216 +0x624
2023-10-10T13:12:11.8390690Z   github.com/ovn-org/ovn-kubernetes/go-controller/hybrid-overlay/pkg/controller.(*Node).Run.func1()
2023-10-10T13:12:11.8391543Z       /home/runner/work/ovn-kubernetes/ovn-kubernetes/go-controller/hybrid-overlay/pkg/controller/node.go:169 +0xea
2023-10-10T13:12:11.8391905Z ==================
2023-10-10T13:12:11.8392427Z I1010 13:12:11.833678   26777 ovn_node_linux.go:246] Add hybridOverlay Node remoteNode
2023-10-10T13:12:11.8392956Z I1010 13:12:11.834277   26777 informer.go:319] Successfully synced 'remoteNode'
2023-10-10T13:12:11.8397498Z I1010 13:12:11.835199   26777 ovs.go:168] Exec(14): stderr: ""
2023-10-10T13:12:11.8398988Z I1010 13:12:11.835328   26777 ovs.go:164] Exec(15): /fake-bin/ovs-vsctl --timeout=15 --if-exists get interface br-ext mac_in_use

https://github.com/ovn-org/ovn-kubernetes/actions/runs/6469466485/job/17563581067?pr=3953