Skip to content

Conversation

@openshift-cherrypick-robot

This is an automated cherry-pick of #2475

/assign tjungblu

/cherrypick release-4.16

sxllwx and others added 4 commits October 23, 2025 10:25
…d write

Improve audit context handling by encapsulating event data and operations behind a structured API. Make
the Audit system more robust in concurrent environments by properly isolating mutable state. The cleaner
API simplifies interaction with audit events, improving maintainability. Encapsulation reduces bugs
by preventing direct manipulation of audit events.

Signed-off-by: Davanum Srinivas <[email protected]>
Co-Authored-By: Jordan Liggitt <[email protected]>
Co-Authored-By: sxllwx <[email protected]>
Signed-off-by: Davanum Srinivas <[email protected]>
Co-Authored-By: Jordan Liggitt <[email protected]>
Co-Authored-By: Thomas Jungblut <[email protected]>

Set event level during context init, fixing imports

Signed-off-by: Davanum Srinivas <[email protected]>
Signed-off-by: Thomas Jungblut <[email protected]>
… going to use it

Merge pull request kubernetes#131725 from dims/avoid-encoding-in-log-response-object-when-we-dont-need-it
When backporting some changes from upstream's master branch a unit test
ended up being broken. The code covered by this test does not seem to
exist upstream, neither the test file.

The code this commit fixes was introduced by 57c60d8 and we should
squash this one with it once the time for rebasing arrives.

Even though 57c60d8 description reads "UPSTREAM: 115328: annotate early
and late requests" the upstream PR 115328 was closed without merging.
@openshift-ci-robot
Copy link

@openshift-cherrypick-robot: the contents of this pull request could not be automatically validated.

The following commits are valid:

The following commits could not be validated and must be approved by a top-level approver:

Comment /validate-backports to re-evaluate validity of the upstream PRs, for example when they are merged upstream.

@openshift-ci-robot
Copy link

@openshift-cherrypick-robot: Jira Issue OCPBUGS-61773 has been cloned as Jira Issue OCPBUGS-63460. Will retitle bug to link to clone.
/retitle [release-4.17] OCPBUGS-63460: UPSTREAM: : backporting fix for concurrent map iteration and write #2456

In response to this:

This is an automated cherry-pick of #2475

/assign tjungblu

/cherrypick release-4.16

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-ci openshift-ci bot changed the title [release-4.17] OCPBUGS-61773: UPSTREAM: <carry>: backporting fix for concurrent map iteration and write #2456 [release-4.17] OCPBUGS-63460: UPSTREAM: <carry>: backporting fix for concurrent map iteration and write #2456 Oct 23, 2025
@openshift-ci-robot openshift-ci-robot added jira/valid-reference Indicates that this PR references a valid Jira ticket of any type. jira/invalid-bug Indicates that a referenced Jira bug is invalid for the branch this PR is targeting. labels Oct 23, 2025
@openshift-ci-robot
Copy link

@openshift-cherrypick-robot: This pull request references Jira Issue OCPBUGS-63460, which is invalid:

  • expected dependent Jira Issue OCPBUGS-61773 to be in one of the following states: VERIFIED, RELEASE PENDING, CLOSED (ERRATA), CLOSED (CURRENT RELEASE), CLOSED (DONE), CLOSED (DONE-ERRATA), but it is MODIFIED instead

Comment /jira refresh to re-evaluate validity if changes to the Jira bug are made, or edit the title of this pull request to link to a different bug.

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

In response to this:

This is an automated cherry-pick of #2475

/assign tjungblu

/cherrypick release-4.16

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-ci openshift-ci bot requested review from bertinatto and deads2k October 23, 2025 10:28
@openshift-ci openshift-ci bot added the vendor-update Touching vendor dir or related files label Oct 23, 2025
@tjungblu
Copy link

/retest-required

@tjungblu
Copy link

@bertinatto Fabio, could you please use your magic approval for this branch? This unfortunately needs to go to 4.16

@tjungblu
Copy link

/jira refresh

@openshift-ci-robot
Copy link

@tjungblu: This pull request references Jira Issue OCPBUGS-63460, which is invalid:

  • expected dependent Jira Issue OCPBUGS-61773 to be in one of the following states: VERIFIED, RELEASE PENDING, CLOSED (ERRATA), CLOSED (CURRENT RELEASE), CLOSED (DONE), CLOSED (DONE-ERRATA), but it is ON_QA instead

Comment /jira refresh to re-evaluate validity if changes to the Jira bug are made, or edit the title of this pull request to link to a different bug.

In response to this:

/jira refresh

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.

@tjungblu
Copy link

/assign @bertinatto

@openshift-ci
Copy link

openshift-ci bot commented Oct 23, 2025

@openshift-cherrypick-robot: all tests passed!

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-sigs/prow repository. I understand the commands that are listed here.

@mrobson
Copy link

mrobson commented Oct 27, 2025

/jira refresh

