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

Data race due to outgoing buffer reuse (roll forward the reverted PR) #3307

Closed
menghanl opened this issue Jan 10, 2020 · 2 comments
Closed
Assignees
Labels
P2 Type: Feature New features or improvements in behavior

Comments

@menghanl
Copy link
Contributor

A data race during proto marshal. Could be related to the buffer reuse.

Full log
==================
WARNING: DATA RACE
Write at 0x00c001ee6ff8 by goroutine 218:
  runtime.slicecopy()
      /home/travis/.gimme/versions/go1.13.6.linux.amd64/src/runtime/slice.go:197 +0x0
  github.com/golang/protobuf/proto.appendBytes3()
      /home/travis/go/pkg/mod/github.com/golang/[email protected]/proto/table_marshal.go:2136 +0x14f
  github.com/golang/protobuf/proto.(*marshalInfo).marshal()
      /home/travis/go/pkg/mod/github.com/golang/[email protected]/proto/table_marshal.go:270 +0x575
  github.com/golang/protobuf/proto.makeMessageMarshaler.func2()
      /home/travis/go/pkg/mod/github.com/golang/[email protected]/proto/table_marshal.go:2234 +0x173
  github.com/golang/protobuf/proto.(*marshalInfo).marshal()
      /home/travis/go/pkg/mod/github.com/golang/[email protected]/proto/table_marshal.go:270 +0x575
  github.com/golang/protobuf/proto.(*InternalMessageInfo).Marshal()
      /home/travis/go/pkg/mod/github.com/golang/[email protected]/proto/table_marshal.go:141 +0xcb
  google.golang.org/grpc/test/grpc_testing.(*SimpleResponse).XXX_Marshal()
      /home/travis/gopath/src/google.golang.org/grpc/test/grpc_testing/test.pb.go:244 +0x9b
  github.com/golang/protobuf/proto.(*Buffer).Marshal()
      /home/travis/go/pkg/mod/github.com/golang/[email protected]/proto/table_marshal.go:2742 +0x190
  google.golang.org/grpc/encoding/proto.marshal()
      /home/travis/gopath/src/google.golang.org/grpc/encoding/proto/proto.go:46 +0x1b5
  google.golang.org/grpc/encoding/proto.codec.Marshal()
      /home/travis/gopath/src/google.golang.org/grpc/encoding/proto/proto.go:60 +0xde
  google.golang.org/grpc/encoding/proto.(*codec).Marshal()
      <autogenerated>:1 +0x62
  google.golang.org/grpc.encode()
      /home/travis/gopath/src/google.golang.org/grpc/rpc_util.go:543 +0x6e
  google.golang.org/grpc.(*Server).sendResponse()
      /home/travis/gopath/src/google.golang.org/grpc/server.go:846 +0x192
  google.golang.org/grpc.(*Server).processUnaryRPC()
      /home/travis/gopath/src/google.golang.org/grpc/server.go:1070 +0xad6
  google.golang.org/grpc.(*Server).handleStream()
      /home/travis/gopath/src/google.golang.org/grpc/server.go:1331 +0x1343
  google.golang.org/grpc.(*Server).serveStreams.func1.1()
      /home/travis/gopath/src/google.golang.org/grpc/server.go:722 +0xc8
Previous read at 0x00c001ee6fff by goroutine 437:
  runtime.slicecopy()
      /home/travis/.gimme/versions/go1.13.6.linux.amd64/src/runtime/slice.go:197 +0x0
  golang.org/x/net/http2.(*Framer).WriteDataPadded()
      /home/travis/go/pkg/mod/golang.org/x/[email protected]/http2/frame.go:683 +0x34d
  golang.org/x/net/http2.(*writeData).writeFrame()
      /home/travis/go/pkg/mod/golang.org/x/[email protected]/http2/frame.go:643 +0x11d
  golang.org/x/net/http2.(*serverConn).writeFrameAsync()
      /home/travis/go/pkg/mod/golang.org/x/[email protected]/http2/server.go:741 +0x58
