search

philippseith / signalr

SignalR server and client in go
MIT License
133 stars 39 forks source link

Data races in master #90

Closed andig closed 2 years ago

andig commented 2 years ago

Note this using the client:

WARNING: DATA RACE
Write at 0x00c0000100c0 by goroutine 62:
  github.com/philippseith/signalr.(*webSocketConnection).watchDog()
      /Users/andig/go/pkg/mod/github.com/philippseith/signalr@v0.4.2-0.20211105081818-e7b6db33ef38/websocketconnection.go:99 +0x2b4

Previous read at 0x00c0000100c0 by goroutine 71:
  github.com/philippseith/signalr.(*webSocketConnection).watchDog.func3()
      /Users/andig/go/pkg/mod/github.com/philippseith/signalr@v0.4.2-0.20211105081818-e7b6db33ef38/websocketconnection.go:104 +0x48

Goroutine 62 (running) created at:
  github.com/philippseith/signalr.newWebSocketConnection()
      /Users/andig/go/pkg/mod/github.com/philippseith/signalr@v0.4.2-0.20211105081818-e7b6db33ef38/websocketconnection.go:28 +0x1dc
  github.com/philippseith/signalr.NewHTTPConnection()
      /Users/andig/go/pkg/mod/github.com/philippseith/signalr@v0.4.2-0.20211105081818-e7b6db33ef38/httpconnection.go:122 +0x980
  github.com/evcc-io/evcc/charger.(*Easee).connect.func1()
      /Users/andig/htdocs/evcc/charger/easee.go:153 +0x200
  github.com/philippseith/signalr.(*client).setupConnectionAndProtocol.func1()
      /Users/andig/go/pkg/mod/github.com/philippseith/signalr@v0.4.2-0.20211105081818-e7b6db33ef38/client.go:199 +0xcc
  github.com/philippseith/signalr.(*client).setupConnectionAndProtocol()
      /Users/andig/go/pkg/mod/github.com/philippseith/signalr@v0.4.2-0.20211105081818-e7b6db33ef38/client.go:210 +0x30
  github.com/philippseith/signalr.(*client).run()
      /Users/andig/go/pkg/mod/github.com/philippseith/signalr@v0.4.2-0.20211105081818-e7b6db33ef38/client.go:159 +0x30
  github.com/philippseith/signalr.(*client).Start.func1()
      /Users/andig/go/pkg/mod/github.com/philippseith/signalr@v0.4.2-0.20211105081818-e7b6db33ef38/client.go:128 +0xfc

Goroutine 71 (running) created at:
  github.com/philippseith/signalr.(*webSocketConnection).watchDog()
      /Users/andig/go/pkg/mod/github.com/philippseith/signalr@v0.4.2-0.20211105081818-e7b6db33ef38/websocketconnection.go:101 +0x364
==================
==================
WARNING: DATA RACE
Write at 0x00c0000100c8 by goroutine 62:
  github.com/philippseith/signalr.(*webSocketConnection).watchDog()
      /Users/andig/go/pkg/mod/github.com/philippseith/signalr@v0.4.2-0.20211105081818-e7b6db33ef38/websocketconnection.go:100 +0x30c

Previous read at 0x00c0000100c8 by goroutine 71:
  github.com/philippseith/signalr.(*webSocketConnection).watchDog.func3()
      /Users/andig/go/pkg/mod/github.com/philippseith/signalr@v0.4.2-0.20211105081818-e7b6db33ef38/websocketconnection.go:103 +0x30

Goroutine 62 (running) created at:
  github.com/philippseith/signalr.newWebSocketConnection()
      /Users/andig/go/pkg/mod/github.com/philippseith/signalr@v0.4.2-0.20211105081818-e7b6db33ef38/websocketconnection.go:28 +0x1dc
  github.com/philippseith/signalr.NewHTTPConnection()
      /Users/andig/go/pkg/mod/github.com/philippseith/signalr@v0.4.2-0.20211105081818-e7b6db33ef38/httpconnection.go:122 +0x980
  github.com/evcc-io/evcc/charger.(*Easee).connect.func1()
      /Users/andig/htdocs/evcc/charger/easee.go:153 +0x200
  github.com/philippseith/signalr.(*client).setupConnectionAndProtocol.func1()
      /Users/andig/go/pkg/mod/github.com/philippseith/signalr@v0.4.2-0.20211105081818-e7b6db33ef38/client.go:199 +0xcc
  github.com/philippseith/signalr.(*client).setupConnectionAndProtocol()
      /Users/andig/go/pkg/mod/github.com/philippseith/signalr@v0.4.2-0.20211105081818-e7b6db33ef38/client.go:210 +0x30
  github.com/philippseith/signalr.(*client).run()
      /Users/andig/go/pkg/mod/github.com/philippseith/signalr@v0.4.2-0.20211105081818-e7b6db33ef38/client.go:159 +0x30
  github.com/philippseith/signalr.(*client).Start.func1()
      /Users/andig/go/pkg/mod/github.com/philippseith/signalr@v0.4.2-0.20211105081818-e7b6db33ef38/client.go:128 +0xfc

Goroutine 71 (running) created at:
  github.com/philippseith/signalr.(*webSocketConnection).watchDog()
      /Users/andig/go/pkg/mod/github.com/philippseith/signalr@v0.4.2-0.20211105081818-e7b6db33ef38/websocketconnection.go:101 +0x364
==================

I've also noticed https://github.com/philippseith/signalr/blob/master/client.go#L123 is not guarded by a lock.

andig commented 2 years ago

Both seem to be the same case and race accessing timer in watchDog:

    case food := <-w.watchDogChan:
        if timer != nil {
            if !timer.Stop() {
                go func() {
                    <-timer.C
                }()
            }
            go func() {
                cancelTimeoutChan <- struct{}{}
            }()
        }

The entire block is racy, also regarding cancelTimeoutChan. I think the key could be to use only one channel/timer and reuse those. I don't fully understand the code though.

andig commented 2 years ago

That's not the only races though. The entire test suite is racy:

❯ got -race ./...
package t1
Running Suite: SignalR Suite
============================
Random Seed: 1636115067
Will run 166 of 166 specs

••••==================
WARNING: DATA RACE
Write at 0x00c000194500 by goroutine 35:
  ??()
      -:0 +0x100031cd8
  github.com/philippseith/signalr.(*loop).GetNewID()
      /Users/andig/htdocs/signalr/loop.go:174 +0x3c
  github.com/philippseith/signalr.(*client).Invoke.func1()
      /Users/andig/htdocs/signalr/client.go:306 +0x7c

Previous read at 0x00c000194500 by goroutine 109:
  github.com/philippseith/signalr.(*loop).GetNewID()
      /Users/andig/htdocs/signalr/loop.go:175 +0x4c
  github.com/philippseith/signalr.(*client).Invoke.func1()
      /Users/andig/htdocs/signalr/client.go:306 +0x7c