@openshift-ci-robot openshift-ci-robot added jira/valid-bug Indicates that a referenced Jira bug is valid for the branch this PR is targeting. and removed jira/invalid-bug Indicates that a referenced Jira bug is invalid for the branch this PR is targeting. labels Oct 27, 2025
@openshift-ci-robot
Copy link

@mrobson: This pull request references Jira Issue OCPBUGS-63460, which is valid. The bug has been moved to the POST state.

7 validation(s) were run on this bug
  • bug is open, matching expected state (open)
  • bug target version (4.17.z) matches configured target version for branch (4.17.z)
  • bug is in the state New, which is one of the valid states (NEW, ASSIGNED, POST)
  • release note text is set and does not match the template
  • dependent bug Jira Issue OCPBUGS-61773 is in the state Verified, which is one of the valid states (VERIFIED, RELEASE PENDING, CLOSED (ERRATA), CLOSED (CURRENT RELEASE), CLOSED (DONE), CLOSED (DONE-ERRATA))
  • dependent Jira Issue OCPBUGS-61773 targets the "4.18.z" version, which is one of the valid target versions: 4.18.0, 4.18.z
  • bug has dependents

Requesting review from QA contact:
/cc @wangke19

In response to this:

/jira refresh

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-ci openshift-ci bot requested a review from wangke19 October 27, 2025 13:35
@bertinatto
Copy link
Member

@bertinatto Fabio, could you please use your magic approval for this branch? This unfortunately needs to go to 4.16

Sorry, I missed this.

/lgtm
/label backport-risk-assessed

@openshift-ci openshift-ci bot added the backport-risk-assessed Indicates a PR to a release branch has been evaluated and considered safe to accept. label Oct 28, 2025
@openshift-ci openshift-ci bot added the lgtm Indicates that a PR is ready to be merged. label Oct 28, 2025
@openshift-ci
Copy link

openshift-ci bot commented Oct 28, 2025

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: bertinatto, openshift-cherrypick-robot

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:

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

@openshift-ci openshift-ci bot added the approved Indicates a PR has been approved by an approver from all required OWNERS files. label Oct 28, 2025
@bertinatto
Copy link
Member

/remove-label backports/unvalidated-commits

@openshift-ci openshift-ci bot removed the backports/unvalidated-commits Indicates that not all commits come to merged upstream PRs. label Oct 28, 2025
@wangke19
Copy link

wangke19 commented Oct 28, 2025

/verified by @wangke19
Checkout the code branch and run unit test TestAuditBackendRaceCondition with the race detector for verification:

$ go test -race ./staging/src/k8s.io/apiserver/pkg/endpoints/filters -run TestAuditBackendRaceCondition -v 
=== RUN   TestAuditBackendRaceCondition
=== RUN   TestAuditBackendRaceCondition/log_audit_backend
=== RUN   TestAuditBackendRaceCondition/buffered_audit_backend
=== RUN   TestAuditBackendRaceCondition/webhook_audit_backend
I1028 22:55:43.360215  121240 trace.go:236] Trace[1739845000]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:43.279) (total time: 80ms):
Trace[1739845000]: [80.439596ms] [80.439596ms] END
I1028 22:55:44.873151  121240 trace.go:236] Trace[498667006]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:44.792) (total time: 80ms):
Trace[498667006]: [80.797721ms] [80.797721ms] END
I1028 22:55:45.662570  121240 trace.go:236] Trace[364897206]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:45.582) (total time: 79ms):
Trace[364897206]: [79.839678ms] [79.839678ms] END
I1028 22:55:45.805816  121240 trace.go:236] Trace[2133991679]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:45.685) (total time: 119ms):
Trace[2133991679]: [119.845682ms] [119.845682ms] END
I1028 22:55:46.088485  121240 trace.go:236] Trace[605062838]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:45.987) (total time: 100ms):
Trace[605062838]: [100.616469ms] [100.616469ms] END
I1028 22:55:46.618240  121240 trace.go:236] Trace[1099125653]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:46.537) (total time: 80ms):
Trace[1099125653]: [80.485331ms] [80.485331ms] END
I1028 22:55:46.903365  121240 trace.go:236] Trace[2079044253]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:46.822) (total time: 80ms):
Trace[2079044253]: [80.891632ms] [80.891632ms] END
I1028 22:55:47.024544  121240 trace.go:236] Trace[1019265882]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:46.904) (total time: 120ms):
Trace[1019265882]: [120.371002ms] [120.371002ms] END
I1028 22:55:47.332058  121240 trace.go:236] Trace[1195028929]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:47.251) (total time: 80ms):
Trace[1195028929]: [80.69471ms] [80.69471ms] END
I1028 22:55:47.453213  121240 trace.go:236] Trace[829257601]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:47.352) (total time: 100ms):
Trace[829257601]: [100.163031ms] [100.163031ms] END
I1028 22:55:47.881771  121240 trace.go:236] Trace[1653919758]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:47.801) (total time: 80ms):
Trace[1653919758]: [80.130414ms] [80.130414ms] END
I1028 22:55:48.002884  121240 trace.go:236] Trace[1875328073]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:47.901) (total time: 100ms):
Trace[1875328073]: [100.963249ms] [100.963249ms] END
I1028 22:55:48.153596  121240 trace.go:236] Trace[1411127422]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:48.043) (total time: 110ms):
Trace[1411127422]: [110.229471ms] [110.229471ms] END
I1028 22:55:48.576030  121240 trace.go:236] Trace[1531148940]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:48.474) (total time: 101ms):
Trace[1531148940]: [101.033175ms] [101.033175ms] END
I1028 22:55:48.720888  121240 trace.go:236] Trace[1297738050]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:48.576) (total time: 144ms):
Trace[1297738050]: [144.379278ms] [144.379278ms] END
I1028 22:55:49.046386  121240 trace.go:236] Trace[724028096]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:48.965) (total time: 80ms):
Trace[724028096]: [80.631075ms] [80.631075ms] END
I1028 22:55:49.871573  121240 trace.go:236] Trace[1376564407]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:49.767) (total time: 103ms):
Trace[1376564407]: [103.399405ms] [103.399405ms] END
I1028 22:55:50.148604  121240 trace.go:236] Trace[2090697758]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:50.007) (total time: 141ms):
Trace[2090697758]: [141.303072ms] [141.303072ms] END
I1028 22:55:50.341874  121240 trace.go:236] Trace[1065430396]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:50.194) (total time: 147ms):
Trace[1065430396]: [147.202655ms] [147.202655ms] END
I1028 22:55:50.462918  121240 trace.go:236] Trace[782794117]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:50.361) (total time: 100ms):
Trace[782794117]: [100.745546ms] [100.745546ms] END
I1028 22:55:50.971183  121240 trace.go:236] Trace[1588674784]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:50.870) (total time: 100ms):
Trace[1588674784]: [100.978014ms] [100.978014ms] END
I1028 22:55:51.092328  121240 trace.go:236] Trace[1904865062]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:50.991) (total time: 101ms):
Trace[1904865062]: [101.070967ms] [101.070967ms] END
I1028 22:55:51.294257  121240 trace.go:236] Trace[788459830]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:51.152) (total time: 141ms):
Trace[788459830]: [141.345143ms] [141.345143ms] END
I1028 22:55:51.482911  121240 trace.go:236] Trace[131103768]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:51.334) (total time: 148ms):
Trace[131103768]: [148.222415ms] [148.222415ms] END
I1028 22:55:51.745168  121240 trace.go:236] Trace[225355263]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:51.604) (total time: 141ms):
Trace[225355263]: [141.036707ms] [141.036707ms] END
I1028 22:55:52.007872  121240 trace.go:236] Trace[448813396]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:51.886) (total time: 120ms):
Trace[448813396]: [120.751269ms] [120.751269ms] END
I1028 22:55:52.172981  121240 trace.go:236] Trace[1801213110]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:52.048) (total time: 123ms):
Trace[1801213110]: [123.965602ms] [123.965602ms] END
I1028 22:55:52.439019  121240 trace.go:236] Trace[434404721]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:52.334) (total time: 104ms):
Trace[434404721]: [104.498662ms] [104.498662ms] END
I1028 22:55:52.611614  121240 trace.go:236] Trace[1618080286]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:52.469) (total time: 142ms):
Trace[1618080286]: [142.036347ms] [142.036347ms] END
I1028 22:55:52.883581  121240 trace.go:236] Trace[906816341]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:52.745) (total time: 137ms):
Trace[906816341]: [137.749799ms] [137.749799ms] END
I1028 22:55:53.329918  121240 trace.go:236] Trace[1623303402]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:53.168) (total time: 161ms):
Trace[1623303402]: [161.599816ms] [161.599816ms] END
I1028 22:55:53.453340  121240 trace.go:236] Trace[136836329]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:53.330) (total time: 122ms):
Trace[136836329]: [122.412564ms] [122.412564ms] END
I1028 22:55:53.930104  121240 trace.go:236] Trace[95729575]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:53.850) (total time: 79ms):
Trace[95729575]: [79.878363ms] [79.878363ms] END
I1028 22:55:54.114030  121240 trace.go:236] Trace[21898096]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:53.973) (total time: 140ms):
Trace[21898096]: [140.466154ms] [140.466154ms] END
I1028 22:55:54.479025  121240 trace.go:236] Trace[579383137]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:54.315) (total time: 163ms):
Trace[579383137]: [163.098136ms] [163.098136ms] END
I1028 22:55:55.364015  121240 trace.go:236] Trace[462281250]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:55.263) (total time: 100ms):
Trace[462281250]: [100.693702ms] [100.693702ms] END
I1028 22:55:56.105103  121240 trace.go:236] Trace[343325889]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:55.961) (total time: 143ms):
Trace[343325889]: [143.669572ms] [143.669572ms] END
I1028 22:55:56.529002  121240 trace.go:236] Trace[988518012]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:56.407) (total time: 121ms):
Trace[988518012]: [121.129669ms] [121.129669ms] END
I1028 22:55:56.712981  121240 trace.go:236] Trace[1605909841]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:56.549) (total time: 163ms):
Trace[1605909841]: [163.45555ms] [163.45555ms] END
I1028 22:55:57.424477  121240 trace.go:236] Trace[1672937705]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:57.303) (total time: 121ms):
Trace[1672937705]: [121.113678ms] [121.113678ms] END
I1028 22:55:57.943522  121240 trace.go:236] Trace[1911978595]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:57.862) (total time: 80ms):
Trace[1911978595]: [80.805272ms] [80.805272ms] END
I1028 22:55:58.916463  121240 trace.go:236] Trace[923897496]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:58.773) (total time: 142ms):
Trace[923897496]: [142.485902ms] [142.485902ms] END
I1028 22:55:59.112368  121240 trace.go:236] Trace[1258552763]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:58.936) (total time: 175ms):
Trace[1258552763]: [175.514819ms] [175.514819ms] END
I1028 22:55:59.257023  121240 trace.go:236] Trace[20501882]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:59.134) (total time: 122ms):
Trace[20501882]: [122.394958ms] [122.394958ms] END
I1028 22:55:59.782111  121240 trace.go:236] Trace[534124607]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:59.620) (total time: 161ms):
Trace[534124607]: [161.555316ms] [161.555316ms] END
I1028 22:55:59.976956  121240 trace.go:236] Trace[1003665816]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:59.855) (total time: 121ms):
Trace[1003665816]: [121.226613ms] [121.226613ms] END
I1028 22:56:00.098416  121240 trace.go:236] Trace[2083839668]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:59.977) (total time: 120ms):
Trace[2083839668]: [120.825804ms] [120.825804ms] END
I1028 22:56:00.340940  121240 trace.go:236] Trace[1834964579]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:56:00.139) (total time: 201ms):
Trace[1834964579]: [201.324829ms] [201.324829ms] END
I1028 22:56:00.502547  121240 trace.go:236] Trace[13663005]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:56:00.360) (total time: 141ms):
Trace[13663005]: [141.579741ms] [141.579741ms] END
I1028 22:56:00.689707  121240 trace.go:236] Trace[676266562]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:56:00.527) (total time: 162ms):
Trace[676266562]: [162.407541ms] [162.407541ms] END
I1028 22:56:01.214970  121240 trace.go:236] Trace[1293210646]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:56:01.033) (total time: 181ms):
Trace[1293210646]: [181.605081ms] [181.605081ms] END
I1028 22:56:01.359275  121240 trace.go:236] Trace[1219652526]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:56:01.215) (total time: 143ms):
Trace[1219652526]: [143.587974ms] [143.587974ms] END
I1028 22:56:01.570956  121240 trace.go:236] Trace[828164355]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:56:01.409) (total time: 161ms):
Trace[828164355]: [161.409832ms] [161.409832ms] END
I1028 22:56:02.286877  121240 trace.go:236] Trace[1704842792]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:56:02.145) (total time: 141ms):
Trace[1704842792]: [141.108488ms] [141.108488ms] END
I1028 22:56:02.651400  121240 trace.go:236] Trace[1369325528]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:56:02.491) (total time: 160ms):
Trace[1369325528]: [160.086139ms] [160.086139ms] END
I1028 22:56:03.243515  121240 trace.go:236] Trace[7648089]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:56:03.044) (total time: 198ms):
Trace[7648089]: [198.889164ms] [198.889164ms] END
I1028 22:56:03.387823  121240 trace.go:236] Trace[472648025]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:56:03.266) (total time: 121ms):
Trace[472648025]: [121.160284ms] [121.160284ms] END
I1028 22:56:03.853265  121240 trace.go:236] Trace[1509779201]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:56:03.691) (total time: 161ms):
Trace[1509779201]: [161.39262ms] [161.39262ms] END
I1028 22:56:04.049757  121240 trace.go:236] Trace[1666448130]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:56:03.881) (total time: 168ms):
Trace[1666448130]: [168.186592ms] [168.186592ms] END
I1028 22:56:04.586258  121240 trace.go:236] Trace[397649700]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:56:04.464) (total time: 121ms):
Trace[397649700]: [121.193311ms] [121.193311ms] END
I1028 22:56:04.811135  121240 trace.go:236] Trace[1170791713]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:56:04.627) (total time: 183ms):
Trace[1170791713]: [183.806045ms] [183.806045ms] END
I1028 22:56:05.033313  121240 trace.go:236] Trace[566877631]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:56:04.872) (total time: 160ms):
Trace[566877631]: [160.654672ms] [160.654672ms] END
I1028 22:56:05.214751  121240 trace.go:236] Trace[758886279]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:56:05.053) (total time: 161ms):
Trace[758886279]: [161.351659ms] [161.351659ms] END
I1028 22:56:07.015021  121240 trace.go:236] Trace[475061600]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:56:06.791) (total time: 222ms):
Trace[475061600]: [222.852059ms] [222.852059ms] END
I1028 22:56:07.199212  121240 trace.go:236] Trace[430062681]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:56:07.055) (total time: 143ms):
Trace[430062681]: [143.292316ms] [143.292316ms] END
I1028 22:56:08.234970  121240 trace.go:236] Trace[1243082044]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:56:08.072) (total time: 162ms):
Trace[1243082044]: [162.209163ms] [162.209163ms] END
=== RUN   TestAuditBackendRaceCondition/union_audit_backend
--- PASS: TestAuditBackendRaceCondition (120.17s)
    --- PASS: TestAuditBackendRaceCondition/log_audit_backend (30.01s)
    --- PASS: TestAuditBackendRaceCondition/buffered_audit_backend (30.00s)
    --- PASS: TestAuditBackendRaceCondition/webhook_audit_backend (30.15s)
    --- PASS: TestAuditBackendRaceCondition/union_audit_backend (30.01s)
