Counter.WithContext: data race #128548
Description
What happened?
I ran integration tests with race detection enabled (#116980).
k8s.io/kubernetes/test/integration/storageversionmigrator failed with a data race (https://prow.k8s.io/view/gs/kubernetes-ci-logs/pr-logs/pull/116980/pull-kubernetes-integration/1853468672903876608):
Write at 0x00c000514d20 by goroutine 326096:
k8s.io/component-base/metrics.(*Counter).WithContext()
/home/prow/go/src/k8s.io/kubernetes/staging/src/k8s.io/component-base/metrics/counter.go:110 +0xb5e
k8s.io/apiserver/pkg/audit.ObserveEvent()
/home/prow/go/src/k8s.io/kubernetes/staging/src/k8s.io/apiserver/pkg/audit/metrics.go:89 +0xb40
k8s.io/apiserver/pkg/endpoints/filters.processAuditEvent()
/home/prow/go/src/k8s.io/kubernetes/staging/src/k8s.io/apiserver/pkg/endpoints/filters/audit.go:197 +0xb3f
k8s.io/apiserver/pkg/server.DefaultBuildHandlerChain.WithAudit.func6.1()
/home/prow/go/src/k8s.io/kubernetes/staging/src/k8s.io/apiserver/pkg/endpoints/filters/audit.go:113 +0x6fe
runtime.deferreturn()
/usr/local/go/src/runtime/panic.go:605 +0x5d
net/http.HandlerFunc.ServeHTTP()
/usr/local/go/src/net/http/server.go:2220 +0x47
k8s.io/apiserver/pkg/endpoints/filterlatency.trackStarted.func1()
/home/prow/go/src/k8s.io/kubernetes/staging/src/k8s.io/apiserver/pkg/endpoints/filterlatency/filterlatency.go:84 +0x23c
net/http.HandlerFunc.ServeHTTP()
/usr/local/go/src/net/http/server.go:2220 +0x47
k8s.io/apiserver/pkg/server.DefaultBuildHandlerChain.TrackCompleted.trackCompleted.func27.deferwrap1()
/home/prow/go/src/k8s.io/kubernetes/staging/src/k8s.io/apiserver/pkg/endpoints/filterlatency/filterlatency.go:103 +0x6f
runtime.deferreturn()
/usr/local/go/src/runtime/panic.go:605 +0x5d
net/http.HandlerFunc.ServeHTTP()
/usr/local/go/src/net/http/server.go:2220 +0x47
k8s.io/apiserver/pkg/endpoints/filters.withAuthentication.func1()
/home/prow/go/src/k8s.io/kubernetes/staging/src/k8s.io/apiserver/pkg/endpoints/filters/authentication.go:123 +0xd01
net/http.HandlerFunc.ServeHTTP()
/usr/local/go/src/net/http/server.go:2220 +0x47
k8s.io/apiserver/pkg/endpoints/filterlatency.trackStarted.func1()
/home/prow/go/src/k8s.io/kubernetes/staging/src/k8s.io/apiserver/pkg/endpoints/filterlatency/filterlatency.go:94 +0x4b5
net/http.HandlerFunc.ServeHTTP()
/usr/local/go/src/net/http/server.go:2220 +0x47
k8s.io/apiserver/pkg/server.DefaultBuildHandlerChain.WithWarningRecorder.func11()
/home/prow/go/src/k8s.io/kubernetes/staging/src/k8s.io/apiserver/pkg/endpoints/filters/warning.go:35 +0x11d
net/http.HandlerFunc.ServeHTTP()
/usr/local/go/src/net/http/server.go:2220 +0x47
k8s.io/apiserver/pkg/server/filters.(*timeoutHandler).ServeHTTP.func1()
/home/prow/go/src/k8s.io/kubernetes/staging/src/k8s.io/apiserver/pkg/server/filters/timeout.go:115 +0xd3
Previous write at 0x00c000514d20 by goroutine 326108:
k8s.io/component-base/metrics.(*Counter).WithContext()
/home/prow/go/src/k8s.io/kubernetes/staging/src/k8s.io/component-base/metrics/counter.go:110 +0xb5e
k8s.io/apiserver/pkg/audit.ObserveEvent()
/home/prow/go/src/k8s.io/kubernetes/staging/src/k8s.io/apiserver/pkg/audit/metrics.go:89 +0xb40
k8s.io/apiserver/pkg/endpoints/filters.processAuditEvent()
/home/prow/go/src/k8s.io/kubernetes/staging/src/k8s.io/apiserver/pkg/endpoints/filters/audit.go:197 +0xb3f
k8s.io/apiserver/pkg/server.DefaultBuildHandlerChain.WithAudit.func6.1()
/home/prow/go/src/k8s.io/kubernetes/staging/src/k8s.io/apiserver/pkg/endpoints/filters/audit.go:113 +0x6fe
runtime.deferreturn()
/usr/local/go/src/runtime/panic.go:605 +0x5d
net/http.HandlerFunc.ServeHTTP()
/usr/local/go/src/net/http/server.go:2220 +0x47
k8s.io/apiserver/pkg/endpoints/filterlatency.trackStarted.func1()
/home/prow/go/src/k8s.io/kubernetes/staging/src/k8s.io/apiserver/pkg/endpoints/filterlatency/filterlatency.go:84 +0x23c
net/http.HandlerFunc.ServeHTTP()
/usr/local/go/src/net/http/server.go:2220 +0x47
k8s.io/apiserver/pkg/server.DefaultBuildHandlerChain.TrackCompleted.trackCompleted.func27.deferwrap1()
/home/prow/go/src/k8s.io/kubernetes/staging/src/k8s.io/apiserver/pkg/endpoints/filterlatency/filterlatency.go:103 +0x6f
runtime.deferreturn()
/usr/local/go/src/runtime/panic.go:605 +0x5d
net/http.HandlerFunc.ServeHTTP()
/usr/local/go/src/net/http/server.go:2220 +0x47
k8s.io/apiserver/pkg/endpoints/filters.withAuthentication.func1()
/home/prow/go/src/k8s.io/kubernetes/staging/src/k8s.io/apiserver/pkg/endpoints/filters/authentication.go:123 +0xd01
net/http.HandlerFunc.ServeHTTP()
/usr/local/go/src/net/http/server.go:2220 +0x47
k8s.io/apiserver/pkg/endpoints/filterlatency.trackStarted.func1()
/home/prow/go/src/k8s.io/kubernetes/staging/src/k8s.io/apiserver/pkg/endpoints/filterlatency/filterlatency.go:94 +0x4b5
net/http.HandlerFunc.ServeHTTP()
/usr/local/go/src/net/http/server.go:2220 +0x47
k8s.io/apiserver/pkg/server.DefaultBuildHandlerChain.WithWarningRecorder.func11()
/home/prow/go/src/k8s.io/kubernetes/staging/src/k8s.io/apiserver/pkg/endpoints/filters/warning.go:35 +0x11d
net/http.HandlerFunc.ServeHTTP()
/usr/local/go/src/net/http/server.go:2220 +0x47
k8s.io/apiserver/pkg/server/filters.(*timeoutHandler).ServeHTTP.func1()
/home/prow/go/src/k8s.io/kubernetes/staging/src/k8s.io/apiserver/pkg/server/filters/timeout.go:115 +0xd3
What did you expect to happen?
No race.
How can we reproduce it (as minimally and precisely as possible)?
Run the integration test with go test -race.
Anything else we need to know?
This was introduced in #119949 three weeks ago.
/sig instrumentation
/cc @rexagod
Kubernetes version
master (soon 1.32)
Cloud provider
n/a
OS version
# On Linux:
$ cat /etc/os-release
# paste output here
$ uname -a
# paste output here
# On Windows:
C:\> wmic os get Caption, Version, BuildNumber, OSArchitecture
# paste output hereInstall tools
Container runtime (CRI) and version (if applicable)
Related plugins (CNI, CSI, ...) and versions (if applicable)
Metadata
Metadata
Assignees
Labels
Type
Projects
Status