Goroutine 35 (running) created at:
  github.com/philippseith/signalr.(*client).Invoke()
      /Users/andig/htdocs/signalr/client.go:299 +0x90
  github.com/philippseith/signalr.glob..func1.2.3()
      /Users/andig/htdocs/signalr/client_test.go:187 +0x1a0
  runtime.call16()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/runtime/asm_arm64.s:414 +0x70
  reflect.Value.Call()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/reflect/value.go:339 +0x98
  github.com/onsi/ginkgo/internal/leafnodes.newRunner.func1()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/leafnodes/runner.go:49 +0x31c
  github.com/onsi/ginkgo/internal/leafnodes.(*runner).runAsync.func1()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/leafnodes/runner.go:86 +0x94

Goroutine 109 (running) created at:
  github.com/philippseith/signalr.(*client).Invoke()
      /Users/andig/htdocs/signalr/client.go:299 +0x90
  github.com/philippseith/signalr.glob..func1.2.3()
      /Users/andig/htdocs/signalr/client_test.go:188 +0x288
  runtime.call16()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/runtime/asm_arm64.s:414 +0x70
  reflect.Value.Call()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/reflect/value.go:339 +0x98
  github.com/onsi/ginkgo/internal/leafnodes.newRunner.func1()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/leafnodes/runner.go:49 +0x31c
  github.com/onsi/ginkgo/internal/leafnodes.(*runner).runAsync.func1()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/leafnodes/runner.go:86 +0x94
==================
•••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••••==================
WARNING: DATA RACE
Write at 0x00c0000103a8 by goroutine 196:
  github.com/philippseith/signalr.(*webSocketConnection).watchDog()
      /Users/andig/htdocs/signalr/websocketconnection.go:99 +0x2b4

Previous read at 0x00c0000103a8 by goroutine 424:
  github.com/philippseith/signalr.(*webSocketConnection).watchDog.func3()
      /Users/andig/htdocs/signalr/websocketconnection.go:104 +0x48

Goroutine 196 (running) created at:
  github.com/philippseith/signalr.newWebSocketConnection()
      /Users/andig/htdocs/signalr/websocketconnection.go:28 +0x1dc
  github.com/philippseith/signalr.(*httpMux).handleWebsocket()
      /Users/andig/htdocs/signalr/httpmux.go:150 +0x74c
  github.com/philippseith/signalr.(*httpMux).handleGet()
      /Users/andig/htdocs/signalr/httpmux.go:75 +0x16c
  github.com/philippseith/signalr.(*httpMux).ServeHTTP()
      /Users/andig/htdocs/signalr/httpmux.go:35 +0x84
  net/http.(*ServeMux).ServeHTTP()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:2424 +0xb4
  net/http.serverHandler.ServeHTTP()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:2878 +0x7dc
  net/http.(*conn).serve()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:1929 +0x11a8

Goroutine 424 (running) created at:
  github.com/philippseith/signalr.(*webSocketConnection).watchDog()
      /Users/andig/htdocs/signalr/websocketconnection.go:101 +0x364
==================
==================
WARNING: DATA RACE
Write at 0x00c0000103c0 by goroutine 196:
  github.com/philippseith/signalr.(*webSocketConnection).watchDog()
      /Users/andig/htdocs/signalr/websocketconnection.go:100 +0x30c

Previous read at 0x00c0000103c0 by goroutine 424:
  github.com/philippseith/signalr.(*webSocketConnection).watchDog.func3()
      /Users/andig/htdocs/signalr/websocketconnection.go:103 +0x30

Goroutine 196 (running) created at:
  github.com/philippseith/signalr.newWebSocketConnection()
      /Users/andig/htdocs/signalr/websocketconnection.go:28 +0x1dc
  github.com/philippseith/signalr.(*httpMux).handleWebsocket()
      /Users/andig/htdocs/signalr/httpmux.go:150 +0x74c
  github.com/philippseith/signalr.(*httpMux).handleGet()
      /Users/andig/htdocs/signalr/httpmux.go:75 +0x16c
  github.com/philippseith/signalr.(*httpMux).ServeHTTP()
      /Users/andig/htdocs/signalr/httpmux.go:35 +0x84
  net/http.(*ServeMux).ServeHTTP()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:2424 +0xb4
  net/http.serverHandler.ServeHTTP()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:2878 +0x7dc
  net/http.(*conn).serve()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:1929 +0x11a8

Goroutine 424 (running) created at:
  github.com/philippseith/signalr.(*webSocketConnection).watchDog()
      /Users/andig/htdocs/signalr/websocketconnection.go:101 +0x364
==================
•••••••==================
WARNING: DATA RACE
Read at 0x00c000d460e8 by goroutine 437:
  bufio.(*Writer).Available()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/bufio/bufio.go:624 +0xa0
  bufio.(*Writer).WriteString()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/bufio/bufio.go:706 +0x28
  net/http.(*chunkWriter).close()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:407 +0xd4
  net/http.(*response).finishRequest()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:1607 +0xbc
  net/http.(*conn).serve()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:1934 +0x11e8

Previous write at 0x00c000d460e8 by goroutine 479:
  bufio.(*Writer).Flush()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/bufio/bufio.go:619 +0x310
  net/http.(*chunkWriter).flush()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:397 +0xa4
  net/http.(*response).Flush()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:1659 +0x84
  github.com/philippseith/signalr.(*serverSSEConnection).Write()
      /Users/andig/htdocs/signalr/serversseconnection.go:89 +0x2cc
  github.com/philippseith/signalr.(*jsonHubProtocol).WriteMessage()
      /Users/andig/htdocs/signalr/jsonhubprotocol.go:212 +0x2f4
  github.com/philippseith/signalr.(*defaultHubConnection).writeMessage.func1.1()
      /Users/andig/htdocs/signalr/hubconnection.go:228 +0xb4

Goroutine 437 (running) created at:
  net/http.(*Server).Serve()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:3033 +0x6c0
  net/http.(*Server).ListenAndServe()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:2930 +0xe4
  net/http.ListenAndServe()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:3184 +0x17c
  github.com/philippseith/signalr.glob..func6.1.3.1.1()
      /Users/andig/htdocs/signalr/httpserver_test.go:103 +0x28