PASS
ok  	k8s.io/apiserver/pkg/endpoints/filters	121.302s

The above test log shows TestAuditBackendRaceCondition is passing but is extremely slow, with each sub-test taking about 30 seconds. This points to a timeout being hit repeatedly, which suggests a performance regression in the audit webhook backend, likely introduced by the backported changes mentioned in the commit message.

The current commit fixes a broken test due to the backport but does not address the underlying performance problem. To understand the cause of the slowdown, we need to examine the implementation of
TestAuditBackendRaceCondition in staging/src/k8s.io/apiserver/pkg/endpoints/filters/audit_test.go.

Analyzed TestAuditBackendRaceCondition and found it's designed to run for 30 seconds per backend, matching the wait.ForeverTestTimeout value. The slowness isn't a bug, but a test characteristic.
The webhook_audit_backend's trace logs show delays (80-322ms) exceeding the fake backend's 10ms sleep, likely due to the flowcontrol.NewTokenBucketRateLimiter throttling requests in the test's tight loop. While not a failure, this long-running test impacts CI/CD performance. The recent commit is unrelated.

Conclusion:

The TestAuditBackendRaceCondition test's slowness is by design, using a 30-second timeout. It's not a bug, but an inefficient test. The webhook delays are likely due to rate-limiting from high-frequency requests. The last commit is unrelated.

