Repository: moby/moby (language: go)

Issue:
[go client] negotiateAPIVersionPing triggers Go race detector
**Description**

Creating a Moby/Docker client using `client.NewClientWithOpts(client.WithAPIVersionNegotiation())` and then using this client from multiple goroutines (such as indirectly by requesting an event stream) reproducibly triggers go's race detector in https://github.com/moby/moby/blob/74286cba8c2c14d5360caec44d2da74858e9c707/client/client.go#L251

The go Docker client dependency is:

```
github.com/docker/docker v20.10.17+incompatible
```

**Steps to reproduce the issue:**
1. check out the repository https://github.com/thediveo/whalewatcher
2. in the root of the repository run `go test -v -race ./watcher/moby`

**Describe the results you received:**

```
WARNING: DATA RACE
Write at 0x00c0000a0372 by goroutine 24:
  github.com/docker/docker/client.(*Client).negotiateAPIVersionPing()
      /home/.../go/pkg/mod/github.com/docker/docker@v20.10.17+incompatible/client/client.go:244 +0x184
  github.com/docker/docker/client.(*Client).NegotiateAPIVersion()
      /home/.../go/pkg/mod/github.com/docker/docker@v20.10.17+incompatible/client/client.go:208 +0xe4
  github.com/docker/docker/client.(*Client).getAPIPath()
      /home/.../go/pkg/mod/github.com/docker/docker@v20.10.17+incompatible/client/client.go:184 +0x84
  github.com/docker/docker/client.(*Client).sendRequest()
      /home/.../go/pkg/mod/github.com/docker/docker@v20.10.17+incompatible/client/request.go:109 +0x7c
  github.com/docker/docker/client.(*Client).get()
      /home/.../go/pkg/mod/github.com/docker/docker@v20.10.17+incompatible/client/request.go:37 +0x16c
  github.com/docker/docker/client.(*Client).Events.func1()
      /home/.../go/pkg/mod/github.com/docker/docker@v20.10.17+incompatible/client/events.go:35 +0x1dc
Previous write at 0x00c0000a0372 by goroutine 23:
  github.com/docker/docker/client.(*Client).negotiateAPIVersionPing()
      /home/.../go/pkg/mod/github.com/docker/docker@v20.10.17+incompatible/client/client.go:244 +0x184
  github.com/docker/docker/client.(*Client).NegotiateAPIVersion()
      /home/.../go/pkg/mod/github.com/docker/docker@v20.10.17+incompatible/client/client.go:208 +0xe4
  github.com/docker/docker/client.(*Client).getAPIPath()
      /home/.../go/pkg/mod/github.com/docker/docker@v20.10.17+incompatible/client/client.go:184 +0x84
  github.com/docker/docker/client.(*Client).sendRequest()
      /home/.../go/pkg/mod/github.com/docker/docker@v20.10.17+incompatible/client/request.go:109 +0x7c
  github.com/docker/docker/client.(*Client).get()
      /home/.../go/pkg/mod/github.com/docker/docker@v20.10.17+incompatible/client/request.go:37 +0x584
  github.com/docker/docker/client.(*Client).ContainerList()
      /home/.../go/pkg/mod/github.com/docker/docker@v20.10.17+incompatible/client/container_list.go:48 +0x5c8
  github.com/thediveo/whalewatcher/engineclient/moby.(*MobyWatcher).List()
      /home/.../workspaces/namespaces/whalewatcher/engineclient/moby/moby.go:138 +0x9c
  github.com/thediveo/whalewatcher/watcher.(*watcher).list()
      /home/.../workspaces/namespaces/whalewatcher/watcher/watcher.go:424 +0x94
  github.com/thediveo/whalewatcher/watcher.(*watcher).Watch.func1.1()
      /home/.../workspaces/namespaces/whalewatcher/watcher/watcher.go:232 +0x50
```

**Describe the results you expected:**

Go's race detector doesn't get triggered.

**Additional information you deem important (e.g. issue happens only occasionally):**

- reproducible

**Output of `docker version`:**

