flake: TestCachedResources

[mjudeikis]

Describe the bug

achedresources_test.go:285: Ensure that there are no Sheriffs in "1kwzyq277tk0cqnz"
    vr_cachedresources_test.go:285: Ensure that there are no Sheriffs in "j758e15y6tuaspg5"
    vr_cachedresources_test.go:291: Verify watching and wildcards work
    vr_cachedresources_test.go:309: Creating a wildcard watch for sheriffs against "https://127.0.0.1:6443/services/apiexport/9k4x3f7p0ce6mdyc/cached-wildwest-provider"
    vr_cachedresources_test.go:342: Creating a Sheriff in "root:e2e-workspace-rwd6f:e2e-workspace-z6l2c"
    assertions.go:1949: Waiting for condition, but got: expected to see 2 sheriffs from wildcard watches, got 0
    vr_cachedresources_test.go:357: 
        	Error Trace:	/home/prow/go/src/github.com/kcp-dev/kcp/staging/src/github.com/kcp-dev/sdk/testing/helpers/eventually.go:40
        	            				/home/prow/go/src/github.com/kcp-dev/kcp/test/e2e/virtualresources/cachedresources/vr_cachedresources_test.go:357
        	Error:      	Condition never satisfied
        	Test:       	TestCachedResources
        	Messages:   	waiting for two sheriffs
DONE 229 tests, 4 skipped, 2 failures in 358.510s
I0203 07:51:47.354396   19535 shard.go:248] "gathering shard metrics" shard="kcp"
I0203 07:51:47.546076   19535 shard.go:272] "writing metrics file" shard="kcp" path="/logs/artifacts/kcp/kcp-metrics.txt"
I0203 07:51:47.548947   19535 shard.go:277] "wrote metrics file" shard="kcp" path="/logs/artifacts/kcp/kcp-metrics.txt"
make: *** [Makefile:350: test-e2e-shared-minimal] Error 1
+ EXIT_CODE=2

Steps To Reproduce

This is CI flake:
https://public-prow.kcp.k8c.io/view/s3/prow-public-data/pr-logs/pull/kcp-dev_kcp/3808/pull-kcp-test-e2e-shared/2018590003830984704

Expected Behaviour

work

Additional Context

No response

[neolit123]

/kind flake

[neolit123]

i am able to get it to panic due to concurrent writes locally but not with the error from CI.

go test -test.fullpath=true -timeout 60s -coverprofile=/tmp/vscode-goBDx9wU/go-code-cover -run ^TestCachedResources$ github.com/kcp-dev/kcp/test/e2e/virtualresources/cachedresources -v -c

stress ./cachedresources.test
...
9m45s: 210 runs so far, 2 failures (0.95%), 24 active
9m50s: 210 runs so far, 2 failures (0.95%), 24 active
9m55s: 212 runs so far, 2 failures (0.94%), 24 active
10m0s: 213 runs so far, 2 failures (0.94%), 24 active
10m5s: 214 runs so far, 2 failures (0.93%), 24 active

        I0204 16:19:15.697106  177814 httplog.go:134] "HTTP" verb="GET" URI="/services/cache/shards/root/clusters/33yb8rnnmcw88wm1/apis/cache.kcp.io/v1alpha1/cachedresourceendpointslices/sheriffs.wildwest.dev" latency="3.026722ms" userAgent="kcp/v0.0.0 (linux/amd64) kubernetes/$Format" audit-ID="0e8fa53e-2db2-497f-b0b3-60dba0a94aac" srcIP="127.0.0.1:48936" resp=200
        I0204 16:19:15.714317  177814 httplog.go:134] "HTTP" verb="GET" URI="/services/replication/33yb8rnnmcw88wm1/sheriffs.wildwest.dev/clusters/%2A/apis/wildwest.dev/v1alpha1" latency="15.84844ms" userAgent="kcp/v0.0.0 (linux/amd64) kubernetes/$Format/kcp-virtual-resources-apiserver" audit-ID="7570b2c4-092c-4d0f-80fe-d2c4e01bf214" srcIP="127.0.0.1:48936" resp=200
        I0204 16:19:15.715943  177814 httplog.go:134] "HTTP" verb="GET" URI="/clusters/2gbfe3v0nj7t3zc8/apis/wildwest.dev/v1alpha1" latency="24.09226ms" userAgent="cachedresources.test/v0.0.0 (linux/amd64) kubernetes/$Format/TestCachedResources" audit-ID="206f91e5-2c2b-4de7-893c-3df8c5f5111f" srcIP="127.0.0.1:48792" apf_pl="catch-all" apf_fs="catch-all" apf_iseats=1 apf_fseats=0 apf_additionalLatency="0s" apf_execution_time="23.149835ms" resp=200
        I0204 16:19:15.719319  177814 httplog.go:134] "HTTP" verb="GET" URI="/readyz" latency="1.632348ms" userAgent="cachedresources.test/v0.0.0 (linux/amd64) kubernetes/$Format/TestCachedResources" audit-ID="021b678b-fd2d-4f14-adf8-681f0d4da452" srcIP="127.0.0.1:48792" apf_pl="exempt" apf_fs="exempt" apf_iseats=1 apf_fseats=0 apf_additionalLatency="0s" apf_execution_time="1.278541ms" resp=200
        I0204 16:19:15.782241  177814 httplog.go:134] "HTTP" verb="GET" URI="/livez" latency="464.895µs" userAgent="cachedresources.test/v0.0.0 (linux/amd64) kubernetes/$Format/TestCachedResources" audit-ID="28f552b2-926a-4571-816a-7eb9e5667be4" srcIP="127.0.0.1:48792" apf_pl="exempt" apf_fs="exempt" apf_iseats=1 apf_fseats=0 apf_additionalLatency="0s" apf_execution_time="106.827µs" resp=200
        fatal error: concurrent map writes
        
        goroutine 58385 [running]:
        internal/runtime/maps.fatal({0x44274f0?, 0x0?})
        	/usr/local/go/src/runtime/panic.go:1046 +0x18
        internal/runtime/maps.(*Map).Delete(0xc0013e4960, 0x4137f20, 0xc013150750)
        	/usr/local/go/src/internal/runtime/maps/map.go:652 +0x4c

this can be done for this test IMO, and i will PR it:

diff --git a/test/e2e/virtualresources/cachedresources/vr_cachedresources_test.go b/test/e2e/virtualresources/cachedresources/vr_cachedresources_test.go
index ad8b5f772..bc1bd81f7 100644
--- a/test/e2e/virtualresources/cachedresources/vr_cachedresources_test.go
+++ b/test/e2e/virtualresources/cachedresources/vr_cachedresources_test.go
@@ -364,7 +364,7 @@ func TestCachedResources(t *testing.T) {
                        }
                }
                return true, ""
-       }, wait.ForeverTestTimeout, time.Second*1, "waiting for two sheriffs")
+       }, wait.ForeverTestTimeout*2, time.Millisecond*500, "waiting for two sheriffs")

        t.Log("Stopping watches")
        for _, stop := range watchStopFuncs {

additional comment from me is that t.Parallel() might not be a good idea for some of the more complicated tests. it can starve the prow pod for resources, and various weird bugs can happen too. i guess the same can happen in prod, but usually people have obs tools if they care.

[gman0]

It seems we're not of the woods yet (for example #3808). Let's reopen and see.