terraform-plugin-sdk icon indicating copy to clipboard operation
terraform-plugin-sdk copied to clipboard

go data race condition in acceptance tests when `resource.ParallelTest` is used

Open Didainius opened this issue 5 years ago • 2 comments

SDK version

{
  "Path": "github.com/hashicorp/terraform-plugin-sdk",
  "Version": "v1.6.0"
}

Occurs on 1.5.0 as well.

Relevant provider source code

	resource.ParallelTest(t, resource.TestCase{

https://github.com/Didainius/terraform-provider-fake/blob/test-race-condition/fake/resource_fake_one_test.go#L10

Terraform Configuration Files

This is not specific to any configuration. The main point is to use resource.ParallelTest instead of resource.Test

...

Debug Output

# make test
Sometimes it must be run multiple times as it doesn't always hit, but I would say 3 out of 5 runs do
cd fake && TF_ACC=1 go test -race -v .
=== RUN   TestAccFakeOne
=== PAUSE TestAccFakeOne
=== RUN   TestAccFakeOne2
=== PAUSE TestAccFakeOne2
=== RUN   TestAccFakeOne3
=== PAUSE TestAccFakeOne3
=== RUN   TestAccFakeOne4
=== PAUSE TestAccFakeOne4
=== RUN   TestAccFakeOne5
=== PAUSE TestAccFakeOne5
=== CONT  TestAccFakeOne3
=== CONT  TestAccFakeOne4
=== CONT  TestAccFakeOne5
=== CONT  TestAccFakeOne2
=== CONT  TestAccFakeOne
==================
WARNING: DATA RACE
Write at 0x00c0003164e8 by goroutine 125:
  github.com/hashicorp/terraform-plugin-sdk/internal/helper/plugin.(*GRPCProviderServer).Configure()
      /Users/user/go/pkg/mod/github.com/hashicorp/[email protected]/internal/helper/plugin/grpc_provider.go:478 +0x34e
  github.com/hashicorp/terraform-plugin-sdk/internal/tfplugin5._Provider_Configure_Handler()
      /Users/user/go/pkg/mod/github.com/hashicorp/[email protected]/internal/tfplugin5/tfplugin5.pb.go:3135 +0x2fc
  google.golang.org/grpc.(*Server).processUnaryRPC()
      /Users/user/go/pkg/mod/google.golang.org/[email protected]/server.go:995 +0x994
  google.golang.org/grpc.(*Server).handleStream()
      /Users/user/go/pkg/mod/google.golang.org/[email protected]/server.go:1275 +0x1343
  google.golang.org/grpc.(*Server).serveStreams.func1.1()
      /Users/user/go/pkg/mod/google.golang.org/[email protected]/server.go:710 +0xc8

Previous write at 0x00c0003164e8 by goroutine 177:
  github.com/hashicorp/terraform-plugin-sdk/internal/helper/plugin.(*GRPCProviderServer).Configure()
      /Users/user/go/pkg/mod/github.com/hashicorp/[email protected]/internal/helper/plugin/grpc_provider.go:478 +0x34e
  github.com/hashicorp/terraform-plugin-sdk/internal/tfplugin5._Provider_Configure_Handler()
      /Users/user/go/pkg/mod/github.com/hashicorp/[email protected]/internal/tfplugin5/tfplugin5.pb.go:3135 +0x2fc
  google.golang.org/grpc.(*Server).processUnaryRPC()
      /Users/user/go/pkg/mod/google.golang.org/[email protected]/server.go:995 +0x994
  google.golang.org/grpc.(*Server).handleStream()
      /Users/user/go/pkg/mod/google.golang.org/[email protected]/server.go:1275 +0x1343
  google.golang.org/grpc.(*Server).serveStreams.func1.1()
      /Users/user/go/pkg/mod/google.golang.org/[email protected]/server.go:710 +0xc8

Goroutine 125 (running) created at:
  google.golang.org/grpc.(*Server).serveStreams.func1()
      /Users/user/go/pkg/mod/google.golang.org/[email protected]/server.go:708 +0xb8
  google.golang.org/grpc/internal/transport.(*http2Server).operateHeaders()
      /Users/user/go/pkg/mod/google.golang.org/[email protected]/internal/transport/http2_server.go:429 +0x1679
  google.golang.org/grpc/internal/transport.(*http2Server).HandleStreams()
      /Users/user/go/pkg/mod/google.golang.org/[email protected]/internal/transport/http2_server.go:470 +0x3d7
  google.golang.org/grpc.(*Server).serveStreams()
      /Users/user/go/pkg/mod/google.golang.org/[email protected]/server.go:706 +0x19a
  google.golang.org/grpc.(*Server).handleRawConn.func1()
      /Users/user/go/pkg/mod/google.golang.org/[email protected]/server.go:668 +0x4c

Goroutine 177 (running) created at:
  google.golang.org/grpc.(*Server).serveStreams.func1()
      /Users/user/go/pkg/mod/google.golang.org/[email protected]/server.go:708 +0xb8
  google.golang.org/grpc/internal/transport.(*http2Server).operateHeaders()
      /Users/user/go/pkg/mod/google.golang.org/[email protected]/internal/transport/http2_server.go:429 +0x1679
  google.golang.org/grpc/internal/transport.(*http2Server).HandleStreams()
      /Users/user/go/pkg/mod/google.golang.org/[email protected]/internal/transport/http2_server.go:470 +0x3d7
  google.golang.org/grpc.(*Server).serveStreams()
      /Users/user/go/pkg/mod/google.golang.org/[email protected]/server.go:706 +0x19a
  google.golang.org/grpc.(*Server).handleRawConn.func1()
      /Users/user/go/pkg/mod/google.golang.org/[email protected]/server.go:668 +0x4c
==================
--- FAIL: TestAccFakeOne5 (0.36s)
    testing.go:853: race detected during execution of test
--- FAIL: TestAccFakeOne2 (0.36s)
    testing.go:853: race detected during execution of test
--- FAIL: TestAccFakeOne4 (0.36s)
    testing.go:853: race detected during execution of test
--- FAIL: TestAccFakeOne3 (0.37s)
    testing.go:853: race detected during execution of test
--- FAIL: TestAccFakeOne (0.37s)
    testing.go:853: race detected during execution of test
FAIL
FAIL	github.com/Didainius/terraform-provider-fake/fake	0.580s
FAIL
make: *** [test] Error 1

Expected Behavior

I would not expect a data race here

Actual Behavior

Data race occured in go acceptance test

Steps to Reproduce

We have hit this problem in terraform-provider-vcd but as part of debugging I created a repo (https://github.com/Didainius/terraform-provider-fake/tree/test-race-condition) with fake provider to isolate the problem and ensure our codebase does not misbehave

  1. git clone --single-branch --branch test-race-condition https://github.com/Didainius/terraform-provider-fake.git
  2. Run make test which runs cd fake && TF_ACC=1 go test -race -v .

Note Sometimes it doesn't happen on the first run, but it happens at least 3 times out of 5 for me (usually even more).

Note2. Adding --parallel=1 to the test suite cd fake && TF_ACC=1 go test --parallel=1 -race -v . causes no data races to occur (quite obvious, but still noting)

References

I haven't found related issues in this repo so far.

Didainius avatar Feb 11 '20 11:02 Didainius

Calling Configure on the same provider instance multiple times is definitely problematic, not sure why that is occurring. That said, we should probably just revisit runs with -race after we ship #262 .

paultyng avatar Feb 11 '20 16:02 paultyng

https://github.com/hashicorp/terraform-plugin-sdk/pull/636 introduced warning logs to signal to provider developers when a provider Configure function was executed multiple times, which should only ever occur during provider acceptance testing since a single provider instance is used across multiple, potentially concurrent tests. If the provider configurations are similar across all concurrent acceptance tests, it is not a problem as the same provider configuration should remain in place. Production usage of providers should not have an issue here as Terraform CLI only configures the provider once during its operations as a new provider instance is used each operation.

Since this issue was raised though, the code referenced no longer exists, so we'd need to see updated race detector output. I'll leave this open on the off-chance that someone in the community may have some interest in the subject, however the maintainers cannot provide any guarantees around a timely review of a fix. For other maintainer benefit, verifying any fixes should include running acceptance testing against a large provider that widely implements ParallelTest, such as terraform-provider-aws.

bflad avatar Mar 30 '22 13:03 bflad