Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

clientv3: Data Race - Watch used in conjunction with net/http's request context #8275

Closed
joshmue opened this issue Jul 18, 2017 · 2 comments

Comments

2 participants
@joshmue
Copy link

commented Jul 18, 2017

Hi.

I came across a race condition with clientv3's Watch function if used with request contexts from net/http.

The cause of this issue seems to be quite similar to #7811 (Fix #7816): Calling context's String() method (indirectly) when writes may occur at the same time.

Example to reproduce (with running etcd server):

package main

import (
	"github.com/coreos/etcd/clientv3"
	"log"
	"net/http"
)

func main() {
	etcdClient, err := clientv3.New(clientv3.Config{
		Endpoints: []string{"http://127.0.0.1:2379"},
	})
	if err != nil {
		panic(err)
	}
	defer etcdClient.Close()
	http.HandleFunc("/", func(w http.ResponseWriter, r *http.Request) {
		_ = etcdClient.Watch(r.Context(), "/foobar")
	})

	log.Fatal(http.ListenAndServe("127.0.0.1:8081", nil))
}

Run with -race enabled and do multiple times:

curl http://localhost:8081

Leads to output like this (at least on my linux machine with Go 1.8.3):

==================
WARNING: DATA RACE
Write at 0x00c42008db60 by main goroutine:
  sync/atomic.CompareAndSwapInt32()
      /usr/local/go/src/runtime/race_amd64.s:293 +0xb
  sync.(*Mutex).Lock()
      /usr/local/go/src/sync/mutex.go:48 +0x4d
  net/http.(*Server).trackConn()
      /usr/local/go/src/net/http/server.go:2691 +0x4a
  net/http.(*conn).setState()
      /usr/local/go/src/net/http/server.go:1663 +0x156
  net/http.(*Server).Serve()
      /usr/local/go/src/net/http/server.go:2667 +0x329
  net/http.(*Server).ListenAndServe()
      /usr/local/go/src/net/http/server.go:2585 +0xe0
  net/http.ListenAndServe()
      /usr/local/go/src/net/http/server.go:2787 +0xee
  main.main()
      /tmp/reproduce_race.go:21 +0x222

Previous read at 0x00c42008db60 by goroutine 15:
  reflect.typedmemmove()
      /usr/local/go/src/runtime/mbarrier.go:253 +0x0
  reflect.packEface()
      /usr/local/go/src/reflect/value.go:112 +0x11c
  reflect.valueInterface()
      /usr/local/go/src/reflect/value.go:955 +0x18c
  reflect.Value.Interface()
      /usr/local/go/src/reflect/value.go:925 +0x51
  fmt.(*pp).printValue()
      /usr/local/go/src/fmt/print.go:694 +0x3aea
  fmt.(*pp).printValue()
      /usr/local/go/src/fmt/print.go:848 +0x27dc
  fmt.(*pp).printArg()
      /usr/local/go/src/fmt/print.go:682 +0x1b1
  fmt.(*pp).doPrintf()
      /usr/local/go/src/fmt/print.go:998 +0x1cad
  fmt.Sprintf()
      /usr/local/go/src/fmt/print.go:196 +0x77
  context.(*valueCtx).String()
      /usr/local/go/src/context/context.go:471 +0x16a
  fmt.(*pp).handleMethods()
      /usr/local/go/src/fmt/print.go:596 +0x40a
  fmt.(*pp).printArg()
      /usr/local/go/src/fmt/print.go:679 +0x132
  fmt.(*pp).doPrintf()
      /usr/local/go/src/fmt/print.go:998 +0x1cad
  fmt.Sprintf()
      /usr/local/go/src/fmt/print.go:196 +0x77
  context.(*valueCtx).String()
      /usr/local/go/src/context/context.go:471 +0x16a
  fmt.(*pp).handleMethods()
      /usr/local/go/src/fmt/print.go:596 +0x40a
  fmt.(*pp).printArg()
      /usr/local/go/src/fmt/print.go:679 +0x132
  fmt.(*pp).doPrintf()
      /usr/local/go/src/fmt/print.go:998 +0x1cad
  fmt.Sprintf()
      /usr/local/go/src/fmt/print.go:196 +0x77
  context.(*cancelCtx).String()
      /usr/local/go/src/context/context.go:332 +0xcc
  fmt.(*pp).handleMethods()
      /usr/local/go/src/fmt/print.go:596 +0x40a
  fmt.(*pp).printArg()
      /usr/local/go/src/fmt/print.go:679 +0x132
  fmt.(*pp).doPrintf()
      /usr/local/go/src/fmt/print.go:998 +0x1cad
  fmt.Sprintf()
      /usr/local/go/src/fmt/print.go:196 +0x77
  context.(*cancelCtx).String()
      /usr/local/go/src/context/context.go:332 +0xcc
  fmt.(*pp).handleMethods()
      /usr/local/go/src/fmt/print.go:596 +0x40a
  fmt.(*pp).printArg()
      /usr/local/go/src/fmt/print.go:679 +0x132
  fmt.(*pp).doPrintf()
      /usr/local/go/src/fmt/print.go:998 +0x1cad
  fmt.Sprintf()
      /usr/local/go/src/fmt/print.go:196 +0x77
  github.com/coreos/etcd/clientv3.(*watcher).newWatcherGrpcStream()
      /tmp/gopath/src/github.com/coreos/etcd/clientv3/watch.go:216 +0x169
  github.com/coreos/etcd/clientv3.(*watcher).Watch()
      /tmp/gopath/src/github.com/coreos/etcd/clientv3/watch.go:269 +0xc33
  main.main.func1()
      /tmp/reproduce_race.go:18 +0x152
  net/http.HandlerFunc.ServeHTTP()
      /usr/local/go/src/net/http/server.go:1942 +0x51
  net/http.(*ServeMux).ServeHTTP()
      /usr/local/go/src/net/http/server.go:2238 +0xa2
  net/http.serverHandler.ServeHTTP()
      /usr/local/go/src/net/http/server.go:2568 +0xbc
  net/http.(*conn).serve()
      /usr/local/go/src/net/http/server.go:1825 +0x71a

Goroutine 15 (finished) created at:
  net/http.(*Server).Serve()
      /usr/local/go/src/net/http/server.go:2668 +0x35f
  net/http.(*Server).ListenAndServe()
      /usr/local/go/src/net/http/server.go:2585 +0xe0
  net/http.ListenAndServe()
      /usr/local/go/src/net/http/server.go:2787 +0xee
  main.main()
      /tmp/reproduce_race.go:21 +0x222
==================

Thanks

@heyitsanthony heyitsanthony self-assigned this Jul 18, 2017

@heyitsanthony

This comment has been minimized.

Copy link
Contributor

commented Jul 19, 2017

@joshmue the simplest fix is to wrap the context to mask the string output. There's an example in the v3client package: https://github.com/coreos/etcd/blob/3ce31acda410db937408ac1c1011fe7b0babd8a7/etcdserver/api/v3client/v3client.go#L57. The client doesn't do this by default because it uses the context information to decide which grpc stream to use. In this case it probably doesn't matter too much.

@joshmue

This comment has been minimized.

Copy link
Author

commented Jul 21, 2017

@heyitsanthony

Thank you very much for the explanation; I will use the fix and close this issue.

However i'd suggest to document this behaviour more explicitly at some point, as the design of the context package and its use IMHO do not suggest that such problems could occur.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.