Goroutine 479 (finished) created at:
  github.com/philippseith/signalr.(*defaultHubConnection).writeMessage.func1()
      /Users/andig/htdocs/signalr/hubconnection.go:228 +0x190
  github.com/philippseith/signalr.(*defaultHubConnection).writeMessage()
      /Users/andig/htdocs/signalr/hubconnection.go:238 +0xd4
  github.com/philippseith/signalr.(*defaultHubConnection).Completion()
      /Users/andig/htdocs/signalr/hubconnection.go:203 +0xbc
  github.com/philippseith/signalr.completion()
      /Users/andig/htdocs/signalr/loop.go:309 +0x84
  github.com/philippseith/signalr.(*loop).sendResult()
      /Users/andig/htdocs/signalr/loop.go:300 +0xdc
  github.com/philippseith/signalr.(*loop).returnInvocationResult()
      /Users/andig/htdocs/signalr/loop.go:239 +0x2c0
  github.com/philippseith/signalr.(*loop).handleInvocationMessage.func2()
      /Users/andig/htdocs/signalr/loop.go:208 +0xfc
==================
==================
WARNING: DATA RACE
Write at 0x00c000d48000 by goroutine 437:
  runtime.slicecopy()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/runtime/slice.go:284 +0x0
  bufio.(*Writer).WriteString()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/bufio/bufio.go:716 +0x244
  net/http.(*chunkWriter).close()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:407 +0xd4
  net/http.(*response).finishRequest()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:1607 +0xbc
  net/http.(*conn).serve()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:1934 +0x11e8

Previous read at 0x00c000d48000 by goroutine 479:
  internal/race.ReadRange()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/internal/race/race.go:46 +0x98
  syscall.Write()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/syscall/syscall_unix.go:217 +0x80
  internal/poll.ignoringEINTRIO()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/internal/poll/fd_unix.go:582 +0x3f0
  internal/poll.(*FD).Write()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/internal/poll/fd_unix.go:275 +0x1f0
  net.(*netFD).Write()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/fd_posix.go:74 +0x4c
  net.(*conn).Write()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/net.go:195 +0x9c
  net.(*TCPConn).Write()
      <autogenerated>:1 +0x54
  net/http.checkConnErrorWriter.Write()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:3532 +0x68
  bufio.(*Writer).Flush()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/bufio/bufio.go:607 +0xe0
  net/http.(*chunkWriter).flush()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:397 +0xa4
  net/http.(*response).Flush()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:1659 +0x84
  github.com/philippseith/signalr.(*serverSSEConnection).Write()
      /Users/andig/htdocs/signalr/serversseconnection.go:89 +0x2cc
  github.com/philippseith/signalr.(*jsonHubProtocol).WriteMessage()
      /Users/andig/htdocs/signalr/jsonhubprotocol.go:212 +0x2f4
  github.com/philippseith/signalr.(*defaultHubConnection).writeMessage.func1.1()
      /Users/andig/htdocs/signalr/hubconnection.go:228 +0xb4

Goroutine 437 (running) created at:
  net/http.(*Server).Serve()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:3033 +0x6c0
  net/http.(*Server).ListenAndServe()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:2930 +0xe4
  net/http.ListenAndServe()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:3184 +0x17c
  github.com/philippseith/signalr.glob..func6.1.3.1.1()
      /Users/andig/htdocs/signalr/httpserver_test.go:103 +0x28

Goroutine 479 (finished) created at:
  github.com/philippseith/signalr.(*defaultHubConnection).writeMessage.func1()
      /Users/andig/htdocs/signalr/hubconnection.go:228 +0x190
  github.com/philippseith/signalr.(*defaultHubConnection).writeMessage()
      /Users/andig/htdocs/signalr/hubconnection.go:238 +0xd4
  github.com/philippseith/signalr.(*defaultHubConnection).Completion()
      /Users/andig/htdocs/signalr/hubconnection.go:203 +0xbc
  github.com/philippseith/signalr.completion()
      /Users/andig/htdocs/signalr/loop.go:309 +0x84
  github.com/philippseith/signalr.(*loop).sendResult()
      /Users/andig/htdocs/signalr/loop.go:300 +0xdc
  github.com/philippseith/signalr.(*loop).returnInvocationResult()
      /Users/andig/htdocs/signalr/loop.go:239 +0x2c0
  github.com/philippseith/signalr.(*loop).handleInvocationMessage.func2()
      /Users/andig/htdocs/signalr/loop.go:208 +0xfc
==================
•==================
WARNING: DATA RACE
Read at 0x00c00066adc0 by goroutine 229:
  github.com/philippseith/signalr.(*webSocketConnection).watchDog.func3()
      /Users/andig/htdocs/signalr/websocketconnection.go:104 +0x60

Previous write at 0x00c00066adc0 by goroutine 409:
  time.NewTimer()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/time/sleep.go:89 +0x78
  github.com/philippseith/signalr.(*webSocketConnection).watchDog()
      /Users/andig/htdocs/signalr/websocketconnection.go:99 +0x2a0

Goroutine 229 (running) created at:
  github.com/philippseith/signalr.(*webSocketConnection).watchDog()
      /Users/andig/htdocs/signalr/websocketconnection.go:101 +0x364

Goroutine 409 (running) created at:
  github.com/philippseith/signalr.newWebSocketConnection()
      /Users/andig/htdocs/signalr/websocketconnection.go:28 +0x1dc
  github.com/philippseith/signalr.(*httpMux).handleWebsocket()
      /Users/andig/htdocs/signalr/httpmux.go:150 +0x74c
  github.com/philippseith/signalr.(*httpMux).handleGet()
      /Users/andig/htdocs/signalr/httpmux.go:75 +0x16c
  github.com/philippseith/signalr.(*httpMux).ServeHTTP()
      /Users/andig/htdocs/signalr/httpmux.go:35 +0x84
  net/http.(*ServeMux).ServeHTTP()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:2424 +0xb4
  net/http.serverHandler.ServeHTTP()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:2878 +0x7dc
  net/http.(*conn).serve()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:1929 +0x11a8
==================
•••••••••••••••••••••••••••••••••==================
WARNING: DATA RACE
Read at 0x00c0003f2638 by goroutine 617:
  github.com/philippseith/signalr.(*testingConnection).ConnectionID()
      /Users/andig/htdocs/signalr/testingconnection_test.go:49 +0x40
  github.com/philippseith/signalr.glob..func9.4.1()
      /Users/andig/htdocs/signalr/hubcontext_test.go:218 +0x74
  runtime.call16()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/runtime/asm_arm64.s:414 +0x70
  reflect.Value.Call()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/reflect/value.go:339 +0x98
  github.com/onsi/ginkgo/internal/leafnodes.newRunner.func1()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/leafnodes/runner.go:49 +0x31c
  github.com/onsi/ginkgo/internal/leafnodes.(*runner).runAsync.func1()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/leafnodes/runner.go:86 +0x94

Previous write at 0x00c0003f2638 by goroutine 577:
  github.com/philippseith/signalr.(*testingConnection).ConnectionID()
      /Users/andig/htdocs/signalr/testingconnection_test.go:53 +0x150
  github.com/philippseith/signalr.(*server).processHandshake()
      /Users/andig/htdocs/signalr/server.go:199 +0x48
  github.com/philippseith/signalr.(*server).Serve()
      /Users/andig/htdocs/signalr/server.go:111 +0x44
  github.com/philippseith/signalr.connectMany.func1()
      /Users/andig/htdocs/signalr/hubcontext_test.go:97 +0x8c