```
Client: Docker Engine - Community
 Version:           20.10.17
 API version:       1.41
 Go version:        go1.17.11
 Git commit:        100c701
 Built:             Mon Jun  6 23:02:36 2022
 OS/Arch:           linux/arm64
 Context:           default
 Experimental:      true
Server: Docker Engine - Community
 Engine:
  Version:          20.10.17
  API version:      1.41 (minimum version 1.12)
  Go version:       go1.17.11
  Git commit:       a89b842
  Built:            Mon Jun  6 23:01:00 2022
  OS/Arch:          linux/arm64
  Experimental:     false
 containerd:
  Version:          1.6.6
  GitCommit:        10c12954828e7c7c9b6e0ea9b0c02b01407d3ae1
 runc:
  Version:          1.1.2
  GitCommit:        v1.1.2-0-ga916309
 docker-init:
  Version:          0.19.0
  GitCommit:        de40ad0
```

**Output of `docker info`:**

```
Client:
 Context:    default
 Debug Mode: false
 Plugins:
  app: Docker App (Docker Inc., v0.9.1-beta3)
  buildx: Docker Buildx (Docker Inc., v0.8.2-docker)
  compose: Docker Compose (Docker Inc., v2.6.0)
Server:
 Containers: 6
  Running: 0
  Paused: 0
  Stopped: 6
 Images: 30
 Server Version: 20.10.17
 Storage Driver: overlay2
  Backing Filesystem: extfs
  Supports d_type: true
  Native Overlay Diff: true
  userxattr: false
 Logging Driver: json-file
 Cgroup Driver: systemd
 Cgroup Version: 2
 Plugins:
  Volume: local
  Network: bridge host ipvlan macvlan null overlay
  Log: awslogs fluentd gcplogs gelf journald json-file local logentries splunk syslog
 Swarm: inactive
 Runtimes: io.containerd.runc.v2 io.containerd.runtime.v1.linux runc
 Default Runtime: runc
 Init Binary: docker-init
 containerd version: 10c12954828e7c7c9b6e0ea9b0c02b01407d3ae1
 runc version: v1.1.2-0-ga916309
 init version: de40ad0
 Security Options:
  apparmor
  seccomp
   Profile: default
  cgroupns
 Kernel Version: 5.13.0-1031-raspi
 Operating System: Ubuntu 21.10
 OSType: linux
 Architecture: aarch64
 CPUs: 4
 Total Memory: 7.625GiB
 Name: ****
 ID: ****
 Docker Root Dir: /var/lib/docker
 Debug Mode: false
 Registry: https://index.docker.io/v1/
 Labels:
 Experimental: false
 Insecure Registries:
  127.0.0.0/8
 Live Restore Enabled: false
```

Prevent data race in version negotiation
- fixes https://github.com/moby/moby/issues/43729

Concurrent operations on the same client lead to data race during
version negotiation. This commit adds locks to `version` and
`negotiated` fields, and replaces all usages by methods protected by
locks.

<!--

Please make sure you've read and understood our contributing guidelines;
https://github.com/moby/moby/blob/master/CONTRIBUTING.md

** Make sure all your commits include a signature generated with `git commit -s` **

For additional information on our contributing process, read our contributing
guide https://docs.docker.com/opensource/code/

If this is a bug fix, make sure your description includes "fixes #xxxx", or
"closes #xxxx"

Please provide the following information:
-->

**- What I did**
Fixed a data race that occurs during concurrent version negotiation.
**- How I did it**
I created two locks and made sure all concurrent usages of `version` and `negotiated` fields are protected.
**- How to verify it**
Create and use a client concurrently with race detector on.
**- Description for the changelog**
<!--
Write a short (one line) summary that describes the changes in this
pull request for inclusion in the changelog:
-->
Prevent data race in version negotiation.

**- A picture of a cute animal (not mandatory but encouraged)**
😼



