search

ipfs / go-bitswap

The golang implementation of the bitswap protocol
MIT License
216 stars 112 forks source link

Potential race condition detected #527

Closed whyrusleeping closed 3 years ago

whyrusleeping commented 3 years ago

Ive been running estuary with the race checker on for the past day or so, and it turned up something in bitswap:

==================
WARNING: DATA RACE
Write at 0x00c03b434778 by goroutine 97930172:
  github.com/ipfs/go-bitswap/network.(*connectEventManager).MarkUnresponsive()
      /home/estuary/go/pkg/mod/github.com/ipfs/go-bitswap@v0.4.0/network/connecteventmanager.go:75 +0x164
  github.com/ipfs/go-bitswap/network.(*streamMessageSender).multiAttempt()
      /home/estuary/go/pkg/mod/github.com/ipfs/go-bitswap@v0.4.0/network/ipfs_impl.go:184 +0x4b4
  github.com/ipfs/go-bitswap/network.(*streamMessageSender).SendMsg()
      /home/estuary/go/pkg/mod/github.com/ipfs/go-bitswap@v0.4.0/network/ipfs_impl.go:149 +0xab
  github.com/ipfs/go-bitswap/internal/messagequeue.(*MessageQueue).sendMessage()
      /home/estuary/go/pkg/mod/github.com/ipfs/go-bitswap@v0.4.0/internal/messagequeue/messagequeue.go:540 +0x363
  github.com/ipfs/go-bitswap/internal/messagequeue.(*MessageQueue).sendIfReady()
      /home/estuary/go/pkg/mod/github.com/ipfs/go-bitswap@v0.4.0/internal/messagequeue/messagequeue.go:509 +0x3d
  github.com/ipfs/go-bitswap/internal/messagequeue.(*MessageQueue).runQueue()
      /home/estuary/go/pkg/mod/github.com/ipfs/go-bitswap@v0.4.0/internal/messagequeue/messagequeue.go:444 +0x530
  github.com/ipfs/go-bitswap/internal/messagequeue.(*MessageQueue).Startup·dwrap·12()
      /home/estuary/go/pkg/mod/github.com/ipfs/go-bitswap@v0.4.0/internal/messagequeue/messagequeue.go:393 +0x39

Previous read at 0x00c03b434778 by goroutine 98219079:
  github.com/ipfs/go-bitswap/network.(*connectEventManager).OnMessage()
      /home/estuary/go/pkg/mod/github.com/ipfs/go-bitswap@v0.4.0/network/connecteventmanager.go:88 +0xed
  github.com/ipfs/go-bitswap/network.(*impl).handleNewStream()
      /home/estuary/go/pkg/mod/github.com/ipfs/go-bitswap@v0.4.0/network/ipfs_impl.go:421 +0x529
  github.com/ipfs/go-bitswap/network.(*impl).handleNewStream-fm()
      /home/estuary/go/pkg/mod/github.com/ipfs/go-bitswap@v0.4.0/network/ipfs_impl.go:398 +0x4d
  github.com/libp2p/go-libp2p/p2p/host/basic.(*BasicHost).SetStreamHandler.func1()
      /home/estuary/go/pkg/mod/github.com/libp2p/go-libp2p@v0.14.3/p2p/host/basic/basic_host.go:574 +0x86
  github.com/libp2p/go-libp2p/p2p/host/basic.(*BasicHost).newStreamHandler·dwrap·3()
      /home/estuary/go/pkg/mod/github.com/libp2p/go-libp2p@v0.14.3/p2p/host/basic/basic_host.go:421 +0x74

Goroutine 97930172 (running) created at:
  github.com/ipfs/go-bitswap/internal/messagequeue.(*MessageQueue).Startup()
      /home/estuary/go/pkg/mod/github.com/ipfs/go-bitswap@v0.4.0/internal/messagequeue/messagequeue.go:393 +0x144
  github.com/ipfs/go-bitswap/internal/peermanager.(*PeerManager).getOrCreate()
      /home/estuary/go/pkg/mod/github.com/ipfs/go-bitswap@v0.4.0/internal/peermanager/peermanager.go:193 +0x101
  github.com/ipfs/go-bitswap/internal/peermanager.(*PeerManager).Connected()
      /home/estuary/go/pkg/mod/github.com/ipfs/go-bitswap@v0.4.0/internal/peermanager/peermanager.go:91 +0xc9
  github.com/ipfs/go-bitswap.(*Bitswap).PeerConnected()
      /home/estuary/go/pkg/mod/github.com/ipfs/go-bitswap@v0.4.0/bitswap.go:611 +0x4f
  github.com/ipfs/go-bitswap/network.(*connectEventManager).Connected()
      /home/estuary/go/pkg/mod/github.com/ipfs/go-bitswap@v0.4.0/network/connecteventmanager.go:44 +0x276
  github.com/ipfs/go-bitswap/network.(*netNotifiee).Connected()
      /home/estuary/go/pkg/mod/github.com/ipfs/go-bitswap@v0.4.0/network/ipfs_impl.go:450 +0x10d
  github.com/libp2p/go-libp2p-swarm.(*Swarm).addConn.func1()
      /home/estuary/go/pkg/mod/github.com/libp2p/go-libp2p-swarm@v0.5.3/swarm.go:275 +0x64
  github.com/libp2p/go-libp2p-swarm.(*Swarm).notifyAll.func1()
      /home/estuary/go/pkg/mod/github.com/libp2p/go-libp2p-swarm@v0.5.3/swarm.go:549 +0xaa
  github.com/libp2p/go-libp2p-swarm.(*Swarm).notifyAll·dwrap·19()
      /home/estuary/go/pkg/mod/github.com/libp2p/go-libp2p-swarm@v0.5.3/swarm.go:550 +0x58

Goroutine 98219079 (running) created at:
  github.com/libp2p/go-libp2p/p2p/host/basic.(*BasicHost).newStreamHandler()
      /home/estuary/go/pkg/mod/github.com/libp2p/go-libp2p@v0.14.3/p2p/host/basic/basic_host.go:421 +0x7ca
  github.com/libp2p/go-libp2p/p2p/host/basic.(*BasicHost).newStreamHandler-fm()
      /home/estuary/go/pkg/mod/github.com/libp2p/go-libp2p@v0.14.3/p2p/host/basic/basic_host.go:378 +0x4d
  github.com/libp2p/go-libp2p-swarm.(*Conn).start.func1.1()
      /home/estuary/go/pkg/mod/github.com/libp2p/go-libp2p-swarm@v0.5.3/swarm_conn.go:125 +0xe4
==================

cc @mvdan who helped me set up the 'unlimited goroutine race checker'

aschmahmann commented 3 years ago

The problem here is that https://github.com/ipfs/go-bitswap/blob/2b51297a0b68198b6c4bcacdd8868a6df8dcd182/network/connecteventmanager.go#L85 copies out the connection state under a read lock as a pointer.

We should either do the check under the read lock, or do what was probably intended which is to copy out the state instead of a pointer to the state.

Stebalien commented 3 years ago

Fix in #528. Interestingly, this isn't getting covered by tests:

https://codecov.io/gh/ipfs/go-bitswap/src/6dce2a1000638a707fb65e0ba5f2c9009580f9b8/network/connecteventmanager.go#L100

Are we not receiving any messages after receiving the connect notification?