Goroutine 617 (running) created at:
  github.com/onsi/ginkgo/internal/leafnodes.(*runner).runAsync()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/leafnodes/runner.go:71 +0x84
  github.com/onsi/ginkgo/internal/leafnodes.(*runner).run()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/leafnodes/runner.go:62 +0x78
  github.com/onsi/ginkgo/internal/leafnodes.(*ItNode).Run()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/leafnodes/it_node.go:26 +0x74
  github.com/onsi/ginkgo/internal/spec.(*Spec).runSample()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/spec/spec.go:215 +0x2a8
  github.com/onsi/ginkgo/internal/spec.(*Spec).Run()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/spec/spec.go:138 +0x17c
  github.com/onsi/ginkgo/internal/specrunner.(*SpecRunner).runSpec()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/specrunner/spec_runner.go:200 +0x164
  github.com/onsi/ginkgo/internal/specrunner.(*SpecRunner).runSpecs()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/specrunner/spec_runner.go:170 +0x278
  github.com/onsi/ginkgo/internal/specrunner.(*SpecRunner).Run()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/specrunner/spec_runner.go:66 +0xc4
  github.com/onsi/ginkgo/internal/suite.(*Suite).Run()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/suite/suite.go:62 +0x598
  github.com/onsi/ginkgo.RunSpecsWithCustomReporters()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/ginkgo_dsl.go:226 +0x1c4
  github.com/onsi/ginkgo.RunSpecs()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/ginkgo_dsl.go:207 +0x1ec
  github.com/philippseith/signalr.TestSignalR()
      /Users/andig/htdocs/signalr/signalr_suite_test.go:14 +0x13c
  testing.tRunner()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/testing/testing.go:1259 +0x198

Goroutine 577 (running) created at:
  github.com/philippseith/signalr.connectMany()
      /Users/andig/htdocs/signalr/hubcontext_test.go:95 +0x2cc
  github.com/philippseith/signalr.glob..func9.1()
      /Users/andig/htdocs/signalr/hubcontext_test.go:169 +0x38
  runtime.call16()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/runtime/asm_arm64.s:414 +0x70
  reflect.Value.Call()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/reflect/value.go:339 +0x98
  github.com/onsi/ginkgo/internal/leafnodes.newRunner.func1()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/leafnodes/runner.go:49 +0x31c
  github.com/onsi/ginkgo/internal/leafnodes.(*runner).runAsync.func1()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/leafnodes/runner.go:86 +0x94
==================
•==================
WARNING: DATA RACE
Read at 0x00c000afa848 by goroutine 636:
  github.com/philippseith/signalr.(*testingConnection).ConnectionID()
      /Users/andig/htdocs/signalr/testingconnection_test.go:49 +0x40
  github.com/philippseith/signalr.glob..func9.5.1()
      /Users/andig/htdocs/signalr/hubcontext_test.go:259 +0x74
  runtime.call16()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/runtime/asm_arm64.s:414 +0x70
  reflect.Value.Call()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/reflect/value.go:339 +0x98
  github.com/onsi/ginkgo/internal/leafnodes.newRunner.func1()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/leafnodes/runner.go:49 +0x31c
  github.com/onsi/ginkgo/internal/leafnodes.(*runner).runAsync.func1()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/leafnodes/runner.go:86 +0x94

Previous write at 0x00c000afa848 by goroutine 491:
  github.com/philippseith/signalr.(*testingConnection).ConnectionID()
      /Users/andig/htdocs/signalr/testingconnection_test.go:53 +0x150
  github.com/philippseith/signalr.(*server).processHandshake()
      /Users/andig/htdocs/signalr/server.go:199 +0x48
  github.com/philippseith/signalr.(*server).Serve()
      /Users/andig/htdocs/signalr/server.go:111 +0x44
  github.com/philippseith/signalr.connectMany.func1()
      /Users/andig/htdocs/signalr/hubcontext_test.go:97 +0x8c

Goroutine 636 (running) created at:
  github.com/onsi/ginkgo/internal/leafnodes.(*runner).runAsync()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/leafnodes/runner.go:71 +0x84
  github.com/onsi/ginkgo/internal/leafnodes.(*runner).run()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/leafnodes/runner.go:62 +0x78
  github.com/onsi/ginkgo/internal/leafnodes.(*ItNode).Run()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/leafnodes/it_node.go:26 +0x74
  github.com/onsi/ginkgo/internal/spec.(*Spec).runSample()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/spec/spec.go:215 +0x2a8
  github.com/onsi/ginkgo/internal/spec.(*Spec).Run()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/spec/spec.go:138 +0x17c
  github.com/onsi/ginkgo/internal/specrunner.(*SpecRunner).runSpec()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/specrunner/spec_runner.go:200 +0x164
  github.com/onsi/ginkgo/internal/specrunner.(*SpecRunner).runSpecs()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/specrunner/spec_runner.go:170 +0x278
  github.com/onsi/ginkgo/internal/specrunner.(*SpecRunner).Run()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/specrunner/spec_runner.go:66 +0xc4
  github.com/onsi/ginkgo/internal/suite.(*Suite).Run()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/suite/suite.go:62 +0x598
  github.com/onsi/ginkgo.RunSpecsWithCustomReporters()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/ginkgo_dsl.go:226 +0x1c4
  github.com/onsi/ginkgo.RunSpecs()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/ginkgo_dsl.go:207 +0x1ec
  github.com/philippseith/signalr.TestSignalR()
      /Users/andig/htdocs/signalr/signalr_suite_test.go:14 +0x13c
  testing.tRunner()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/testing/testing.go:1259 +0x198

Goroutine 491 (running) created at:
  github.com/philippseith/signalr.connectMany()
      /Users/andig/htdocs/signalr/hubcontext_test.go:95 +0x2cc
  github.com/philippseith/signalr.glob..func9.1()
      /Users/andig/htdocs/signalr/hubcontext_test.go:169 +0x38
  runtime.call16()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/runtime/asm_arm64.s:414 +0x70
  reflect.Value.Call()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/reflect/value.go:339 +0x98
  github.com/onsi/ginkgo/internal/leafnodes.newRunner.func1()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/leafnodes/runner.go:49 +0x31c
  github.com/onsi/ginkgo/internal/leafnodes.(*runner).runAsync.func1()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/leafnodes/runner.go:86 +0x94