Goroutine 218 (running) created at:
  google.golang.org/grpc.(*Server).serveStreams.func1()
      /home/travis/gopath/src/google.golang.org/grpc/server.go:720 +0xb8
  google.golang.org/grpc/internal/transport.(*http2Server).operateHeaders()
      /home/travis/gopath/src/google.golang.org/grpc/internal/transport/http2_server.go:447 +0x16a6
  google.golang.org/grpc/internal/transport.(*http2Server).HandleStreams()
      /home/travis/gopath/src/google.golang.org/grpc/internal/transport/http2_server.go:488 +0x459
  google.golang.org/grpc.(*Server).serveStreams()
      /home/travis/gopath/src/google.golang.org/grpc/server.go:718 +0x19a
  google.golang.org/grpc.(*Server).handleRawConn.func1()
      /home/travis/gopath/src/google.golang.org/grpc/server.go:679 +0x4c
Goroutine 437 (finished) created at:
  golang.org/x/net/http2.(*serverConn).startFrameWrite()
      /home/travis/go/pkg/mod/golang.org/x/[email protected]/http2/server.go:1119 +0x365
  golang.org/x/net/http2.(*serverConn).scheduleFrameWrite()
      /home/travis/go/pkg/mod/golang.org/x/[email protected]/http2/server.go:1220 +0x371
  golang.org/x/net/http2.(*serverConn).wroteFrame()
      /home/travis/go/pkg/mod/golang.org/x/[email protected]/http2/server.go:1181 +0x1dd
  golang.org/x/net/http2.(*serverConn).serve()
      /home/travis/go/pkg/mod/golang.org/x/[email protected]/http2/server.go:834 +0x13ce
  golang.org/x/net/http2.(*Server).ServeConn()
      /home/travis/go/pkg/mod/golang.org/x/[email protected]/http2/server.go:438 +0xd9d
  golang.org/x/net/http2.ConfigureServer.func1()
      /home/travis/go/pkg/mod/golang.org/x/[email protected]/http2/server.go:276 +0xb8
  net/http.(*conn).serve()
      /home/travis/.gimme/versions/go1.13.6.linux.amd64/src/net/http/server.go:1800 +0x1d35
==================
E0109 23:39:41.561162    7528 http2_server.go:856] transport: failed to marshal rpc status: code:13 message:"\377\376\375" details:<type_url:"type.googleapis.com/grpc.testing.Empty" > , error: proto: field "google.rpc.Status.Message" contains invalid UTF-8
--- FAIL: Test (99.99s)
    --- FAIL: Test/MaxMsgSizeClientDefault (0.67s)
        end2end_test.go:595: Running test in tcp-clear-v1-balancer environment...
        end2end_test.go:595: Running test in tcp-tls-v1-balancer environment...
        end2end_test.go:595: Running test in tcp-clear environment...
        end2end_test.go:595: Running test in tcp-tls environment...
        end2end_test.go:595: Running test in handler-tls environment...
        end2end_test.go:595: Running test in no-balancer environment...
        testing.go:853: race detected during execution of test
    testing.go:853: race detected during execution of test
@dfawley
Copy link
Member

dfawley commented Jan 24, 2020

The problem appears to be that we call Done on the data buffer when we dequeue it in loopy writer, when we should only call Done after it is fully written to the framer.

@dfawley dfawley added the P1 label Jan 24, 2020
@menghanl menghanl removed the P1 label Jan 30, 2020
@dfawley dfawley changed the title flaky test: Test/MaxMsgSizeClientDefault Data race due to outgoing buffer reuse Feb 6, 2020
@menghanl
Copy link
Contributor Author

menghanl commented Feb 6, 2020

The buffer reuse change causing this issue was reverted, so this flake is fixed. We are keeping this issue as a reminder to roll-forward the change, with the necessary fix.

@menghanl menghanl added the P1 label Feb 20, 2020
@menghanl menghanl changed the title Data race due to outgoing buffer reuse Data race due to outgoing buffer reuse (roll forward the reverted PR) Jul 16, 2020
@menghanl menghanl added fixit P2 Type: Feature New features or improvements in behavior and removed P1 Type: Bug labels Jul 16, 2020
@easwars easwars removed the fixit label May 4, 2021
@easwars easwars closed this as completed May 4, 2021
@github-actions github-actions bot locked as resolved and limited conversation to collaborators Nov 1, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
P2 Type: Feature New features or improvements in behavior
Projects
None yet
Development

No branches or pull requests

3 participants