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

race condition #2533

Closed
marten-seemann opened this issue May 9, 2020 · 3 comments · Fixed by #2561
Closed

race condition #2533

marten-seemann opened this issue May 9, 2020 · 3 comments · Fixed by #2561
Labels
Milestone

Comments

@marten-seemann
Copy link
Member

non-zero RTT with QUIC version TLS dev version (WIP) 
 
  downloads a message with 10ms RTT
 
  /go/src/github.com/lucas-clemente/quic-go/integrationtests/self/rtt_test.go:66
 
==================
 
WARNING: DATA RACE
 
Write at 0x00c004808940 by goroutine 367:
 
  github.com/lucas-clemente/quic-go/internal/wire.parseStreamFrame()
 
      /go/src/github.com/lucas-clemente/quic-go/internal/wire/stream_frame.go:68 +0x61f
 
  github.com/lucas-clemente/quic-go/internal/wire.(*frameParser).parseFrame()
 
      /go/src/github.com/lucas-clemente/quic-go/internal/wire/frame_parser.go:47 +0xc51
 
  github.com/lucas-clemente/quic-go/internal/wire.(*frameParser).ParseNext()
 
      /go/src/github.com/lucas-clemente/quic-go/internal/wire/frame_parser.go:34 +0x16f
 
  github.com/lucas-clemente/quic-go.(*session).handleUnpackedPacket()
 
      /go/src/github.com/lucas-clemente/quic-go/session.go:937 +0x42f
 
  github.com/lucas-clemente/quic-go.(*session).handleSinglePacket()
 
      /go/src/github.com/lucas-clemente/quic-go/session.go:818 +0x1216
 
  github.com/lucas-clemente/quic-go.(*session).handlePacketImpl()
 
      /go/src/github.com/lucas-clemente/quic-go/session.go:749 +0x9f
 
  github.com/lucas-clemente/quic-go.(*session).run()
 
      /go/src/github.com/lucas-clemente/quic-go/session.go:544 +0x135d
 
  github.com/lucas-clemente/quic-go.(*client).dial.func1()
 
      /go/src/github.com/lucas-clemente/quic-go/client.go:280 +0x65
 

 
Previous read at 0x00c004808940 by goroutine 426:
 
  github.com/lucas-clemente/quic-go/internal/wire.putStreamFrame()
 
      /go/src/github.com/lucas-clemente/quic-go/internal/wire/pool.go:29 +0x69
 
  github.com/lucas-clemente/quic-go/internal/wire.(*StreamFrame).PutBack()
 
      /go/src/github.com/lucas-clemente/quic-go/internal/wire/stream_frame.go:189 +0x9a
 
  github.com/lucas-clemente/quic-go.(*sendStream).frameAcked()
 
      /go/src/github.com/lucas-clemente/quic-go/send_stream.go:331 +0x51
 
  github.com/lucas-clemente/quic-go.(*sendStream).frameAcked-fm()
 
      /go/src/github.com/lucas-clemente/quic-go/send_stream.go:330 +0x55
 
  github.com/lucas-clemente/quic-go/internal/ackhandler.(*sentPacketHandler).detectAndRemoveAckedPackets()
 
      /go/src/github.com/lucas-clemente/quic-go/internal/ackhandler/sent_packet_handler.go:366 +0x635
 
  github.com/lucas-clemente/quic-go/internal/ackhandler.(*sentPacketHandler).ReceivedAck()
 
      /go/src/github.com/lucas-clemente/quic-go/internal/ackhandler/sent_packet_handler.go:279 +0x698
 
  github.com/lucas-clemente/quic-go.(*session).handleAckFrame()
 
      /go/src/github.com/lucas-clemente/quic-go/session.go:1149 +0xdb
 
  github.com/lucas-clemente/quic-go.(*session).handleFrame()
 
      /go/src/github.com/lucas-clemente/quic-go/session.go:992 +0x3f9
 
  github.com/lucas-clemente/quic-go.(*session).handleUnpackedPacket()
 
      /go/src/github.com/lucas-clemente/quic-go/session.go:953 +0x5f6
 
  github.com/lucas-clemente/quic-go.(*session).handleSinglePacket()
 
      /go/src/github.com/lucas-clemente/quic-go/session.go:818 +0x1216
 
  github.com/lucas-clemente/quic-go.(*session).handlePacketImpl()
 
      /go/src/github.com/lucas-clemente/quic-go/session.go:749 +0x9f
 
  github.com/lucas-clemente/quic-go.(*session).run()
 
      /go/src/github.com/lucas-clemente/quic-go/session.go:544 +0x135d
 

 
Goroutine 367 (running) created at:
 
  github.com/lucas-clemente/quic-go.(*client).dial()
 
      /go/src/github.com/lucas-clemente/quic-go/client.go:279 +0x961
 
  github.com/lucas-clemente/quic-go.dialContext()
 
      /go/src/github.com/lucas-clemente/quic-go/client.go:189 +0x2e3
 
  github.com/lucas-clemente/quic-go.dialAddrContext()
 
      /go/src/github.com/lucas-clemente/quic-go/client.go:114 +0x286
 
  github.com/lucas-clemente/quic-go.DialAddrContext()
 
      /go/src/github.com/lucas-clemente/quic-go/client.go:96 +0x96
 
  github.com/lucas-clemente/quic-go.DialAddr()
 
      /go/src/github.com/lucas-clemente/quic-go/client.go:72 +0xe3
 
  github.com/lucas-clemente/quic-go/integrationtests/self_test.glob..func14.3.1()
 
      /go/src/github.com/lucas-clemente/quic-go/integrationtests/self/rtt_test.go:79 +0x641
 
  github.com/onsi/ginkgo/internal/leafnodes.(*runner).runSync()
 
      /go/pkg/mod/github.com/onsi/[email protected]/internal/leafnodes/runner.go:113 +0xf3
 
  github.com/onsi/ginkgo/internal/leafnodes.(*runner).run()
 
      /go/pkg/mod/github.com/onsi/[email protected]/internal/leafnodes/runner.go:64 +0x107
 
  github.com/onsi/ginkgo/internal/leafnodes.(*ItNode).Run()
 
      /go/pkg/mod/github.com/onsi/[email protected]/internal/leafnodes/it_node.go:26 +0x87
 
  github.com/onsi/ginkgo/internal/spec.(*Spec).runSample()
 
      /go/pkg/mod/github.com/onsi/[email protected]/internal/spec/spec.go:215 +0x6e1
 
  github.com/onsi/ginkgo/internal/spec.(*Spec).Run()
 
      /go/pkg/mod/github.com/onsi/[email protected]/internal/spec/spec.go:138 +0x17e
 
  github.com/onsi/ginkgo/internal/specrunner.(*SpecRunner).runSpec()
 
      /go/pkg/mod/github.com/onsi/[email protected]/internal/specrunner/spec_runner.go:200 +0x172
 
  github.com/onsi/ginkgo/internal/specrunner.(*SpecRunner).runSpecs()
 
      /go/pkg/mod/github.com/onsi/[email protected]/internal/specrunner/spec_runner.go:170 +0x216
 
  github.com/onsi/ginkgo/internal/specrunner.(*SpecRunner).Run()
 
      /go/pkg/mod/github.com/onsi/[email protected]/internal/specrunner/spec_runner.go:66 +0x140
 
  github.com/onsi/ginkgo/internal/suite.(*Suite).Run()
 
      /go/pkg/mod/github.com/onsi/[email protected]/internal/suite/suite.go:62 +0x69f
 
  github.com/onsi/ginkgo.RunSpecsWithCustomReporters()
 
      /go/pkg/mod/github.com/onsi/[email protected]/ginkgo_dsl.go:226 +0x338
 
  github.com/onsi/ginkgo.RunSpecs()
 
      /go/pkg/mod/github.com/onsi/[email protected]/ginkgo_dsl.go:207 +0x24d
 
  github.com/lucas-clemente/quic-go/integrationtests/self_test.TestSelf()
 
      /go/src/github.com/lucas-clemente/quic-go/integrationtests/self/self_suite_test.go:162 +0xf8
 
  testing.tRunner()
 
      /usr/local/go/src/testing/testing.go:991 +0x1eb
 

 