==================
==================
WARNING: DATA RACE
Read at 0x00c000afa8f8 by goroutine 636:
  github.com/philippseith/signalr.(*testingConnection).ConnectionID()
      /Users/andig/htdocs/signalr/testingconnection_test.go:49 +0x40
  github.com/philippseith/signalr.glob..func9.5.1()
      /Users/andig/htdocs/signalr/hubcontext_test.go:259 +0xc4
  runtime.call16()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/runtime/asm_arm64.s:414 +0x70
  reflect.Value.Call()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/reflect/value.go:339 +0x98
  github.com/onsi/ginkgo/internal/leafnodes.newRunner.func1()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/leafnodes/runner.go:49 +0x31c
  github.com/onsi/ginkgo/internal/leafnodes.(*runner).runAsync.func1()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/leafnodes/runner.go:86 +0x94

Previous write at 0x00c000afa8f8 by goroutine 492:
  github.com/philippseith/signalr.(*testingConnection).ConnectionID()
      /Users/andig/htdocs/signalr/testingconnection_test.go:53 +0x150
  github.com/philippseith/signalr.(*server).processHandshake()
      /Users/andig/htdocs/signalr/server.go:199 +0x48
  github.com/philippseith/signalr.(*server).Serve()
      /Users/andig/htdocs/signalr/server.go:111 +0x44
  github.com/philippseith/signalr.connectMany.func1()
      /Users/andig/htdocs/signalr/hubcontext_test.go:97 +0x8c

Goroutine 636 (running) created at:
  github.com/onsi/ginkgo/internal/leafnodes.(*runner).runAsync()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/leafnodes/runner.go:71 +0x84
  github.com/onsi/ginkgo/internal/leafnodes.(*runner).run()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/leafnodes/runner.go:62 +0x78
  github.com/onsi/ginkgo/internal/leafnodes.(*ItNode).Run()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/leafnodes/it_node.go:26 +0x74
  github.com/onsi/ginkgo/internal/spec.(*Spec).runSample()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/spec/spec.go:215 +0x2a8
  github.com/onsi/ginkgo/internal/spec.(*Spec).Run()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/spec/spec.go:138 +0x17c
  github.com/onsi/ginkgo/internal/specrunner.(*SpecRunner).runSpec()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/specrunner/spec_runner.go:200 +0x164
  github.com/onsi/ginkgo/internal/specrunner.(*SpecRunner).runSpecs()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/specrunner/spec_runner.go:170 +0x278
  github.com/onsi/ginkgo/internal/specrunner.(*SpecRunner).Run()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/specrunner/spec_runner.go:66 +0xc4
  github.com/onsi/ginkgo/internal/suite.(*Suite).Run()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/suite/suite.go:62 +0x598
  github.com/onsi/ginkgo.RunSpecsWithCustomReporters()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/ginkgo_dsl.go:226 +0x1c4
  github.com/onsi/ginkgo.RunSpecs()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/ginkgo_dsl.go:207 +0x1ec
  github.com/philippseith/signalr.TestSignalR()
      /Users/andig/htdocs/signalr/signalr_suite_test.go:14 +0x13c
  testing.tRunner()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/testing/testing.go:1259 +0x198

Goroutine 492 (running) created at:
  github.com/philippseith/signalr.connectMany()
      /Users/andig/htdocs/signalr/hubcontext_test.go:95 +0x2cc
  github.com/philippseith/signalr.glob..func9.1()
      /Users/andig/htdocs/signalr/hubcontext_test.go:169 +0x38
  runtime.call16()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/runtime/asm_arm64.s:414 +0x70
  reflect.Value.Call()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/reflect/value.go:339 +0x98
  github.com/onsi/ginkgo/internal/leafnodes.newRunner.func1()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/leafnodes/runner.go:49 +0x31c
  github.com/onsi/ginkgo/internal/leafnodes.(*runner).runAsync.func1()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/leafnodes/runner.go:86 +0x94
==================
•==================
WARNING: DATA RACE
Read at 0x00c0004522c8 by goroutine 646:
  github.com/philippseith/signalr.(*testingConnection).ConnectionID()
      /Users/andig/htdocs/signalr/testingconnection_test.go:49 +0x40
  github.com/philippseith/signalr.glob..func9.6.1()
      /Users/andig/htdocs/signalr/hubcontext_test.go:303 +0x74
  runtime.call16()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/runtime/asm_arm64.s:414 +0x70
  reflect.Value.Call()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/reflect/value.go:339 +0x98
  github.com/onsi/ginkgo/internal/leafnodes.newRunner.func1()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/leafnodes/runner.go:49 +0x31c
  github.com/onsi/ginkgo/internal/leafnodes.(*runner).runAsync.func1()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/leafnodes/runner.go:86 +0x94

Previous write at 0x00c0004522c8 by goroutine 550:
  github.com/philippseith/signalr.(*testingConnection).ConnectionID()
      /Users/andig/htdocs/signalr/testingconnection_test.go:53 +0x150
  github.com/philippseith/signalr.(*server).processHandshake()
      /Users/andig/htdocs/signalr/server.go:199 +0x48
  github.com/philippseith/signalr.(*server).Serve()
      /Users/andig/htdocs/signalr/server.go:111 +0x44
  github.com/philippseith/signalr.connectMany.func1()
      /Users/andig/htdocs/signalr/hubcontext_test.go:97 +0x8c

Goroutine 646 (running) created at:
  github.com/onsi/ginkgo/internal/leafnodes.(*runner).runAsync()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/leafnodes/runner.go:71 +0x84
  github.com/onsi/ginkgo/internal/leafnodes.(*runner).run()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/leafnodes/runner.go:62 +0x78
  github.com/onsi/ginkgo/internal/leafnodes.(*ItNode).Run()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/leafnodes/it_node.go:26 +0x74
  github.com/onsi/ginkgo/internal/spec.(*Spec).runSample()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/spec/spec.go:215 +0x2a8
  github.com/onsi/ginkgo/internal/spec.(*Spec).Run()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/spec/spec.go:138 +0x17c
  github.com/onsi/ginkgo/internal/specrunner.(*SpecRunner).runSpec()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/specrunner/spec_runner.go:200 +0x164
  github.com/onsi/ginkgo/internal/specrunner.(*SpecRunner).runSpecs()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/specrunner/spec_runner.go:170 +0x278
  github.com/onsi/ginkgo/internal/specrunner.(*SpecRunner).Run()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/specrunner/spec_runner.go:66 +0xc4
  github.com/onsi/ginkgo/internal/suite.(*Suite).Run()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/suite/suite.go:62 +0x598
  github.com/onsi/ginkgo.RunSpecsWithCustomReporters()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/ginkgo_dsl.go:226 +0x1c4
  github.com/onsi/ginkgo.RunSpecs()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/ginkgo_dsl.go:207 +0x1ec
  github.com/philippseith/signalr.TestSignalR()
      /Users/andig/htdocs/signalr/signalr_suite_test.go:14 +0x13c
  testing.tRunner()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/testing/testing.go:1259 +0x198

Goroutine 550 (running) created at:
  github.com/philippseith/signalr.connectMany()
      /Users/andig/htdocs/signalr/hubcontext_test.go:95 +0x2cc
  github.com/philippseith/signalr.glob..func9.1()
      /Users/andig/htdocs/signalr/hubcontext_test.go:169 +0x38
  runtime.call16()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/runtime/asm_arm64.s:414 +0x70
  reflect.Value.Call()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/reflect/value.go:339 +0x98
  github.com/onsi/ginkgo/internal/leafnodes.newRunner.func1()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/leafnodes/runner.go:49 +0x31c
  github.com/onsi/ginkgo/internal/leafnodes.(*runner).runAsync.func1()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/leafnodes/runner.go:86 +0x94
==================
==================
WARNING: DATA RACE
Read at 0x00c000452378 by goroutine 646:
  github.com/philippseith/signalr.(*testingConnection).ConnectionID()
      /Users/andig/htdocs/signalr/testingconnection_test.go:49 +0x40
  github.com/philippseith/signalr.glob..func9.6.1()
      /Users/andig/htdocs/signalr/hubcontext_test.go:303 +0xc4
  runtime.call16()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/runtime/asm_arm64.s:414 +0x70
  reflect.Value.Call()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/reflect/value.go:339 +0x98
  github.com/onsi/ginkgo/internal/leafnodes.newRunner.func1()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/leafnodes/runner.go:49 +0x31c
  github.com/onsi/ginkgo/internal/leafnodes.(*runner).runAsync.func1()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/leafnodes/runner.go:86 +0x94

Previous write at 0x00c000452378 by goroutine 598:
  github.com/philippseith/signalr.(*testingConnection).ConnectionID()
      /Users/andig/htdocs/signalr/testingconnection_test.go:53 +0x150
  github.com/philippseith/signalr.(*server).processHandshake()
      /Users/andig/htdocs/signalr/server.go:199 +0x48
  github.com/philippseith/signalr.(*server).Serve()
      /Users/andig/htdocs/signalr/server.go:111 +0x44
  github.com/philippseith/signalr.connectMany.func1()
      /Users/andig/htdocs/signalr/hubcontext_test.go:97 +0x8c

Goroutine 646 (running) created at:
  github.com/onsi/ginkgo/internal/leafnodes.(*runner).runAsync()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/leafnodes/runner.go:71 +0x84
  github.com/onsi/ginkgo/internal/leafnodes.(*runner).run()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/leafnodes/runner.go:62 +0x78
  github.com/onsi/ginkgo/internal/leafnodes.(*ItNode).Run()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/leafnodes/it_node.go:26 +0x74
  github.com/onsi/ginkgo/internal/spec.(*Spec).runSample()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/spec/spec.go:215 +0x2a8
  github.com/onsi/ginkgo/internal/spec.(*Spec).Run()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/spec/spec.go:138 +0x17c
  github.com/onsi/ginkgo/internal/specrunner.(*SpecRunner).runSpec()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/specrunner/spec_runner.go:200 +0x164
  github.com/onsi/ginkgo/internal/specrunner.(*SpecRunner).runSpecs()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/specrunner/spec_runner.go:170 +0x278
  github.com/onsi/ginkgo/internal/specrunner.(*SpecRunner).Run()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/specrunner/spec_runner.go:66 +0xc4
  github.com/onsi/ginkgo/internal/suite.(*Suite).Run()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/suite/suite.go:62 +0x598
  github.com/onsi/ginkgo.RunSpecsWithCustomReporters()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/ginkgo_dsl.go:226 +0x1c4
  github.com/onsi/ginkgo.RunSpecs()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/ginkgo_dsl.go:207 +0x1ec
  github.com/philippseith/signalr.TestSignalR()
      /Users/andig/htdocs/signalr/signalr_suite_test.go:14 +0x13c
  testing.tRunner()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/testing/testing.go:1259 +0x198

Goroutine 598 (running) created at:
  github.com/philippseith/signalr.connectMany()
      /Users/andig/htdocs/signalr/hubcontext_test.go:95 +0x2cc
  github.com/philippseith/signalr.glob..func9.1()
      /Users/andig/htdocs/signalr/hubcontext_test.go:169 +0x38
  runtime.call16()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/runtime/asm_arm64.s:414 +0x70
  reflect.Value.Call()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/reflect/value.go:339 +0x98
  github.com/onsi/ginkgo/internal/leafnodes.newRunner.func1()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/leafnodes/runner.go:49 +0x31c
  github.com/onsi/ginkgo/internal/leafnodes.(*runner).runAsync.func1()
      /Users/andig/go/pkg/mod/github.com/onsi/ginkgo@v1.12.1/internal/leafnodes/runner.go:86 +0x94
==================
••••••••••••••••••••••••••••••••••••••••••••••••••••••
Ran 166 of 166 Specs in 7.143 seconds
SUCCESS! -- 166 Passed | 0 Failed | 0 Pending | 0 Skipped
--- FAIL: TestSignalR (7.14s)
    testing.go:1152: race detected during execution of test
FAIL
FAIL    github.com/philippseith/signalr 7.407s
?       github.com/philippseith/signalr/chatsample  [no test files]
?       github.com/philippseith/signalr/chatsample/middleware   [no test files]
?       github.com/philippseith/signalr/chatsample/public   [no test files]
Running Suite: SignalR external Suite
=====================================
Random Seed: 1636115067
Will run 5 of 5 specs

•••••
Ran 5 of 5 Specs in 0.607 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
==================
WARNING: DATA RACE
Write at 0x00c000348010 by goroutine 79:
  github.com/philippseith/signalr.(*webSocketConnection).watchDog()
      /Users/andig/htdocs/signalr/websocketconnection.go:99 +0x2b4

Previous read at 0x00c000348010 by goroutine 81:
  github.com/philippseith/signalr.(*webSocketConnection).watchDog.func3()
      /Users/andig/htdocs/signalr/websocketconnection.go:104 +0x48

Goroutine 79 (running) created at:
  github.com/philippseith/signalr.newWebSocketConnection()
      /Users/andig/htdocs/signalr/websocketconnection.go:28 +0x1dc
  github.com/philippseith/signalr.(*httpMux).handleWebsocket()
      /Users/andig/htdocs/signalr/httpmux.go:150 +0x74c
  github.com/philippseith/signalr.(*httpMux).handleGet()
      /Users/andig/htdocs/signalr/httpmux.go:75 +0x16c
  github.com/philippseith/signalr.(*httpMux).ServeHTTP()
      /Users/andig/htdocs/signalr/httpmux.go:35 +0x84
  net/http.(*ServeMux).ServeHTTP()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:2424 +0xb4
  net/http.serverHandler.ServeHTTP()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:2878 +0x7dc
  net/http.(*conn).serve()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:1929 +0x11a8

Goroutine 81 (running) created at:
  github.com/philippseith/signalr.(*webSocketConnection).watchDog()
      /Users/andig/htdocs/signalr/websocketconnection.go:101 +0x364
==================
==================
WARNING: DATA RACE
Write at 0x00c000348028 by goroutine 79:
  github.com/philippseith/signalr.(*webSocketConnection).watchDog()
      /Users/andig/htdocs/signalr/websocketconnection.go:100 +0x30c

Previous read at 0x00c000348028 by goroutine 81:
  github.com/philippseith/signalr.(*webSocketConnection).watchDog.func3()
      /Users/andig/htdocs/signalr/websocketconnection.go:103 +0x30

Goroutine 79 (running) created at:
  github.com/philippseith/signalr.newWebSocketConnection()
      /Users/andig/htdocs/signalr/websocketconnection.go:28 +0x1dc
  github.com/philippseith/signalr.(*httpMux).handleWebsocket()
      /Users/andig/htdocs/signalr/httpmux.go:150 +0x74c
  github.com/philippseith/signalr.(*httpMux).handleGet()
      /Users/andig/htdocs/signalr/httpmux.go:75 +0x16c
  github.com/philippseith/signalr.(*httpMux).ServeHTTP()
      /Users/andig/htdocs/signalr/httpmux.go:35 +0x84
  net/http.(*ServeMux).ServeHTTP()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:2424 +0xb4
  net/http.serverHandler.ServeHTTP()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:2878 +0x7dc
  net/http.(*conn).serve()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:1929 +0x11a8

Goroutine 81 (running) created at:
  github.com/philippseith/signalr.(*webSocketConnection).watchDog()
      /Users/andig/htdocs/signalr/websocketconnection.go:101 +0x364
==================
--- FAIL: TestServerSmoke (1.63s)
    server_test.go:132: Server 127.0.0.1:5001 is up
    server_test.go:93:
        PASS spec/server.spec.ts
          smoke test
            ✓ should connect on a clients request for connection and answer a simple request (101 ms)
          MessagePack smoke test
            ○ skipped should connect on a clients request for connection and answer a simple request
          JSON e2e test with microsoft/signalr client
            ○ skipped should answer a simple request
            ○ skipped should send correct ping messages
            ○ skipped should answer a simple request with multiple results
            ○ skipped should answer a request with an resulting array of structs
            ○ skipped should answer a request with an resulting map
            ○ skipped should answer a request with a large amount of compressable data
            ○ skipped should answer a request with a large amount of uncompressable data
            ○ skipped should receive a stream
            ○ skipped should upload a stream
            ○ skipped should receive subsequent sends without await
          MessagePack e2e test with microsoft/signalr client
            ○ skipped should answer a simple request
            ○ skipped should send correct ping messages
            ○ skipped should answer a simple request with multiple results
            ○ skipped should answer a request with an resulting array of structs
            ○ skipped should answer a request with an resulting map
            ○ skipped should answer a request with a large amount of compressable data
            ○ skipped should answer a request with a large amount of uncompressable data
            ○ skipped should receive a stream
            ○ skipped should upload a stream
            ○ skipped should receive subsequent sends without await

        Test Suites: 1 passed, 1 total
        Tests:       21 skipped, 1 passed, 22 total
        Snapshots:   0 total
        Time:        1.113 s, estimated 7 s
        Ran all test suites with tests matching "^smoke".

    testing.go:1152: race detected during execution of test
==================
WARNING: DATA RACE
Read at 0x00c000100690 by goroutine 76:
  github.com/philippseith/signalr.(*webSocketConnection).watchDog.func3()
      /Users/andig/htdocs/signalr/websocketconnection.go:104 +0x60

Previous write at 0x00c000100690 by goroutine 37:
  time.NewTimer()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/time/sleep.go:89 +0x78
  github.com/philippseith/signalr.(*webSocketConnection).watchDog()
      /Users/andig/htdocs/signalr/websocketconnection.go:99 +0x2a0

Goroutine 76 (running) created at:
  github.com/philippseith/signalr.(*webSocketConnection).watchDog()
      /Users/andig/htdocs/signalr/websocketconnection.go:101 +0x364

Goroutine 37 (finished) created at:
  github.com/philippseith/signalr.newWebSocketConnection()
      /Users/andig/htdocs/signalr/websocketconnection.go:28 +0x1dc
  github.com/philippseith/signalr.(*httpMux).handleWebsocket()
      /Users/andig/htdocs/signalr/httpmux.go:150 +0x74c
  github.com/philippseith/signalr.(*httpMux).handleGet()
      /Users/andig/htdocs/signalr/httpmux.go:75 +0x16c
  github.com/philippseith/signalr.(*httpMux).ServeHTTP()
      /Users/andig/htdocs/signalr/httpmux.go:35 +0x84
  net/http.(*ServeMux).ServeHTTP()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:2424 +0xb4
  net/http.serverHandler.ServeHTTP()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:2878 +0x7dc
  net/http.(*conn).serve()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:1929 +0x11a8
==================
--- FAIL: TestServerJsonWebSockets (7.05s)
    server_test.go:132: Server 127.0.0.1:5001 is up
    server_test.go:93:
        PASS spec/server.spec.ts (6.571 s)
          smoke test
            ○ skipped should connect on a clients request for connection and answer a simple request
          MessagePack smoke test
            ○ skipped should connect on a clients request for connection and answer a simple request
          JSON e2e test with microsoft/signalr client
            ✓ should answer a simple request (86 ms)
            ✓ should send correct ping messages (5014 ms)
            ✓ should answer a simple request with multiple results (23 ms)
            ✓ should answer a request with an resulting array of structs (9 ms)
            ✓ should answer a request with an resulting map (8 ms)
            ✓ should answer a request with a large amount of compressable data (11 ms)
            ✓ should answer a request with a large amount of uncompressable data (20 ms)
            ✓ should receive a stream (526 ms)
            ✓ should upload a stream (18 ms)
            ✓ should receive subsequent sends without await (9 ms)
          MessagePack e2e test with microsoft/signalr client
            ○ skipped should answer a simple request
            ○ skipped should send correct ping messages
            ○ skipped should answer a simple request with multiple results
            ○ skipped should answer a request with an resulting array of structs
            ○ skipped should answer a request with an resulting map
            ○ skipped should answer a request with a large amount of compressable data
            ○ skipped should answer a request with a large amount of uncompressable data
            ○ skipped should receive a stream
            ○ skipped should upload a stream
            ○ skipped should receive subsequent sends without await

        Test Suites: 1 passed, 1 total
        Tests:       12 skipped, 10 passed, 22 total
        Snapshots:   0 total
        Time:        6.606 s
        Ran all test suites with tests matching "^JSON".

    testing.go:1152: race detected during execution of test
==================
WARNING: DATA RACE
Read at 0x00c0000209e8 by goroutine 121:
  bufio.(*Writer).Available()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/bufio/bufio.go:624 +0xa0
  bufio.(*Writer).WriteString()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/bufio/bufio.go:706 +0x28
  net/http.(*chunkWriter).close()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:407 +0xd4
  net/http.(*response).finishRequest()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:1607 +0xbc
  net/http.(*conn).serve()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:1934 +0x11e8

Previous write at 0x00c0000209e8 by goroutine 117:
  bufio.(*Writer).Flush()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/bufio/bufio.go:619 +0x310
  net/http.(*chunkWriter).flush()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:397 +0xa4
  net/http.(*response).Flush()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:1659 +0x84
  github.com/philippseith/signalr.(*serverSSEConnection).Write()
      /Users/andig/htdocs/signalr/serversseconnection.go:89 +0x2cc
  github.com/philippseith/signalr.(*jsonHubProtocol).WriteMessage()
      /Users/andig/htdocs/signalr/jsonhubprotocol.go:212 +0x2f4
  github.com/philippseith/signalr.(*defaultHubConnection).writeMessage.func1.1()
      /Users/andig/htdocs/signalr/hubconnection.go:228 +0xb4

Goroutine 121 (running) created at:
  net/http.(*Server).Serve()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:3033 +0x6c0
  net/http.(*Server).ListenAndServe()
      /opt/homebrew/Cellar/go/1.17.2/libexec/src/net/http/server.go:2930 +0xe4
  github.com/philippseith/signalr/signalr_test_test.runServer()
      /Users/andig/htdocs/signalr/signalr_test/server_test.go:135 +0x500
  github.com/philippseith/signalr/signalr_test_test.testServer.func1()
      /Users/andig/htdocs/signalr/signalr_test/server_test.go:64 +0x48

Goroutine 117 (finished) created at:
  github.com/philippseith/signalr.(*defaultHubConnection).writeMessage.func1()
      /Users/andig/htdocs/signalr/hubconnection.go:228 +0x190
  github.com/philippseith/signalr.(*defaultHubConnection).writeMessage()
      /Users/andig/htdocs/signalr/hubconnection.go:238 +0xd4
  github.com/philippseith/signalr.(*defaultHubConnection).Completion()
      /Users/andig/htdocs/signalr/hubconnection.go:203 +0xbc
  github.com/philippseith/signalr.completion()
      /Users/andig/htdocs/signalr/loop.go:309 +0x84
  github.com/philippseith/signalr.(*loop).sendResult()
      /Users/andig/htdocs/signalr/loop.go:300 +0xdc
  github.com/philippseith/signalr.(*loop).returnInvocationResult()
      /Users/andig/htdocs/signalr/loop.go:239 +0x2c0
  github.com/philippseith/signalr.(*loop).handleInvocationMessage.func2()
      /Users/andig/htdocs/signalr/loop.go:208 +0xfc
==================
--- FAIL: TestServerJsonSSE (7.97s)
    server_test.go:132: Server 127.0.0.1:5001 is up
    server_test.go:93:
        PASS spec/server.spec.ts (7.456 s)
          smoke test
            ○ skipped should connect on a clients request for connection and answer a simple request
          MessagePack smoke test
            ○ skipped should connect on a clients request for connection and answer a simple request
          JSON e2e test with microsoft/signalr client
            ✓ should answer a simple request (143 ms)
            ✓ should send correct ping messages (5070 ms)
            ✓ should answer a simple request with multiple results (83 ms)
            ✓ should answer a request with an resulting array of structs (77 ms)
            ✓ should answer a request with an resulting map (75 ms)
            ✓ should answer a request with a large amount of compressable data (93 ms)
            ✓ should answer a request with a large amount of uncompressable data (77 ms)
            ✓ should receive a stream (574 ms)
            ✓ should upload a stream (303 ms)
            ✓ should receive subsequent sends without await (78 ms)
          MessagePack e2e test with microsoft/signalr client
            ○ skipped should answer a simple request
            ○ skipped should send correct ping messages
            ○ skipped should answer a simple request with multiple results
            ○ skipped should answer a request with an resulting array of structs
            ○ skipped should answer a request with an resulting map
            ○ skipped should answer a request with a large amount of compressable data
            ○ skipped should answer a request with a large amount of uncompressable data
            ○ skipped should receive a stream
            ○ skipped should upload a stream
            ○ skipped should receive subsequent sends without await

        Test Suites: 1 passed, 1 total
        Tests:       12 skipped, 10 passed, 22 total
        Snapshots:   0 total
        Time:        7.501 s
        Ran all test suites with tests matching "^JSON".

    testing.go:1152: race detected during execution of test
FAIL
FAIL    github.com/philippseith/signalr/signalr_test    26.216s
FAIL
philippseith commented 2 years ago

That's not the only races though. The entire test suite is racy: I know, but didn't have the time to fix it. The raciness sometimes causes flaky tests, but for the most time the tests work as expected. So I didn't take any actions yet.

andig commented 2 years ago

The problem ist not flaky tests but undefined runtime behaviour. If the code is racy anything might happen really.

philippseith commented 2 years ago

Don't get me wrong. I was talking about the races in the test code, not in the tested code.

andig commented 2 years ago

Ah, sorry. I think the logs above are real races in the server/client though. I would like to help but the code is a bit opaque for me.

philippseith commented 2 years ago

Some are real, some are test races. Real races:

Testcode races:

One special case is the sseServerConnection. Write currently is inevitably called on a different goroutine as the one the http request comes in. handleSSEConnection stays in h.serveConnection(sseConn) and the writing and flushing is done directly in the server loop. sseServerConnection needs to be rewritten that it sends write/flush jobs in a channel back to handleSSEConnection which polls for jobs and executes them.

andig commented 2 years ago

There are some more things that you probably wouldn't want to do even if they might work:

// Broadcast when loop is connected
isLoopConnected := make(chan struct{}, 1)
go func() {
    <-isLoopConnected
    close(isLoopConnected)
    c.setState(ClientConnected)
}()
// Run the loop
err = loop.Run(isLoopConnected)

Here the channel is closed on the receiving side. Best practice imho is to always close on sending side.

philippseith commented 2 years ago

added it to #93

philippseith commented 2 years ago

One special case is the sseServerConnection. Write currently is inevitably called on a different goroutine as the one the http request comes in. handleSSEConnection stays in h.serveConnection(sseConn) and the writing and flushing is done directly in the server loop. sseServerConnection needs to be rewritten that it sends write/flush jobs in a channel back to handleSSEConnection which polls for jobs and executes them.

See #95