@openshift-ci-robot openshift-ci-robot added the verified Signifies that the PR passed pre-merge verification criteria label Oct 28, 2025
@openshift-ci-robot
Copy link

@wangke19: This PR has been marked as verified by @wangke19.

In response to this:

/verified by @wangke19
Checkout the code branch and run unit test TestAuditBackendRaceCondition with the race detector for verification:

$ go test -race ./staging/src/k8s.io/apiserver/pkg/endpoints/filters -run TestAuditBackendRaceCondition -v 
=== RUN   TestAuditBackendRaceCondition
=== RUN   TestAuditBackendRaceCondition/log_audit_backend
=== RUN   TestAuditBackendRaceCondition/buffered_audit_backend
=== RUN   TestAuditBackendRaceCondition/webhook_audit_backend
I1028 22:55:43.360215  121240 trace.go:236] Trace[1739845000]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:43.279) (total time: 80ms):
Trace[1739845000]: [80.439596ms] [80.439596ms] END
I1028 22:55:44.873151  121240 trace.go:236] Trace[498667006]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:44.792) (total time: 80ms):
Trace[498667006]: [80.797721ms] [80.797721ms] END
I1028 22:55:45.662570  121240 trace.go:236] Trace[364897206]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:45.582) (total time: 79ms):
Trace[364897206]: [79.839678ms] [79.839678ms] END
I1028 22:55:45.805816  121240 trace.go:236] Trace[2133991679]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:45.685) (total time: 119ms):
Trace[2133991679]: [119.845682ms] [119.845682ms] END
I1028 22:55:46.088485  121240 trace.go:236] Trace[605062838]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:45.987) (total time: 100ms):
Trace[605062838]: [100.616469ms] [100.616469ms] END
I1028 22:55:46.618240  121240 trace.go:236] Trace[1099125653]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:46.537) (total time: 80ms):
Trace[1099125653]: [80.485331ms] [80.485331ms] END
I1028 22:55:46.903365  121240 trace.go:236] Trace[2079044253]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:46.822) (total time: 80ms):
Trace[2079044253]: [80.891632ms] [80.891632ms] END
I1028 22:55:47.024544  121240 trace.go:236] Trace[1019265882]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:46.904) (total time: 120ms):
Trace[1019265882]: [120.371002ms] [120.371002ms] END
I1028 22:55:47.332058  121240 trace.go:236] Trace[1195028929]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:47.251) (total time: 80ms):
Trace[1195028929]: [80.69471ms] [80.69471ms] END
I1028 22:55:47.453213  121240 trace.go:236] Trace[829257601]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:47.352) (total time: 100ms):
Trace[829257601]: [100.163031ms] [100.163031ms] END
I1028 22:55:47.881771  121240 trace.go:236] Trace[1653919758]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:47.801) (total time: 80ms):
Trace[1653919758]: [80.130414ms] [80.130414ms] END
I1028 22:55:48.002884  121240 trace.go:236] Trace[1875328073]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:47.901) (total time: 100ms):
Trace[1875328073]: [100.963249ms] [100.963249ms] END
I1028 22:55:48.153596  121240 trace.go:236] Trace[1411127422]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:48.043) (total time: 110ms):
Trace[1411127422]: [110.229471ms] [110.229471ms] END
I1028 22:55:48.576030  121240 trace.go:236] Trace[1531148940]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:48.474) (total time: 101ms):
Trace[1531148940]: [101.033175ms] [101.033175ms] END
I1028 22:55:48.720888  121240 trace.go:236] Trace[1297738050]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:48.576) (total time: 144ms):
Trace[1297738050]: [144.379278ms] [144.379278ms] END
I1028 22:55:49.046386  121240 trace.go:236] Trace[724028096]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:48.965) (total time: 80ms):
Trace[724028096]: [80.631075ms] [80.631075ms] END
I1028 22:55:49.871573  121240 trace.go:236] Trace[1376564407]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:49.767) (total time: 103ms):
Trace[1376564407]: [103.399405ms] [103.399405ms] END
I1028 22:55:50.148604  121240 trace.go:236] Trace[2090697758]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:50.007) (total time: 141ms):
Trace[2090697758]: [141.303072ms] [141.303072ms] END
I1028 22:55:50.341874  121240 trace.go:236] Trace[1065430396]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:50.194) (total time: 147ms):
Trace[1065430396]: [147.202655ms] [147.202655ms] END
I1028 22:55:50.462918  121240 trace.go:236] Trace[782794117]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:50.361) (total time: 100ms):
Trace[782794117]: [100.745546ms] [100.745546ms] END
I1028 22:55:50.971183  121240 trace.go:236] Trace[1588674784]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:50.870) (total time: 100ms):
Trace[1588674784]: [100.978014ms] [100.978014ms] END
I1028 22:55:51.092328  121240 trace.go:236] Trace[1904865062]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:50.991) (total time: 101ms):
Trace[1904865062]: [101.070967ms] [101.070967ms] END
I1028 22:55:51.294257  121240 trace.go:236] Trace[788459830]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:51.152) (total time: 141ms):
Trace[788459830]: [141.345143ms] [141.345143ms] END
I1028 22:55:51.482911  121240 trace.go:236] Trace[131103768]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:51.334) (total time: 148ms):
Trace[131103768]: [148.222415ms] [148.222415ms] END
I1028 22:55:51.745168  121240 trace.go:236] Trace[225355263]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:51.604) (total time: 141ms):
Trace[225355263]: [141.036707ms] [141.036707ms] END
I1028 22:55:52.007872  121240 trace.go:236] Trace[448813396]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:51.886) (total time: 120ms):
Trace[448813396]: [120.751269ms] [120.751269ms] END
I1028 22:55:52.172981  121240 trace.go:236] Trace[1801213110]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:52.048) (total time: 123ms):
Trace[1801213110]: [123.965602ms] [123.965602ms] END
I1028 22:55:52.439019  121240 trace.go:236] Trace[434404721]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:52.334) (total time: 104ms):
Trace[434404721]: [104.498662ms] [104.498662ms] END
I1028 22:55:52.611614  121240 trace.go:236] Trace[1618080286]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:52.469) (total time: 142ms):
Trace[1618080286]: [142.036347ms] [142.036347ms] END
I1028 22:55:52.883581  121240 trace.go:236] Trace[906816341]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:52.745) (total time: 137ms):
Trace[906816341]: [137.749799ms] [137.749799ms] END
I1028 22:55:53.329918  121240 trace.go:236] Trace[1623303402]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:53.168) (total time: 161ms):
Trace[1623303402]: [161.599816ms] [161.599816ms] END
I1028 22:55:53.453340  121240 trace.go:236] Trace[136836329]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:53.330) (total time: 122ms):
Trace[136836329]: [122.412564ms] [122.412564ms] END
I1028 22:55:53.930104  121240 trace.go:236] Trace[95729575]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:53.850) (total time: 79ms):
Trace[95729575]: [79.878363ms] [79.878363ms] END
I1028 22:55:54.114030  121240 trace.go:236] Trace[21898096]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:53.973) (total time: 140ms):
Trace[21898096]: [140.466154ms] [140.466154ms] END
I1028 22:55:54.479025  121240 trace.go:236] Trace[579383137]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:54.315) (total time: 163ms):
Trace[579383137]: [163.098136ms] [163.098136ms] END
I1028 22:55:55.364015  121240 trace.go:236] Trace[462281250]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:55.263) (total time: 100ms):
Trace[462281250]: [100.693702ms] [100.693702ms] END
I1028 22:55:56.105103  121240 trace.go:236] Trace[343325889]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:55.961) (total time: 143ms):
Trace[343325889]: [143.669572ms] [143.669572ms] END
I1028 22:55:56.529002  121240 trace.go:236] Trace[988518012]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:56.407) (total time: 121ms):
Trace[988518012]: [121.129669ms] [121.129669ms] END
I1028 22:55:56.712981  121240 trace.go:236] Trace[1605909841]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:56.549) (total time: 163ms):
Trace[1605909841]: [163.45555ms] [163.45555ms] END
I1028 22:55:57.424477  121240 trace.go:236] Trace[1672937705]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:57.303) (total time: 121ms):
Trace[1672937705]: [121.113678ms] [121.113678ms] END
I1028 22:55:57.943522  121240 trace.go:236] Trace[1911978595]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:57.862) (total time: 80ms):
Trace[1911978595]: [80.805272ms] [80.805272ms] END
I1028 22:55:58.916463  121240 trace.go:236] Trace[923897496]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:58.773) (total time: 142ms):
Trace[923897496]: [142.485902ms] [142.485902ms] END
I1028 22:55:59.112368  121240 trace.go:236] Trace[1258552763]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:58.936) (total time: 175ms):
Trace[1258552763]: [175.514819ms] [175.514819ms] END
I1028 22:55:59.257023  121240 trace.go:236] Trace[20501882]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:59.134) (total time: 122ms):
Trace[20501882]: [122.394958ms] [122.394958ms] END
I1028 22:55:59.782111  121240 trace.go:236] Trace[534124607]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:59.620) (total time: 161ms):
Trace[534124607]: [161.555316ms] [161.555316ms] END
I1028 22:55:59.976956  121240 trace.go:236] Trace[1003665816]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:59.855) (total time: 121ms):
Trace[1003665816]: [121.226613ms] [121.226613ms] END
I1028 22:56:00.098416  121240 trace.go:236] Trace[2083839668]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:55:59.977) (total time: 120ms):
Trace[2083839668]: [120.825804ms] [120.825804ms] END
I1028 22:56:00.340940  121240 trace.go:236] Trace[1834964579]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:56:00.139) (total time: 201ms):
Trace[1834964579]: [201.324829ms] [201.324829ms] END
I1028 22:56:00.502547  121240 trace.go:236] Trace[13663005]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:56:00.360) (total time: 141ms):
Trace[13663005]: [141.579741ms] [141.579741ms] END
I1028 22:56:00.689707  121240 trace.go:236] Trace[676266562]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:56:00.527) (total time: 162ms):
Trace[676266562]: [162.407541ms] [162.407541ms] END
I1028 22:56:01.214970  121240 trace.go:236] Trace[1293210646]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:56:01.033) (total time: 181ms):
Trace[1293210646]: [181.605081ms] [181.605081ms] END
I1028 22:56:01.359275  121240 trace.go:236] Trace[1219652526]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:56:01.215) (total time: 143ms):
Trace[1219652526]: [143.587974ms] [143.587974ms] END
I1028 22:56:01.570956  121240 trace.go:236] Trace[828164355]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:56:01.409) (total time: 161ms):
Trace[828164355]: [161.409832ms] [161.409832ms] END
I1028 22:56:02.286877  121240 trace.go:236] Trace[1704842792]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:56:02.145) (total time: 141ms):
Trace[1704842792]: [141.108488ms] [141.108488ms] END
I1028 22:56:02.651400  121240 trace.go:236] Trace[1369325528]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:56:02.491) (total time: 160ms):
Trace[1369325528]: [160.086139ms] [160.086139ms] END
I1028 22:56:03.243515  121240 trace.go:236] Trace[7648089]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:56:03.044) (total time: 198ms):
Trace[7648089]: [198.889164ms] [198.889164ms] END
I1028 22:56:03.387823  121240 trace.go:236] Trace[472648025]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:56:03.266) (total time: 121ms):
Trace[472648025]: [121.160284ms] [121.160284ms] END
I1028 22:56:03.853265  121240 trace.go:236] Trace[1509779201]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:56:03.691) (total time: 161ms):
Trace[1509779201]: [161.39262ms] [161.39262ms] END
I1028 22:56:04.049757  121240 trace.go:236] Trace[1666448130]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:56:03.881) (total time: 168ms):
Trace[1666448130]: [168.186592ms] [168.186592ms] END
I1028 22:56:04.586258  121240 trace.go:236] Trace[397649700]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:56:04.464) (total time: 121ms):
Trace[397649700]: [121.193311ms] [121.193311ms] END
I1028 22:56:04.811135  121240 trace.go:236] Trace[1170791713]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:56:04.627) (total time: 183ms):
Trace[1170791713]: [183.806045ms] [183.806045ms] END
I1028 22:56:05.033313  121240 trace.go:236] Trace[566877631]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:56:04.872) (total time: 160ms):
Trace[566877631]: [160.654672ms] [160.654672ms] END
I1028 22:56:05.214751  121240 trace.go:236] Trace[758886279]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:56:05.053) (total time: 161ms):
Trace[758886279]: [161.351659ms] [161.351659ms] END
I1028 22:56:07.015021  121240 trace.go:236] Trace[475061600]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:56:06.791) (total time: 222ms):
Trace[475061600]: [222.852059ms] [222.852059ms] END
I1028 22:56:07.199212  121240 trace.go:236] Trace[430062681]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:56:07.055) (total time: 143ms):
Trace[430062681]: [143.292316ms] [143.292316ms] END
I1028 22:56:08.234970  121240 trace.go:236] Trace[1243082044]: "Call Audit Events webhook" name:dynamic_webhook,event-count:1 (28-Oct-2025 22:56:08.072) (total time: 162ms):
Trace[1243082044]: [162.209163ms] [162.209163ms] END
=== RUN   TestAuditBackendRaceCondition/union_audit_backend
--- PASS: TestAuditBackendRaceCondition (120.17s)
   --- PASS: TestAuditBackendRaceCondition/log_audit_backend (30.01s)
   --- PASS: TestAuditBackendRaceCondition/buffered_audit_backend (30.00s)
   --- PASS: TestAuditBackendRaceCondition/webhook_audit_backend (30.15s)
   --- PASS: TestAuditBackendRaceCondition/union_audit_backend (30.01s)