Discussion / hints:
Thanks for reporting! I recalled there was a PR that should fix this, which wasn't merged yet; https://github.com/moby/moby/pull/42379 feel free to review that PR as well to confirm that addresses the issue you found 👍 
> [By default, programmers should expect that a type is safe for use only by a single goroutine at a time. If a type provides stronger guarantees, the doc comment should state them.](https://go.dev/doc/comment#:~:text=By%20default%2C%20programmers%20should%20expect%20that%20a%20type%20is%20safe%20for%20use%20only%20by%20a%20single%20goroutine%20at%20a%20time.%20If%20a%20type%20provides%20stronger%20guarantees%2C%20the%20doc%20comment%20should%20state%20them.)

The `*client.Client` type in v20.10.17 is not documented as safe for concurrent use, therefore the Go race detector triggering when concurrently using the client is expected behaviour. It is the consuming code's responsibility to ensure that client instances are used safely. An enhancement to the client to make it safe for concurrent use is in the works.
Hi @thaJeztah, 
Thank you for taking a look at this change.
I addressed your comments and pushed an updated version.
@tianon @corhere @rumpl @ndeloof PTAL
> LGTM but I wonder: why introduce such mutex-based synchronized access to version, and not just run API version negotiation from `NewClientWithOpts` as such an initializer is expected to?

I think we can't do this in the initializer because the `NegotiateAPIVersion`/`NegotiateAPIVersionPing` can be called at any time later.
sur, it _can_ be called at any time later, but what would be the benefit? You can't use the client without this to happen once, so better just return a fully initialized client, vs doing some lazy-init with synchronized code
The idea of doing this at a later stage ("lazily") is to only connect with the daemon if an API call is to be made, which is not always known up-front when the client is created.
@thaJeztah as `client.host` is set in the ~constructor~ initializer, how could you use such a client with a not known daemon?
Sorry for chiming in: in the "worst" case, the daemon might not be online at the time the client gets created and a properly written software (I dunno what this is, haven't reached that stage yet myself) is fine to (re) connect during long-term operation anyway. And in consequence that might even raise the question whether to renegotiate after daemon connection-loss.

Anyway, connection and reconnecting including API version negotiation looks to me like a "late binding" over the long lifetime of services using the Docker API. To me, such use cases match with the current design where establishing a daemon service connection and the API negotiation only takes place later, but not when creating a client.
lazy-init might indeed make sense in some circumstances, and as noted being able to re-negociate connection after failure would be even nicer. Just for the current design doing lazy init sounds to me some additional complexity added for a minimal benefits (most client are just used a few ms after creation, aren't they?). But I'm not against this, already gave my LGTM vote, just wonder why we would want this to be more complicated that it needs to be.
Yes, some things were moved to be connecting only if needed, as (for example, in the `docker` cli), the client may be created during startup of the CLI, but may not need to make an actual connection when invoked (think of `docker --help` or `docker <some command that doesn't make an API call>`).

Also note that the client may be used in different contexts than a "cli" 
I'm perfectly fine with the current fix and wanted to just give a view onto further use cases, but didn't intend to throw in a spanner into the works. I'm actually using Docker clients almost always outside any CLI context but instead in service contexts to diagnose OT container workloads in (in both meanings) production systems.
As I have a large set of unit tests for the diagnosis services that often need to talk to a real Docker daemon under test, the race condition currently blocks me from using `go test -race`: this stll floods my unit tests with positives that are upstream ... and this unfortunately means I cannot run race tests in the pipelines on a regular basis. I would be very thankful if this PR could be merged so it soon trickles down into not only all my tests.
I'm now seeing a different read/write race between `NegotiateAPIVersion` and `getAPIPath` after having successfully stopped the other race. I actually have issued an initial `NegotiateAPIVersion` call on the client before spinning separate goroutines issuing API calls but am now somewhat surprised that `NetworkList`/`getAPIPath` triggers a race.

Should this be handled as part of this PR or shall I file a new, separate issue?

```
WARNING: DATA RACE
Read at 0x00c00040e472 by goroutine 20:
  github.com/docker/docker/client.(*Client).getAPIPath()
      /home/.../go/pkg/mod/github.com/docker/docker@v20.10.17+incompatible/client/client.go:183 +0x8f
  github.com/docker/docker/client.(*Client).sendRequest()
      /home/.../go/pkg/mod/github.com/docker/docker@v20.10.17+incompatible/client/request.go:109 +0xbb
  github.com/docker/docker/client.(*Client).get()
      /home/.../go/pkg/mod/github.com/docker/docker@v20.10.17+incompatible/client/request.go:37 +0x294
  github.com/docker/docker/client.(*Client).NetworkList()
      /home/.../go/pkg/mod/github.com/docker/docker@v20.10.17+incompatible/client/network_list.go:25 +0x24f
  github.com/thediveo/whalewatcher/watcher/moby.glob..func1.3()
      /home/.../cscom/ghostwire-ws/whalewatcher/watcher/moby/moby_test.go:68 +0x593
  github.com/onsi/ginkgo/v2/internal.(*Suite).runNode.func2()
      /home/.../go/pkg/mod/github.com/onsi/ginkgo/v2@v2.1.4/internal/suite.go:596 +0xe7

Previous write at 0x00c00040e472 by goroutine 26:
  github.com/docker/docker/client.(*Client).negotiateAPIVersionPing()
      /home/.../go/pkg/mod/github.com/docker/docker@v20.10.17+incompatible/client/client.go:244 +0x192
  github.com/docker/docker/client.(*Client).NegotiateAPIVersion()
      /home/.../go/pkg/mod/github.com/docker/docker@v20.10.17+incompatible/client/client.go:208 +0x164
  github.com/thediveo/whalewatcher/engineclient/moby.(*MobyWatcher).List()
      /home/.../cscom/ghostwire-ws/whalewatcher/engineclient/moby/moby.go:136 +0x91
  github.com/thediveo/whalewatcher/watcher.(*watcher).list()
      /home/.../cscom/ghostwire-ws/whalewatcher/watcher/watcher.go:424 +0xcf
  github.com/thediveo/whalewatcher/watcher.(*watcher).Watch.func1.1()
      /home/.../cscom/ghostwire-ws/whalewatcher/watcher/watcher.go:232 +0x59
```
> I'm now seeing a different read/write race between `NegotiateAPIVersion` and `getAPIPath` after having successfully stopped the other race. I actually have issued an initial `NegotiateAPIVersion` call on the client before spinning separate goroutines issuing API calls but am now somewhat surprised that `NetworkList`/`getAPIPath` triggers a race.

@thediveo looking at your whalewatcher `develop` branch, it appears to be a bug in your code. Your end-to-end test concurrently calls `func (*Client) NegotiateAPIVersion` and `func (*Client) NetworkList` from separate goroutines. You aren't waiting for `NegotiateAPIVersion` to return before using the client concurrently. Try reverting https://github.com/thediveo/whalewatcher/commit/8ff72e97ae50f93b5b2a9593ae2df9930e3ae8d2 and inserting the line `moby.NegotiateAPIVersion(context.Background())` [here](https://github.com/thediveo/whalewatcher/blob/82cf83f563afeaa373866e04e7d51e0ce9f341fd/watcher/moby/moby.go#L50) instead.
@corhere ah! thank you very much for pointing out my botched fix attempt, as I obviously got the gist wrong the first time. As I don't want to run the NegotiateAPIVersion on the background context I had to implement it slightly differently, but my tests now all pass. However, this also means that there might be downstream false positives so to enable -race in downstream tests I will need for this PR to finally become merged and part of a new version tag. If I'm getting this correct now, then the reason is that I will always end up in cases where the currently race-triggering API calls will be on different goroutines/threads.

Thank you very much again for your help!
> However, this also means that there might be downstream false positives so to enable -race in downstream tests I will need for this PR to finally become merged and part of a new version tag.

The race detector generally does not have false positives; if it reports that a race has been detected, the program violates the Go memory model in some way.

>  If I'm getting this correct now, then the reason is that I will always end up in cases where the currently race-triggering API calls will be on different goroutines/threads.

I still don't think you're getting it, as [you're still calling `NegotiateAPIVersion` more than once on a client.](https://github.com/thediveo/whalewatcher/commit/1af1ff7eb2878e3be44b46cd2a36fc1a4a50d781#diff-2e8d4a97765f04988901d37fb9e403de8c97ae53cfd60fbf72665ceb7d008909R70) The client has an internal flag, `negotiated`, which is set to true by the `NegotiateAPIVersion` method. Every API method on the client checks this flag and calls `NegotiateAPIVersion` itself if the flag is false. So while the flag is false, concurrent calls to any API methods on a client will cause data races: unsynchronized read and write of the `negotiated` flag. But once the flag is true, concurrent API method calls will **not** race with each other as they won't call `NegotiateAPIVersion` themselves, but they **will** race with any explicit calls to `NegotiateAPIVersion`. So to work around the race on the v20.10 client, you need to get that flag set to true without triggering a race, __and never call `NegotiateAPIVersion` again on that client.__ I hope this helps @thediveo.
my false positive was misleading, sorry. I forgot to put it into context of a correct positive but in an upstream module, so to a downstream unit test it's a false positive from the module unit test perspective, but not a Go race detector false positive. Sorry for confusing you.

I think I understood this reasoning correctly, but it is good that you reinforce the point again. And this is what I'm referring to in the bottom part of my comment: I ensured your point (if I'm not mistaken) now both in the whalewatcher code under test as well in a particular test case by ensuring that the "synchronous" API version negation safely takes place in a single place and completes, before issuing further API calls from multiple goroutines.

What I wanted to hint at while this fix on my side should be as you suggested, except put into a later place because of the required context, other (private) modules downstream to whalewatcher might not be refactor-able to also implement this fix. Instead these private modules need to wait for the PR fix in order to enable test -race in the future on them.

Fix patch:
diff --git a/client/client.go b/client/client.go
index f2eeb6c5702ed..60d91bc65b5a4 100644
--- a/client/client.go
+++ b/client/client.go
@@ -49,6 +49,8 @@ import (
 	"net/url"
 	"path"
 	"strings"
+	"sync"
+	"sync/atomic"
 	"time"
 
 	"github.com/docker/docker/api"
@@ -131,7 +133,10 @@ type Client struct {
 	negotiateVersion bool
 
 	// negotiated indicates that API version negotiation took place
-	negotiated bool
+	negotiated atomic.Bool
+
+	// negotiateLock is used to single-flight the version negotiation process
+	negotiateLock sync.Mutex
 
 	tp trace.TracerProvider
 
@@ -266,7 +271,16 @@ func (cli *Client) Close() error {
 // be negotiated when making the actual requests, and for which cases
 // we cannot do the negotiation lazily.
 func (cli *Client) checkVersion(ctx context.Context) error {
-	if !cli.manualOverride && cli.negotiateVersion && !cli.negotiated {
+	if !cli.manualOverride && cli.negotiateVersion && !cli.negotiated.Load() {
+		// Ensure exclusive write access to version and negotiated fields
+		cli.negotiateLock.Lock()
+		defer cli.negotiateLock.Unlock()
+
+		// May have been set during last execution of critical zone
+		if cli.negotiated.Load() {
+			return nil
+		}
+
 		ping, err := cli.Ping(ctx)
 		if err != nil {
 			return err
@@ -312,6 +326,10 @@ func (cli *Client) ClientVersion() string {
 // added (1.24).
 func (cli *Client) NegotiateAPIVersion(ctx context.Context) {
 	if !cli.manualOverride {
+		// Avoid concurrent modification of version-related fields
+		cli.negotiateLock.Lock()
+		defer cli.negotiateLock.Unlock()
+
 		ping, err := cli.Ping(ctx)
 		if err != nil {
 			// FIXME(thaJeztah): Ping returns an error when failing to connect to the API; we should not swallow the error here, and instead returning it.
@@ -336,6 +354,10 @@ func (cli *Client) NegotiateAPIVersion(ctx context.Context) {
 // added (1.24).
 func (cli *Client) NegotiateAPIVersionPing(pingResponse types.Ping) {
 	if !cli.manualOverride {
+		// Avoid concurrent modification of version-related fields
+		cli.negotiateLock.Lock()
+		defer cli.negotiateLock.Unlock()
+
 		cli.negotiateAPIVersionPing(pingResponse)
 	}
 }
@@ -361,7 +383,7 @@ func (cli *Client) negotiateAPIVersionPing(pingResponse types.Ping) {
 	// Store the results, so that automatic API version negotiation (if enabled)
 	// won't be performed on the next request.
 	if cli.negotiateVersion {
-		cli.negotiated = true
+		cli.negotiated.Store(true)
 	}
 }
 


Test patch: