data race in TestAidAttestationFailiures/AidAttestation_fails_if_server_does_not_sends_a_challenge

[zmt]

• Version: 2067119
• Platform: Linux [redacted] 5.4.129+ #1 SMP Wed Aug 18 19:58:18 PDT 2021 x86_64 GNU/Linux
• Subsystem: tpm nodeattestor plugin

The TestAidAttestationFailiures/AidAttestation_fails_if_server_does_not_sends_a_challenge exhibits a data race between the code under test and the t.Cleanup call to sim.Close(). That is the only subtest which uses streambuilder.FailAndBuild from the nodeattestortest package.

See example failure.

Discovered while addressing #2379.

[zmt]

Also note typo in test name: "Failiures".

[zmt]

I may have a simple patch for this.

[zmt]

Nope. If I remove the t.Cleanup(...sim.Close()...) in favor of a defer sim.Close() after each call to setupSimulator, it avoids the data race, but makes a different subtest flaky with or without the race detector:

% go test -race -count 10 -failfast ./pkg/agent/plugin/nodeattestor/tpmdevid
--- FAIL: TestAidAttestationFailures (0.48s)
    --- FAIL: TestAidAttestationFailures/AidAttestation_fails_if_a_new_session_cannot_be_started (0.48s)
        devid_test.go:467:
            	Error Trace:	devid_test.go:467
            	Error:      	"rpc error: code = Internal desc = nodeattestor(tpm_devid): unable to get endorsement certificate: failed to read NV index 01c00002: GetCapability for TPM_PT_NV_BUFFER_MAX failed: attempting to use a closed simulator" does not contain "rpc error: code = Internal desc = nodeattestor(tpm_devid): unable to start a new TPM session: cannot load DevID key on TPM"
            	Test:       	TestAidAttestationFailures/AidAttestation_fails_if_a_new_session_cannot_be_started
FAIL
FAIL	github.com/spiffe/spire/pkg/agent/plugin/nodeattestor/tpmdevid	9.383s
% go test -count 10 -failfast ./pkg/agent/plugin/nodeattestor/tpmdevid
--- FAIL: TestAidAttestationFailures (0.35s)
    --- FAIL: TestAidAttestationFailures/AidAttestation_fails_if_a_new_session_cannot_be_started (0.35s)
        devid_test.go:467:
            	Error Trace:	devid_test.go:467
            	Error:      	"rpc error: code = Internal desc = nodeattestor(tpm_devid): unable to get endorsement certificate: failed to read NV index 01c00002: GetCapability for TPM_PT_NV_BUFFER_MAX failed: attempting to use a closed simulator" does not contain "rpc error: code = Internal desc = nodeattestor(tpm_devid): unable to start a new TPM session: cannot load DevID key on TPM"
            	Test:       	TestAidAttestationFailures/AidAttestation_fails_if_a_new_session_cannot_be_started
FAIL
FAIL	github.com/spiffe/spire/pkg/agent/plugin/nodeattestor/tpmdevid	7.081s

[zmt]

Also see #2379 & #2705.

[azdagron]

Thanks for opening this @zmt !

This race is ultimately a deficiency in the way the TPMSimulator wrapper has been designed. When the test executes, the expected error condition is met, and the test closes the TPMSimulator. Unfortunately, the AidAttestation handler is still being executed concurrently and closes its session, causing the data race. The TPM simulator is not designed to be accessed from more than one goroutine. The plugin is "unloaded" before the TPM simulator is torn down, however, the AidAttestation handler is still running is because the catalog only calls Stop() on the plugin gRPC server, which does not wait for pending RPCs to complete before returning.

We can and should restructure the tpm simulator wrapper and the way it is used that it is only handled by a single goroutine, but either way, this race can be solved by changing the catalog to perform a GracefulStop(), which I think is probably the right thing to do anyway.

I'll put up a PR.

[zmt]

The TPM simulator is not designed to be accessed from more than one goroutine.

I noticed it wasn't safe for concurrency and that the wrapper followed suit. My instinct was to add a mutex to the wrapper, but wasn't sure that was the right direction. I was also looking at a hack to skip the t.Cleanup() for the racy subtest in favor of a defer sim.Close(). When I changed everything to a defer sim.Close() other tests broke so was going to try a janky conditional thing. Your PR is def. a big step up from the hack I was considering to avoid the race.

[zmt]

I can no longer reproduce this. I guess #2722 fixed it.