PASS
ok  	k8s.io/apiserver/pkg/endpoints/filters	121.302s

The above test log shows TestAuditBackendRaceCondition is passing but is extremely slow, with each sub-test taking about 30 seconds. This points to a timeout being hit repeatedly, which suggests a
performance regression in the audit webhook backend, likely introduced by the backported changes mentioned in the commit message.

The current commit fixes a broken test due to the backport but does not address the underlying performance problem. To understand the cause of the slowdown, we need to examine the implementation of
TestAuditBackendRaceCondition in staging/src/k8s.io/apiserver/pkg/endpoints/filters/audit_test.go.

Analyzed TestAuditBackendRaceCondition and found it's designed to run for 30 seconds per backend, matching the wait.ForeverTestTimeout value. The slowness isn't a bug, but a test characteristic.
The webhook_audit_backend's trace logs show delays (80-322ms) exceeding the fake backend's 10ms sleep, likely due to the flowcontrol.NewTokenBucketRateLimiter throttling requests in the test's tight
loop. While not a failure, this long-running test impacts CI/CD performance. The recent commit is unrelated.

Conclusion:

The TestAuditBackendRaceCondition test's slowness is by design, using a 30-second timeout. It's not a bug, but an inefficient test. The webhook delays are likely due to rate-limiting from
high-frequency requests. The last commit is unrelated.

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-merge-bot openshift-merge-bot bot merged commit ac453ed into openshift:release-4.17 Oct 28, 2025
18 checks passed
@openshift-ci-robot
Copy link

@openshift-cherrypick-robot: Jira Issue Verification Checks: Jira Issue OCPBUGS-63460
✔️ This pull request was pre-merge verified.
✔️ All associated pull requests have merged.
✔️ All associated, merged pull requests were pre-merge verified.

Jira Issue OCPBUGS-63460 has been moved to the MODIFIED state and will move to the VERIFIED state when the change is available in an accepted nightly payload. 🕓

In response to this:

This is an automated cherry-pick of #2475

/assign tjungblu

/cherrypick release-4.16

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-cherrypick-robot
Copy link
Author

@openshift-cherrypick-robot: #2496 failed to apply on top of branch "release-4.16":

Applying: UPSTREAM: 129472: Fix API server crash on concurrent map iteration and write
Using index info to reconstruct a base tree...
M	pkg/registry/core/serviceaccount/storage/storage_test.go
M	staging/src/k8s.io/apiserver/pkg/endpoints/filters/request_deadline.go
Falling back to patching base and 3-way merge...
Auto-merging staging/src/k8s.io/apiserver/pkg/endpoints/filters/request_deadline.go
Auto-merging pkg/registry/core/serviceaccount/storage/storage_test.go
CONFLICT (content): Merge conflict in pkg/registry/core/serviceaccount/storage/storage_test.go
error: Failed to merge in the changes.
hint: Use 'git am --show-current-patch=diff' to see the failed patch
hint: When you have resolved this problem, run "git am --continue".
hint: If you prefer to skip this patch, run "git am --skip" instead.
hint: To restore the original branch and stop patching, run "git am --abort".
hint: Disable this message with "git config advice.mergeConflict false"
Patch failed at 0001 UPSTREAM: 129472: Fix API server crash on concurrent map iteration and write

In response to this:

This is an automated cherry-pick of #2475

/assign tjungblu

/cherrypick release-4.16

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-sigs/prow repository.

@openshift-merge-robot
Copy link

Fix included in accepted release 4.17.0-0.nightly-2025-10-28-172133

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

approved Indicates a PR has been approved by an approver from all required OWNERS files. backport-risk-assessed Indicates a PR to a release branch has been evaluated and considered safe to accept. jira/valid-bug Indicates that a referenced Jira bug is valid for the branch this PR is targeting. jira/valid-reference Indicates that this PR references a valid Jira ticket of any type. lgtm Indicates that a PR is ready to be merged. vendor-update Touching vendor dir or related files verified Signifies that the PR passed pre-merge verification criteria

Projects

None yet

Development

Successfully merging this pull request may close these issues.