OCPBUGS-26498: Make ingressConditionsEqual more efficient #588

gcs278 · 2024-04-29T22:46:28Z

We found that the router's contention tracker was slower after updates were made to support the UnservableInFutureVersions condition. This lag sometimes causes routers to update the route status before the contention tracker detected an update, leading to the per-route contention logic not activating.

In such scenarios, the maxContentions logic eventually activates, temporarily preventing the router from making any updates to the routes. This commit improves the efficiency of the ingressConditionsEqual function to help mitigate this type of issues.

Related slack thread.

Current PR Benchmark Results (Nested Loops):

$ go test -bench=. -run=Benchmark_ingressConditionsEqual ./... -benchtime=10s -benchmem
[...] 
goos: linux
goarch: amd64
pkg: github.com/openshift/router/pkg/router/controller
cpu: Intel(R) Core(TM) i7-10850H CPU @ 2.70GHz
Benchmark_ingressConditionsEqual/single-12         		1000000000	         4.936 ns/op	       0 B/op	       0 allocs/op
Benchmark_ingressConditionsEqual/mismatch_length-12         	1000000000	         2.449 ns/op	       0 B/op	       0 allocs/op
Benchmark_ingressConditionsEqual/double-12                  	433452776	        27.60 ns/op	       0 B/op	       0 allocs/op
PASS

Using `sort.Slice` Benchmark Results (Previous PR Revision `b1bea4d`):

$ go test -bench=. -run=Benchmark_ingressConditionsEqual ./... -benchtime=10s -benchmem
[...]
goos: linux
goarch: amd64
pkg: github.com/openshift/router/pkg/router/controller
cpu: Intel(R) Core(TM) i7-10850H CPU @ 2.70GHz
Benchmark_ingressConditionsEqual/single-12         		88920192	       121.0 ns/op	      48 B/op	       2 allocs/op
Benchmark_ingressConditionsEqual/mismatch_length-12         	1000000000	         2.352 ns/op	       0 B/op	       0 allocs/op
Benchmark_ingressConditionsEqual/double-12                  	30747393	       379.5 ns/op	     304 B/op	       6 allocs/op
PASS

Post-#555 Benchmark Results (Not this PR):

$ go test -bench=. -run=Benchmark_ingressConditionsEqual ./... -benchtime=10s -benchmem
[...]
goos: linux
goarch: amd64
pkg: github.com/openshift/router/pkg/router/controller
cpu: Intel(R) Core(TM) i7-10850H CPU @ 2.70GHz
Benchmark_ingressConditionsEqual/single-12         	  	  226267	     52844 ns/op	    7878 B/op	     251 allocs/op
Benchmark_ingressConditionsEqual/mismatch_length-12         	   84859	    140895 ns/op	   18302 B/op	     674 allocs/op
Benchmark_ingressConditionsEqual/double-12                  	   68632	    174946 ns/op	   23050 B/op	     863 allocs/op
PASS

Pre-#555 Benchmark Results:

$ go test -bench=. -run=Benchmark_ingressConditionsEqual ./... -benchtime=10s -benchmem
[...]
goos: linux
goarch: amd64
pkg: github.com/openshift/router/pkg/router/controller
cpu: Intel(R) Core(TM) i7-10850H CPU @ 2.70GHz
Benchmark_ingressConditionsEqual/single-12         	 	 7699280	      1549 ns/op	    1008 B/op	      19 allocs/op
Benchmark_ingressConditionsEqual/mismatch_length-12         	 2992860	      3983 ns/op	    2336 B/op	      35 allocs/op
Benchmark_ingressConditionsEqual/double-12                  	 2984841	      4028 ns/op	    2336 B/op	      35 allocs/op
PASS

Also, I have included some trivial logging improvements that will help debugging racy conditions.

Add missing key to log statement and log when a worker becomes elected to leader or demoted to a follower for better clarity in router logs.

openshift-ci-robot · 2024-04-29T22:46:34Z

@gcs278: This pull request references Jira Issue OCPBUGS-26498, which is valid.

3 validation(s) were run on this bug

bug is open, matching expected state (open)
bug target version (4.16.0) matches configured target version for branch (4.16.0)
bug is in the state POST, which is one of the valid states (NEW, ASSIGNED, POST)

Requesting review from QA contact:
/cc @ShudiLi

The bug has been updated to refer to the pull request using the external bug tracker.

In response to this:

We found that the router's contention tracker was slower after updates were made to support the UnservableInFutureVersions condition. This lag sometimes causes routers to update the route status before the contention tracker detected an update, leading to the per-route contention logic not activating.

In such scenarios, the maxContentions logic eventually activates, temporarily preventing the router from making any updates to the routes. This commit improves the efficiency of the ingressConditionsEqual function to help mitigate this type of issues.

Also, I have included some trivial logging improvements that will help debugging racy conditions.

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the openshift-eng/jira-lifecycle-plugin repository.

Introduces verbose (level 10) logging to trace plugin chain execution. A bug was identified where the plugin chain halted unexpectedly, and logging the plugin chain steps aids in debugging.

Add verbose logging to help indicate the router is attempting to update a route status. This is helpful for debugging racy router status logic.

Miciah · 2024-04-30T00:19:10Z

pkg/router/controller/contention.go

+	// Sort both slices by Type to ensure they are in the same order for comparison.
+	sort.Slice(a, func(i, j int) bool { return a[i].Type < a[j].Type })
+	sort.Slice(b, func(i, j int) bool { return b[i].Type < b[j].Type })


Have you done benchmarks on this code? sort.Slice uses reflection, albeit the lighter-weight reflectlite rather than the standard reflect package, and even without that, the underlying quicksort algorithm implementation is probably slower than a nested loop for the expected number of items (namely 0 or 1 in the usual case, 2 in the exceptional case). If benchmarks show that sort.Slice is fast enough, though, then it doesn't really matter. (If you do write a benchmark, consider using testing.B and adding the benchmark to pkg/router/controller/status_test.go.)

Good point. I need to back this up with some data. I added a benchmark function (first time I've ever done that) and provided various results in the PR description.

The benchmark with sort.Slice results show it's ~500x faster (I'm comparing ns/op). I stopped there.

BUT I just tried out nested loops, and I see it's ~5000-7000x faster. You are right, where 2 conditions are our max, nested loops are faster than sort.Slice..

Miciah · 2024-04-30T04:17:00Z

/approve
/lgtm
/hold
for @frobware to review.

openshift-ci · 2024-04-30T04:17:29Z

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: Miciah

The full list of commands accepted by this bot can be found here.

The pull request process is described here

Needs approval from an approver in each of these files:

~~OWNERS~~ [Miciah]

Approvers can indicate their approval by writing /approve in a comment
Approvers can cancel approval by writing /approve cancel in a comment

frobware · 2024-04-30T10:55:16Z

A suggestion for improved performance:

% git diff
diff --git a/pkg/router/controller/contention.go b/pkg/router/controller/contention.go
index 0d866406..0f159bf7 100644
--- a/pkg/router/controller/contention.go
+++ b/pkg/router/controller/contention.go
@@ -263,10 +263,10 @@ func ingressConditionsEqual(a, b []routev1.RouteIngressCondition) bool {

        // Compare each condition in a with every condition in b.
        // Given the current max of only two conditions, nested loops are more efficient than sorting.
-       for _, condA := range a {
+       for i := 0; i < len(a); i++ {
                matchFound := false
-               for _, condB := range b {
-                       if conditionsEqual(condA, condB) {
+               for j := 0; j < len(b); j++ {
+                       if conditionsEqual(&a[i], &b[j]) {
                                matchFound = true
                                break
                        }
@@ -280,7 +280,7 @@ func ingressConditionsEqual(a, b []routev1.RouteIngressCondition) bool {
 }

 // conditionsEqual compares two RouteIngressConditions, ignoring LastTransitionTime.
-func conditionsEqual(a, b routev1.RouteIngressCondition) bool {
+func conditionsEqual(a, b *routev1.RouteIngressCondition) bool {
        return a.Type == b.Type &&
                a.Status == b.Status &&
                a.Reason == b.Reason &&

Benchmarking shows:

% go test -bench=. -run=Benchmark_ingressConditionsEqual ./... -benchtime=10s
goos: linux
goarch: amd64
pkg: github.com/openshift/router/pkg/router/controller
cpu: 11th Gen Intel(R) Core(TM) i9-11900 @ 2.50GHz
Benchmark_ingressConditionsEqual/single-16              1000000000               3.422 ns/op
Benchmark_ingressConditionsEqual/mismatch_length-16             1000000000               1.487 ns/op
Benchmark_ingressConditionsEqual/double-16                      880706917               13.74 ns/op

frobware · 2024-04-30T10:57:44Z

pkg/router/controller/status_test.go

+			},
+		},
+	}
+	for _, tc := range testCases {


Although there's very minimal setup here you could call b.ResetTimer() to take any current or future setup costs out of the numbers.

We found that the router's contention tracker was slower after updates were made to support the UnservableInFutureVersions condition. This lag sometimes causes routers to update the route status before the contention tracker detected an update, leading to the per-route contention logic not activating. In such scenarios, the maxContentions logic eventually activates, temporarily preventing the router from making any updates to the routes. This commit improves the efficiency of the ingressConditionsEqual function to help mitigate this type of issues.

gcs278 · 2024-04-30T13:39:43Z

A suggestion for improved performance:

% git diff
diff --git a/pkg/router/controller/contention.go b/pkg/router/controller/contention.go
index 0d866406..0f159bf7 100644
--- a/pkg/router/controller/contention.go
+++ b/pkg/router/controller/contention.go
@@ -263,10 +263,10 @@ func ingressConditionsEqual(a, b []routev1.RouteIngressCondition) bool {

        // Compare each condition in a with every condition in b.
        // Given the current max of only two conditions, nested loops are more efficient than sorting.
-       for _, condA := range a {
+       for i := 0; i < len(a); i++ {
                matchFound := false
-               for _, condB := range b {
-                       if conditionsEqual(condA, condB) {
+               for j := 0; j < len(b); j++ {
+                       if conditionsEqual(&a[i], &b[j]) {
                                matchFound = true
                                break
                        }
@@ -280,7 +280,7 @@ func ingressConditionsEqual(a, b []routev1.RouteIngressCondition) bool {
 }

 // conditionsEqual compares two RouteIngressConditions, ignoring LastTransitionTime.
-func conditionsEqual(a, b routev1.RouteIngressCondition) bool {
+func conditionsEqual(a, b *routev1.RouteIngressCondition) bool {
        return a.Type == b.Type &&
                a.Status == b.Status &&
                a.Reason == b.Reason &&

Benchmarking shows:

% go test -bench=. -run=Benchmark_ingressConditionsEqual ./... -benchtime=10s
goos: linux
goarch: amd64
pkg: github.com/openshift/router/pkg/router/controller
cpu: 11th Gen Intel(R) Core(TM) i9-11900 @ 2.50GHz
Benchmark_ingressConditionsEqual/single-16              1000000000               3.422 ns/op
Benchmark_ingressConditionsEqual/mismatch_length-16             1000000000               1.487 ns/op
Benchmark_ingressConditionsEqual/double-16                      880706917               13.74 ns/op

Done, thanks @frobware

frobware · 2024-04-30T14:57:22Z

/lgtm

gcs278 · 2024-04-30T15:19:28Z

/hold cancel

openshift-ci-robot · 2024-04-30T15:52:48Z

/retest-required

Remaining retests: 0 against base HEAD 8762aa4 and 2 for PR HEAD 44f217f in total

gcs278 · 2024-04-30T16:41:31Z

I see something funny in my origin E2E test, just going to hold out of precaution until I understand.
/hold

gcs278 · 2024-04-30T17:03:02Z

Never mind, I mistakenly was testing with the wrong router image and thought there was a regression...
/hold cancel

openshift-ci · 2024-04-30T17:51:22Z

@gcs278: The following test failed, say /retest to rerun all failed tests or /retest-required to rerun all mandatory failed tests:

Test name	Commit	Details	Required	Rerun command
ci/prow/e2e-metal-ipi-ovn-ipv6	`44f217f`	link	false	`/test e2e-metal-ipi-ovn-ipv6`

Full PR test history. Your PR dashboard.

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository. I understand the commands that are listed here.

openshift-ci-robot · 2024-04-30T17:53:26Z

@gcs278: Jira Issue OCPBUGS-26498: Some pull requests linked via external trackers have merged:

The following pull requests linked via external trackers have not merged:

openshift/cluster-ingress-operator#1014 is open

These pull request must merge or be unlinked from the Jira bug in order for it to move to the next state. Once unlinked, request a bug refresh with /jira refresh.

Jira Issue OCPBUGS-26498 has not been moved to the MODIFIED state.

In response to this:

We found that the router's contention tracker was slower after updates were made to support the UnservableInFutureVersions condition. This lag sometimes causes routers to update the route status before the contention tracker detected an update, leading to the per-route contention logic not activating.

In such scenarios, the maxContentions logic eventually activates, temporarily preventing the router from making any updates to the routes. This commit improves the efficiency of the ingressConditionsEqual function to help mitigate this type of issues.

Related slack thread.

Current PR Benchmark Results (Nested Loops):

$ go test -bench=. -run=Benchmark_ingressConditionsEqual ./... -benchtime=10s -benchmem
[...] 
goos: linux
goarch: amd64
pkg: github.com/openshift/router/pkg/router/controller
cpu: Intel(R) Core(TM) i7-10850H CPU @ 2.70GHz
Benchmark_ingressConditionsEqual/single-12         		1000000000	         4.936 ns/op	       0 B/op	       0 allocs/op
Benchmark_ingressConditionsEqual/mismatch_length-12         	1000000000	         2.449 ns/op	       0 B/op	       0 allocs/op
Benchmark_ingressConditionsEqual/double-12                  	433452776	        27.60 ns/op	       0 B/op	       0 allocs/op
PASS

Using `sort.Slice` Benchmark Results (Previous PR Revision `b1bea4d`):

$ go test -bench=. -run=Benchmark_ingressConditionsEqual ./... -benchtime=10s -benchmem
[...]
goos: linux
goarch: amd64
pkg: github.com/openshift/router/pkg/router/controller
cpu: Intel(R) Core(TM) i7-10850H CPU @ 2.70GHz
Benchmark_ingressConditionsEqual/single-12         		88920192	       121.0 ns/op	      48 B/op	       2 allocs/op
Benchmark_ingressConditionsEqual/mismatch_length-12         	1000000000	         2.352 ns/op	       0 B/op	       0 allocs/op
Benchmark_ingressConditionsEqual/double-12                  	30747393	       379.5 ns/op	     304 B/op	       6 allocs/op
PASS

Post-#555 Benchmark Results (Not this PR):

$ go test -bench=. -run=Benchmark_ingressConditionsEqual ./... -benchtime=10s -benchmem
[...]
goos: linux
goarch: amd64
pkg: github.com/openshift/router/pkg/router/controller
cpu: Intel(R) Core(TM) i7-10850H CPU @ 2.70GHz
Benchmark_ingressConditionsEqual/single-12         	  	  226267	     52844 ns/op	    7878 B/op	     251 allocs/op
Benchmark_ingressConditionsEqual/mismatch_length-12         	   84859	    140895 ns/op	   18302 B/op	     674 allocs/op
Benchmark_ingressConditionsEqual/double-12                  	   68632	    174946 ns/op	   23050 B/op	     863 allocs/op
PASS

Pre-#555 Benchmark Results:

$ go test -bench=. -run=Benchmark_ingressConditionsEqual ./... -benchtime=10s -benchmem
[...]
goos: linux
goarch: amd64
pkg: github.com/openshift/router/pkg/router/controller
cpu: Intel(R) Core(TM) i7-10850H CPU @ 2.70GHz
Benchmark_ingressConditionsEqual/single-12         	 	 7699280	      1549 ns/op	    1008 B/op	      19 allocs/op
Benchmark_ingressConditionsEqual/mismatch_length-12         	 2992860	      3983 ns/op	    2336 B/op	      35 allocs/op
Benchmark_ingressConditionsEqual/double-12                  	 2984841	      4028 ns/op	    2336 B/op	      35 allocs/op
PASS

Also, I have included some trivial logging improvements that will help debugging racy conditions.

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the openshift-eng/jira-lifecycle-plugin repository.

openshift-bot · 2024-04-30T22:43:17Z

[ART PR BUILD NOTIFIER]

This PR has been included in build ose-haproxy-router-base-container-v4.17.0-202404302014.p0.gb6f7c63.assembly.stream.el9 for distgit ose-haproxy-router-base.
All builds following this will include this PR.

Log election results in writerlease

efcba1b

Add missing key to log statement and log when a worker becomes elected to leader or demoted to a follower for better clarity in router logs.

openshift-ci bot requested review from ShudiLi, alebedev87 and rfredette April 29, 2024 22:46

gcs278 mentioned this pull request Apr 29, 2024

OCPBUGS-26498: Optimize Upgrade Validation plugin by skipping unnecessary changes #587

Merged

gcs278 added 2 commits April 29, 2024 18:50

Add verbose logging for plugin chain execution

66eb223

Introduces verbose (level 10) logging to trace plugin chain execution. A bug was identified where the plugin chain halted unexpectedly, and logging the plugin chain steps aids in debugging.

Add log for attempting to update route status

3f17190

Add verbose logging to help indicate the router is attempting to update a route status. This is helpful for debugging racy router status logic.

gcs278 force-pushed the efficient-contention-comparison branch from 27cfb9a to b1bea4d Compare April 29, 2024 22:50

Miciah reviewed Apr 30, 2024

View reviewed changes

gcs278 force-pushed the efficient-contention-comparison branch from b1bea4d to c97331f Compare April 30, 2024 04:09

openshift-ci bot added the do-not-merge/hold Indicates that a PR should not merge because someone has issued a /hold command. label Apr 30, 2024

openshift-ci bot assigned Miciah Apr 30, 2024

openshift-ci bot added the lgtm Indicates that a PR is ready to be merged. label Apr 30, 2024

openshift-ci bot added the approved Indicates a PR has been approved by an approver from all required OWNERS files. label Apr 30, 2024

frobware reviewed Apr 30, 2024

View reviewed changes

gcs278 force-pushed the efficient-contention-comparison branch from c97331f to 44f217f Compare April 30, 2024 13:39

openshift-ci bot removed the lgtm Indicates that a PR is ready to be merged. label Apr 30, 2024

openshift-ci bot assigned frobware Apr 30, 2024

openshift-ci bot added the lgtm Indicates that a PR is ready to be merged. label Apr 30, 2024

openshift-ci bot removed the do-not-merge/hold Indicates that a PR should not merge because someone has issued a /hold command. label Apr 30, 2024

openshift-ci bot added the do-not-merge/hold Indicates that a PR should not merge because someone has issued a /hold command. label Apr 30, 2024

openshift-ci bot removed the do-not-merge/hold Indicates that a PR should not merge because someone has issued a /hold command. label Apr 30, 2024

openshift-merge-bot bot merged commit b6f7c63 into openshift:master Apr 30, 2024
7 of 8 checks passed

gcs278 mentioned this pull request Apr 30, 2024

WIP DO NOT MERGE: Debug output for TestRouteAdmissionPolicy openshift/cluster-ingress-operator#1049

Closed

gcs278 mentioned this pull request May 2, 2024

[release-4.15] OCPBUGS-28928: Upgrade Validation plugin for SHA1 certs #585

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

OCPBUGS-26498: Make ingressConditionsEqual more efficient #588

OCPBUGS-26498: Make ingressConditionsEqual more efficient #588

gcs278 commented Apr 29, 2024 •

edited

Loading

openshift-ci-robot commented Apr 29, 2024

Miciah Apr 30, 2024

gcs278 Apr 30, 2024

Miciah commented Apr 30, 2024

openshift-ci bot commented Apr 30, 2024

frobware commented Apr 30, 2024

frobware Apr 30, 2024

gcs278 Apr 30, 2024

gcs278 commented Apr 30, 2024

frobware commented Apr 30, 2024

gcs278 commented Apr 30, 2024

openshift-ci-robot commented Apr 30, 2024

gcs278 commented Apr 30, 2024

gcs278 commented Apr 30, 2024

openshift-ci bot commented Apr 30, 2024

openshift-ci-robot commented Apr 30, 2024

Current PR Benchmark Results (Nested Loops):

Using `sort.Slice` Benchmark Results (Previous PR Revision `b1bea4d`):

Post-#555 Benchmark Results (Not this PR):

Pre-#555 Benchmark Results:

openshift-bot commented Apr 30, 2024

OCPBUGS-26498: Make ingressConditionsEqual more efficient #588

OCPBUGS-26498: Make ingressConditionsEqual more efficient #588

Conversation

gcs278 commented Apr 29, 2024 • edited Loading

Current PR Benchmark Results (Nested Loops):

Using sort.Slice Benchmark Results (Previous PR Revision b1bea4d):

Post-#555 Benchmark Results (Not this PR):

Pre-#555 Benchmark Results:

openshift-ci-robot commented Apr 29, 2024

Miciah Apr 30, 2024

Choose a reason for hiding this comment

gcs278 Apr 30, 2024

Choose a reason for hiding this comment

Miciah commented Apr 30, 2024

openshift-ci bot commented Apr 30, 2024

frobware commented Apr 30, 2024

frobware Apr 30, 2024

Choose a reason for hiding this comment

gcs278 Apr 30, 2024

Choose a reason for hiding this comment

gcs278 commented Apr 30, 2024

frobware commented Apr 30, 2024

gcs278 commented Apr 30, 2024

openshift-ci-robot commented Apr 30, 2024

gcs278 commented Apr 30, 2024

gcs278 commented Apr 30, 2024

openshift-ci bot commented Apr 30, 2024

openshift-ci-robot commented Apr 30, 2024

Current PR Benchmark Results (Nested Loops):

Using sort.Slice Benchmark Results (Previous PR Revision b1bea4d):

Post-#555 Benchmark Results (Not this PR):

Pre-#555 Benchmark Results:

openshift-bot commented Apr 30, 2024

gcs278 commented Apr 29, 2024 •

edited

Loading

Using `sort.Slice` Benchmark Results (Previous PR Revision `b1bea4d`):

Using `sort.Slice` Benchmark Results (Previous PR Revision `b1bea4d`):