Goroutine 426 (running) created at:
 
  github.com/lucas-clemente/quic-go.(*baseServer).createNewSession()
 
      /go/src/github.com/lucas-clemente/quic-go/server.go:457 +0x686
 
  github.com/lucas-clemente/quic-go.(*baseServer).handleInitialImpl()
 
      /go/src/github.com/lucas-clemente/quic-go/server.go:393 +0x6d5
 
  github.com/lucas-clemente/quic-go.(*baseServer).handlePacketImpl()
 
      /go/src/github.com/lucas-clemente/quic-go/server.go:335 +0x52b
 
  github.com/lucas-clemente/quic-go.(*baseServer).run()
 
      /go/src/github.com/lucas-clemente/quic-go/server.go:207 +0x21e
 
==================
@rip-create-your-account

I think this is caused by a double free by putStreamFrame because the frameSorter may insert the same frame callback at two different offsets.

diff --git a/frame_sorter_test.go b/frame_sorter_test.go
index de20bf2d..71ad0e45 100644
--- a/frame_sorter_test.go
+++ b/frame_sorter_test.go
@@ -2,6 +2,7 @@ package quic
 
 import (
 	"bytes"
+	"reflect"
 
 	"github.com/lucas-clemente/quic-go/internal/protocol"
 	"github.com/lucas-clemente/quic-go/internal/utils"
@@ -167,6 +168,35 @@ var _ = Describe("frame sorter", func() {
 				})
 			})
 
+			It("callback is inserted to two offsets", func() {
+				// make sure frames are not cut when we overlap a little bit
+				Expect(protocol.MinStreamFrameBufferSize).To(BeNumerically("<", 500/2))
+				initialCb1, _ := getCallback()
+				initialCb2, _ := getCallback()
+				Expect(s.Push(bytes.Repeat([]byte{1}, 100), 900, initialCb1)).To(Succeed())
+				Expect(s.Push(bytes.Repeat([]byte{1}, 400), 500, initialCb2)).To(Succeed())
+				Expect(s.queue).To(HaveKey(protocol.ByteCount(900)))
+				Expect(s.queue).To(HaveKey(protocol.ByteCount(500)))
+				checkGaps([]utils.ByteInterval{
+					{Start: 0, End: 500},
+					{Start: 1000, End: protocol.MaxByteCount},
+				})
+
+				cb, _ := getCallback()
+				// 900 to 1400
+				Expect(s.Push(bytes.Repeat([]byte{9}, 500), 900, cb)).To(Succeed())
+				Expect(s.queue).To(HaveKey(protocol.ByteCount(900)))
+				Expect(s.queue[900].Data).To(Equal(bytes.Repeat([]byte{9}, 500))) // 900 to 1400
+				checkGaps([]utils.ByteInterval{
+					{Start: 0, End: 500},
+					{Start: 1400, End: protocol.MaxByteCount},
+				})
+
+				// Test that the callback is inserted to two offsets
+				Expect(reflect.ValueOf(s.queue[900].DoneCb)).To(Equal(reflect.ValueOf(cb)))
+				Expect(reflect.ValueOf(s.queue[1000].DoneCb)).To(Equal(reflect.ValueOf(cb)))
+			})
+
 			Context("Overlapping Stream Data detection", func() {
 				var initialCb1, initialCb2, initialCb3 func()
 				var initialCb1Called, initialCb2Called, initialCb3Called *bool

@rip-create-your-account

Just noticed that s.queue[900].Data will end up with a length of 500 and s.queue[1000].Data with a length of 400. So this bug also corrupts the data stream. Considering that crypto streams use the same frame sorting logic then could #2545 be caused by this too?

@marten-seemann
Copy link
Member Author

Thank you, that seems to be a problem.
I've been debugging the frame sorter and it seems like there are a few bugs hiding here, #2544 and #2545 all being caused by this. I'm working on a rewrite of the frame sorter.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants