Being able to call arbitrary functions is useful, even if it means giving up
some compile-time checking. Because we now use reflection,
Eventually/Consistently can be methods.
The "create 100 slices" E2E sometimes flaked with timeouts (e.g. 95 out of 100
slices created). It created too much load for an E2E test.
The same test now uses ktesting as API, which makes it possible to run it as
integration test with the original 100 slices and with more moderate 10 slices
as E2E test.
Manually pairing Being with End is too error prone to be useful. It had the
advantage of keeping variables created between them visible to the following
code, but that doesn't justify using those calls.
By using a callback we can achieve a few things:
- Code using it automatically shadows the parent tCtx, thus enforcing
that within a code block the tCtx with step is used consistently.
- The code block is clearly delineated with curly braces.
- When the code block ends, the unmodified parent tCtx is automatically
in scope again.
Downsides:
- Extra boilerplate for the anonymous function.
Python's `with tCtx.Step(...) as tCtx: ` would be nicer.
As an approximation of that `for tCtx := range tCtx.Step(...)` was
tried with `Step` returning an iterator, but that wasn't very idiomatic.
- Variables created inside the code block are not visible outside of it.
klog calls during init are becoming a problem because now test/e2e/framework
depends in test/utils/ktesting which bumps up the default verbosity during init
to make test output more complete when there is no argument parsing.
For cadvisor, an upstream fix is
needed (https://github.com/google/cadvisor/pull/3778). For kubectl we can make
it silently accept the valid (!) LC_ALL=C.
tCtx.Run and sub-tests make it much simpler to separate the different steps
than with Ginkgo because unless a test runs tCtx.Parallel (which we don't do
here), everything runs sequentially in a deterministic order.
Right now we get:
...
localupcluster.go:285: I1210 12:24:22.067524] bring up v1.34: stopping kubelet
localupcluster.go:285: I1210 12:24:22.067548] bring up v1.34: stopping kube-scheduler
localupcluster.go:285: I1210 12:24:22.067570] bring up v1.34: stopping kube-controller-manager
localupcluster.go:285: I1210 12:24:22.067589] bring up v1.34: stopping kube-apiserver
--- PASS: TestUpgradeDowngrade (94.78s)
--- PASS: TestUpgradeDowngrade/after-cluster-creation (2.07s)
--- PASS: TestUpgradeDowngrade/after-cluster-creation/core_DRA (2.05s)
--- PASS: TestUpgradeDowngrade/after-cluster-creation/ResourceClaim_device_status (0.02s)
--- PASS: TestUpgradeDowngrade/after-cluster-upgrade (4.10s)
--- PASS: TestUpgradeDowngrade/after-cluster-upgrade/core_DRA (4.09s)
--- PASS: TestUpgradeDowngrade/after-cluster-upgrade/ResourceClaim_device_status (0.01s)
--- PASS: TestUpgradeDowngrade/after-cluster-downgrade (1.24s)
--- PASS: TestUpgradeDowngrade/after-cluster-downgrade/core_DRA (1.21s)
--- PASS: TestUpgradeDowngrade/after-cluster-downgrade/ResourceClaim_device_status (0.02s)
PASS
It's even possible to use `-failfast` and
e.g. `-run=TestUpgradeDowngrade/after-cluster-creation/core_DRA`: `go test` then
runs everything up to that sub-test or any failing sub-test, then stops and
cleans up.
This leverages ktesting as wrapper around Ginkgo and testing.T to make all
helper code that is needed to deploy a DRA driver available to Go unit
tests and thus integration tests.
How to proceed with unifying helper code for integration and E2E testing is
open. This is just a minimal first step in that direction. Ideally, such
code should be in separate packages where usage of Ginkgo, e2e/framework
and gomega.Expect/Eventually/Consistently are forbidden.
While at it, the builder gets extended to make cleanup optional.
This will be needed for upgrade/downgrade testing with sub-tests.
This approach with collecting results from callbacks in a main ginkgo.It and
using them as failures in separate ginkgo.It callbacks might be the best that
can be done with Ginkgo.
A better solution is probably Go unit tests with sub-tests.
This makes it possible to call helper packages which expect a TContext from E2E
tests.
The implementation uses GinkgoT as TB and supports registering cleanup
callbacks which expect a context. These callbacks then run with a context that
comes from ginkgo.DeferCleanup, just as if they had called that directly.
Many helper packages need to know the test namespace in addition to the client.
Supporting passing of that information through the TContext avoids adding
another parameter to such helper packages.
This mirrors similar functionality in framework.Framework which also provides
a namespace to the test and packages taking such a parameter.
Instead of granting callers access to the instance stored in the context,
let's return a copy. Otherwise a caller might accidentally modify what is
stored in the context when they forget to make a copy themselves before
modifying fields.
The original implementation was inspired by how context.Context is handled via
wrapping a parent context. That approach had several issues:
- It is useful to let users call methods (e.g. tCtx.ExpectNoError)
instead of ktesting functions with a tCtx parameters, but that only
worked if all implementations of the interface implemented that
set of methods. This made extending those methods cumbersome (see
the commit which added Require+Assert) and could potentially break
implementations of the interface elsewhere, defeating part of the
motivation for having the interface in the first place.
- It was hard to see how the different TContext wrappers cooperated
with each other.
- Layering injection of "ERROR" and "FATAL ERROR" on top of prefixing
with the klog header caused post-processing of a failed unit test to
remove that line because it looked like log output. Other log output
lines where kept because they were not indented.
- In Go <=1.25, the `go vet sprintf` check only works for functions and
methods if they get called directly and themselves directly pass their
parameters on to fmt.Sprint. The check does not work when calling
methods through an interface. Support for that is coming in Go 1.26,
but will depend on bumping the Go version also in go.mod and thus
may not be immediately possible in Kubernetes.
- Interface documentation in
https://pkg.go.dev/k8s.io/kubernetes@v1.34.2/test/utils/ktesting#TContext
is a monolithic text block. Documentation for methods is more readable and allows
referencing those methods with [] (e.g. [TC.Errorf] works, [TContext.Errorf]
didn't).
The revised implementation is a single struct with (almost) no exported
fields. The two exceptions (embedded context.Context and TB) are useful because
it avoids having to write wrappers for several functions resp. necessary
because Helper cannot be wrapped. Like a logr.LogSink, With* methods can make a
shallow copy and then change some fields in the cloned instance.
The former `ktesting.TContext` interface is now a type alias for
`*ktesting.TC`. This ensures that existing code using ktesting doesn't need to
be updated and because that code is a bit more compact (`tCtx
ktesting.TContext` instead of `tCtx *ktesting.TContext` when not using such an
alias). Hiding that it is a pointer might discourage accessing the exported
fields because it looks like an interface.
Output gets fixed and improved such that:
- "FATAL ERROR" and "ERROR" are at the start of the line, followed by the klog header.
- The failure message follows in the next line.
- Continuation lines are always indented.
The set of methods exposed via TB is now a bit more complete (Attr, Chdir).
All former stand-alone With* functions are now also available as methods and
should be used instead of the functions. Those will be removed.
Linting of log calls now works and found some issues.
Assert is useful because sometimes one wants to check several different things
in the same test, without stopping after the first failed assertion.
Require gets added for symmetry and to mirror testify's require and
assert. Require is identical to Expect (gomega naming).
We need to see the actual effect that ktesting will have when used as wrapper
around testing.T. Producing an error hid that adding the klog header makes some
output sub-optimal:
<klog header>: FATAL ERROR: ...
The problem with having the klog header at the beginning of the line is that
the Kubernetes `make test` post-processing treats this as log output instead
of the failure message of the test. Will be fixed separately.
Example:
I1208 16:01:05.852628 243 upgradedowngrade_test.go:239] get source code version: bring up v1.34: cluster is running, use KUBECONFIG=/var/run/kubernetes/admin.kubeconfig to access it
I1208 16:01:05.869679 243 reflector.go:446] "Caches populated" type="*v1.ServiceAccount" reflector="k8s.io/client-go/tools/watch/informerwatcher.go:162"
The first line is printed via framework.Logf, which is meant to emulate the
format used by the klog text logger in the second line. The difference is that
klog formats the pid with 7 characters, padding on the left with spaces.
Consistency trumps brevity here, so let's format exactly as in klog.
Test_isSchedulableAfterClaimChange was sensitive to system load because of the
arbitrary delay when waiting for the assume cache to catch up. Running inside
a synctest bubble avoids this. While at it, the unit tests get converted
to ktesting (nicer failure output, no extra indention needed for
tCtx.SyncTest).
TestPlugin/prebind-fail-with-binding-timeout relied on setting up a claim with
certain time stamps and then getting that test case tested within a certain
real-world time window. It's surprising that this didn't flake more often
because test execution order is random. Now the time stamp gets set right
before the test case is about to be tested. Conversion to a synctest would
be nicer, but synctests cannot have sub-tests, which are used here to track
where log output and failures come from within the larger test case.
Inside the plugin itself some log output gets added to explain why a claim is
unavailable on a node in case of a binding timeout or error during Filter.
The script is broken because it relies on grepping the source code.
This has always been fragile (currently it finds the search term
in comments) and stopped working years ago when changing how tests
are labeled.
Instead of fixing the script let's remove it because it's clearly unused.
The tests assumed that instantiating a DRAManager followed by
informerFactory.WaitForCacheSync would be enough to have the manager
up-to-date, but that's not correct: the test only waits for informer *caches*
to be synced, but syncing *event handlers* like the one in the manager may
still be going on. The flake rate is low, though:
$ GOPATH/bin/stress -p 256 ./noderesources.test
5s: 0 runs so far, 0 failures, 256 active
10s: 256 runs so far, 0 failures, 256 active
15s: 256 runs so far, 0 failures, 256 active
20s: 512 runs so far, 0 failures, 256 active
25s: 567 runs so far, 0 failures, 256 active
30s: 771 runs so far, 0 failures, 256 active
/tmp/go-stress-20251226T181044-974980161
--- FAIL: TestCalculateResourceAllocatableRequest (0.81s)
--- FAIL: TestCalculateResourceAllocatableRequest/DRA-backed-resource-with-shared-device-allocation (0.00s)
extendedresourcecache.go:197: I1226 18:11:14.431337] Updated extended resource cache for explicit mapping extendedResource="extended.resource.dra.io/something" deviceClass="device-class-name"
extendedresourcecache.go:204: I1226 18:11:14.431380] Updated extended resource cache for default mapping extendedResource="deviceclass.resource.kubernetes.io/device-class-name" deviceClass="device-class-name"
extendedresourcecache.go:220: I1226 18:11:14.431394] Updated device class mapping deviceClass="device-class-name" extendedResource="extended.resource.dra.io/something"
resource_allocation_test.go:595: Expected requested=2, but got requested=1
FAIL
It becomes higher when changing WaitForCacheSync such that it doesn't poll and
therefore returns more promptly, which is where this flake was first observed.
The fix is to run the test in a syntest bubble where Wait can be used to wait
for all background activity, including event handling, to be finished before
proceeding with the test.
synctest is less forgiving about lingering goroutines. A synctest bubble must
wait for gouroutines to stop, which in this case means that there has to be
a way to wait for the metric recorder shutdown. Event handlers have to be
removed.
This could be done with plain Go, but here test/utils/ktesting is used instead
because it offers some advantages:
- less boilerplate code
- automatic cancellation of the context (i.e. less manual context.WithCancel)
- tCtx.SyncTest is a direct substitute for t.Run, which avoids re-indenting
sub-tests. synctest itself needs another anonymous function, which makes
the line too long and forced re-indention:
t.Run(... func(...) {
synctest.Test(... func() {
})
})
For the sake of consistency all tests get updated.
While at it, some code gets improved:
- t.Fatal(err) is not a good way to report an error because
there is no additional markup in the test output that indicates
that there was an unexpected error. It just logs err.Error(),
which might not be very informative and/or obvious.
- newTestDRAManager aborts in case of a failure instead of
returning an error.
Verify scripts are run such that stderr is captured and included in the JUnit
files. Stdout is not. Therefore the instructions in case of a failure where
only visible by searching the entire job log file, but not in the Prow summary.
The unit test flaked at least once so far in the CI. Can be reproduced
locally by running many instances of the test in parallel.
There were two potential root causes:
- The watch must be set up completely before creating objects (a fake
client-go limitation).
- The one second timeout might be too small on a loaded system.
By running the tests in a synctest bubble with synctest.Wait calls at
the right places both problems are avoided. As a welcome side effect
the test also completes faster.
Before:
$ go test k8s.io/dynamic-resource-allocation/deviceclass/extendedresourcecache
ok k8s.io/dynamic-resource-allocation/deviceclass/extendedresourcecache 9.300s
$ stress -p 512 ./extendedresourcecache.test
5s: 0 runs so far, 0 failures, 512 active
10s: 8 runs so far, 0 failures, 512 active
/tmp/go-stress-20251225T195231-2875181701
--- FAIL: TestExtendedResourceCache (9.14s)
extendedresourcecache_test.go:234: Expected to find device class 'gpu-class' for 'example.com/gpu', got nil
extendedresourcecache_test.go:241: Expected to find device class 'fpga-class' for 'deviceclass.resource.kubernetes.io/fpga-class', got nil
extendedresourcecache_test.go:247: Expected default mapping for gpu-class
extendedresourcecache.go:197: I1225 19:52:36.332170] Updated extended resource cache for explicit mapping extendedResource="example.com/gpu" deviceClass="gpu-class-3"
extendedresourcecache.go:204: I1225 19:52:36.332216] Updated extended resource cache for default mapping extendedResource="deviceclass.resource.kubernetes.io/gpu-class-3" deviceClass="gpu-class-3"
extendedresourcecache.go:220: I1225 19:52:36.332245] Updated device class mapping deviceClass="gpu-class-3" extendedResource="example.com/gpu"
extendedresourcecache_test.go:260: Expected to find device class 'gpu-class' for 'example.com/gpu', got &DeviceClass{ObjectMeta:{gpu-class-3 0 2025-12-24 19:52:35.32560833 +0100 CET m=-86396.691266715 <nil> <nil> map[] map[] [] [] [{unknown Update resource.k8s.io/v1 2025-12-25 18:52:36.332067439 +0000 UTC FieldsV1 {"f:spec":{"f:extendedResourceName":{}}} }]},Spec:DeviceClassSpec{Selectors:[]DeviceSelector{},Config:[]DeviceClassConfiguration{},ExtendedResourceName:*example.com/gpu,},}
extendedresourcecache.go:197: I1225 19:52:37.336135] Updated extended resource cache for explicit mapping extendedResource="example.com/gpu" deviceClass="gpu-class-4"
extendedresourcecache.go:204: I1225 19:52:37.336169] Updated extended resource cache for default mapping extendedResource="deviceclass.resource.kubernetes.io/gpu-class-4" deviceClass="gpu-class-4"
extendedresourcecache.go:220: I1225 19:52:37.336192] Updated device class mapping deviceClass="gpu-class-4" extendedResource="example.com/gpu"
extendedresourcecache.go:197: I1225 19:52:38.340121] Updated extended resource cache for explicit mapping extendedResource="example
After:
ok k8s.io/dynamic-resource-allocation/deviceclass/extendedresourcecache 0.064s
...
2m0s: 7063 runs so far, 0 failures, 512 active
Reading numPreFilterCalled races with writing it in the scheduler, at least as
far as the data race detector is concerned. That the test waits for pod
scheduling is too indirect. enqueuePlugin.called has the same problem,
but hasn't triggered the race detector (yet).
We need to protect against concurrent access. The easiest way to enforce that
is via atomic.Int64. In contrast to a mutex it is impossible to use it wrong.
Shutting down the scheduler first was also tried, but didn't work out because
"teardown" does more than just stopping the scheduler, it also cancels a
context that is needed during test shutdown.
