Repository: ipfs/boxo

Issue:
Bitswap peer connection race
Experienced via Lassie's CI suite which has suddenly become flaky with some new workloads. Using the [testing/sws-logging](https://github.com/ipfs/boxo/tree/testing/sws-logging) branch here (started by @hannahhoward, continued by me) to diagnose with additional debug printing. It evidences in an inability to communicate with a peer that we know has the block, and bitswap has been told has the block.

See logs below, which come from [here](https://github.com/filecoin-project/lassie/actions/runs/5865827197/job/15903479085?pr=371) using 715365a23d36ccd0fe2c9cf95ec16afa0d50f39b on the [testing/sws-logging](https://github.com/ipfs/boxo/tree/testing/sws-logging) branch. Here's what I believe happens:

* `session#findMorePeers` -> `ProviderQueryManager#FindProvidersAsync`
* `ProviderQueryManager#findProviderWorker` does its thing, processing the queue of providers to connect to, performs a `pqm.network.ConnectTo()` which is goes through (bitswap/network/ipfs_impl.go) `bsnet#ConnectTo()` to just do a basic `host.Connect()`
* We get a `Connected()` notification which is received by (bitswap/network/ipfs_impl.go) `connectEventManager#Connected()` and it does a `c.setState(p, stateResponsive)` on that peer.
* Meanwhile, the `ProviderQueryManager#FindProvidersAsync` has returned, the `Connect()` returned, we even got a `Connected()`, so the `Session` invokes `sessionWantSender#Update(peer, nil, have, nil)`, i.e. the `peer` has the cid `have`, this is a "change".
* In `sessionWantSender` we go from `onChange()` to `processUpdates()` to `updateWantBlockPresence()` to `wantInfo#setPeerBlockPresence()` to `wantInfo#calculateBestPeer()` - we see these in the logs
* After the call to `processUpdates()`, `sessionWantSender` moves on to `sendNextWants()`, which compiles them and calls `sendWants()` which in turn calls `PeerManager#SendWants()`.
* **BUT** it turns out that `PeerManager` doesn't have a `peerQueues` entry for this peer .. yet ..
* Back in `connectEventManager`, the `worker()` (goroutine) loop finally picks up a change, and sees that `p` is now `stateResponsive` so it ends up calling `Bitswap#PeerConnected()` which calls `Client#PeerConnected()` which calls `PeerManager#Connected()` which calls `PeerManager#getOrCreate()` that finally sets up a `peerQueues` entry for that peer; so it's now ready to talk (_"hey, what'd I miss?"_).

I'm a bit fuzzy on what the logs show beyond here and why it doesn't manage to rectify the situation with retries; I guess because it had one chance to take the peer from `FindProvidersAsync` and ask it for the block, and it failed that one chance and there isn't really another.

The async disconnect in `connectEventManager` seems to be the main problem here, perhaps a call to `Connected()` shouldn't return until the state change has been fully propagated.

<details>
<summary>Relevant logs</summary>

```
2023-08-15T09:52:43.126Z	DEBUG	bs:sess	session/session.go:361	FindMorePeers	{"session": 1, "cid": "bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq", "pending": 1}
2023-08-15T09:52:43.126Z	DEBUG	bitswap	providerquerymanager/providerquerymanager.go:332	New Provider Query on cid: bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq
2023-08-15T09:52:43.126Z	DEBUG	bitswap	providerquerymanager/providerquerymanager.go:234	Beginning Find Provider Request for cid: bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq
2023-08-15T09:52:43.126Z	DEBUG	lassie/bitswap	bitswaphelpers/indexerrouting.go:86	provider records requested from bitswap, sending back indexer results	{"providerCount": 1}
2023-08-15T09:52:43.126Z	DEBUG	bitswap	providerquerymanager/providerquerymanager.go:244	Connecting to provider 1WRsHVY1dhNKpD...
2023-08-15T09:52:43.126Z	DEBUG	basichost	basic/basic_host.go:737	host QmRR8VvuQf4Fvr2ptGJj2qjJkmqREJXbF4jv8KkSRLsMj1 dialing 1WRsHVY1dhNKpD
2023-08-15T09:52:43.126Z	DEBUG	mocknet	mock/mock_peernet.go:119	QmRR8VvuQf4Fvr2ptGJj2qjJkmqREJXbF4jv8KkSRLsMj1 (newly) dialing 1WRsHVY1dhNKpD
2023-08-15T09:52:43.126Z	DEBUG	mocknet	mock/mock_peernet.go:132	QmRR8VvuQf4Fvr2ptGJj2qjJkmqREJXbF4jv8KkSRLsMj1 dialing 1WRsHVY1dhNKpD openingConn
2023-08-15T09:52:43.126Z	DEBUG	mocknet	mock/mock_peernet.go:140	QmRR8VvuQf4Fvr2ptGJj2qjJkmqREJXbF4jv8KkSRLsMj1 opening connection to 1WRsHVY1dhNKpD
2023-08-15T09:52:43.126Z	DEBUG	mocknet	mock/mock_peernet.go:183	1WRsHVY1dhNKpD accepting connection from QmRR8VvuQf4Fvr2ptGJj2qjJkmqREJXbF4jv8KkSRLsMj1
2023-08-15T09:52:43.126Z	DEBUG	bitswap_network	network/connecteventmanager.go:159	connectEventManager connected to peer, setting responsive	{"peer": "QmRR8VvuQf4Fvr2ptGJj2qjJkmqREJXbF4jv8KkSRLsMj1"}
2023-08-15T09:52:43.126Z	DEBUG	bitswap_network	network/connecteventmanager.go:140	connectEventManager detected peer connectivity	{"peer": "QmRR8VvuQf4Fvr2ptGJj2qjJkmqREJXbF4jv8KkSRLsMj1"}
2023-08-15T09:52:43.126Z	DEBUG	mocknet	mock/mock_conn.go:148	Conn.NewStreamWithProtocol: QmRR8VvuQf4Fvr2ptGJj2qjJkmqREJXbF4jv8KkSRLsMj1 --> 1WRsHVY1dhNKpD
2023-08-15T09:52:43.126Z	DEBUG	bitswap_network	network/connecteventmanager.go:159	connectEventManager connected to peer, setting responsive	{"peer": "1WRsHVY1dhNKpD"}
2023-08-15T09:52:43.126Z	DEBUG	mocknet	mock/mock_conn.go:148	Conn.NewStreamWithProtocol: 1WRsHVY1dhNKpD --> QmRR8VvuQf4Fvr2ptGJj2qjJkmqREJXbF4jv8KkSRLsMj1
2023-08-15T09:52:43.127Z	DEBUG	basichost	basic/basic_host.go:433	negotiated: /ipfs/id/1.0.0 (took 25.701µs)
2023-08-15T09:52:43.127Z	DEBUG	net/identify	identify/id.go:463	sending snapshot	{"seq": 2, "protocols": ["/fil/datatransfer/1.2.0","/ipfs/bitswap","/ipfs/bitswap/1.0.0","/ipfs/bitswap/1.1.0","/ipfs/bitswap/1.2.0","/ipfs/graphsync/2.0.0","/ipfs/id/1.0.0","/ipfs/id/push/1.0.0"], "addrs": ["/ip6/100::2438:fce9:9d50:c714/tcp/4242"]}
2023-08-15T09:52:43.127Z	DEBUG	net/identify	identify/id.go:468	/ipfs/id/1.0.0 sending message to 1WRsHVY1dhNKpD /ip4/127.0.0.1/tcp/15381
2023-08-15T09:52:43.127Z	DEBUG	net/identify	identify/id.go:519	/ipfs/id/1.0.0 received message from QmRR8VvuQf4Fvr2ptGJj2qjJkmqREJXbF4jv8KkSRLsMj1 /ip6/100::2438:fce9:9d50:c714/tcp/4242
2023-08-15T09:52:43.127Z	DEBUG	net/identify	identify/id.go:787	1WRsHVY1dhNKpD received listen addrs for QmRR8VvuQf4Fvr2ptGJj2qjJkmqREJXbF4jv8KkSRLsMj1: [/ip6/100::2438:fce9:9d50:c714/tcp/4242]
2023-08-15T09:52:43.127Z	DEBUG	basichost	basic/basic_host.go:433	negotiated: /ipfs/id/1.0.0 (took 398.503µs)
2023-08-15T09:52:43.127Z	DEBUG	net/identify	identify/id.go:463	sending snapshot	{"seq": 2, "protocols": ["/ipfs/bitswap","/ipfs/bitswap/1.0.0","/ipfs/bitswap/1.1.0","/ipfs/bitswap/1.2.0","/ipfs/id/1.0.0","/ipfs/id/push/1.0.0"], "addrs": ["/ip4/127.0.0.1/tcp/15381"]}
2023-08-15T09:52:43.127Z	DEBUG	net/identify	identify/id.go:468	/ipfs/id/1.0.0 sending message to QmRR8VvuQf4Fvr2ptGJj2qjJkmqREJXbF4jv8KkSRLsMj1 /ip6/100::2438:fce9:9d50:c714/tcp/4242
2023-08-15T09:52:43.127Z	DEBUG	net/identify	identify/id.go:519	/ipfs/id/1.0.0 received message from 1WRsHVY1dhNKpD /ip4/127.0.0.1/tcp/15381
2023-08-15T09:52:43.127Z	DEBUG	net/identify	identify/id.go:787	QmRR8VvuQf4Fvr2ptGJj2qjJkmqREJXbF4jv8KkSRLsMj1 received listen addrs for 1WRsHVY1dhNKpD: [/ip4/127.0.0.1/tcp/15381]
2023-08-15T09:52:43.127Z	WARN	net/identify	identify/id.go:811	QmRR8VvuQf4Fvr2ptGJj2qjJkmqREJXbF4jv8KkSRLsMj1 cannot unmarshal key from remote peer: 1WRsHVY1dhNKpD, asn1: structure error: tags don't match (16 vs {class:3 tag:27 length:52 isCompound:false}) {optional:false explicit:false application:false private:false defaultValue:<nil> tag:<nil> stringType:0 timeType:0 set:false omitEmpty:false} publicKeyInfo @2
2023-08-15T09:52:43.127Z	DEBUG	basichost	basic/basic_host.go:754	host QmRR8VvuQf4Fvr2ptGJj2qjJkmqREJXbF4jv8KkSRLsMj1 finished dialing 1WRsHVY1dhNKpD
2023-08-15T09:52:43.127Z	DEBUG	bitswap	providerquerymanager/providerquerymanager.go:250	Connected to provider 1WRsHVY1dhNKpD
2023-08-15T09:52:43.127Z	DEBUG	bitswap	providerquerymanager/providerquerymanager.go:264	Found 0 providers for cid: bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq
2023-08-15T09:52:43.127Z	DEBUG	net/identify	identify/obsaddr.go:442	added own observed listen addr	{"observed": "/ip6/100::2438:fce9:9d50:c714/tcp/4242"}
2023-08-15T09:52:43.127Z	DEBUG	bitswap	providerquerymanager/providerquerymanager.go:332	Received provider (1WRsHVY1dhNKpD) for cid (bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq)
2023-08-15T09:52:43.127Z	DEBUG	bitswap	providerquerymanager/providerquerymanager.go:332	Finished Provider Query on cid: bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq
2023-08-15T09:52:43.127Z	DEBUG	bs:peermgr	peermanager/peermanager.go:214	pm RegisterSession	{"peer": "1WRsHVY1dhNKpD", "session": 1}
2023-08-15T09:52:43.127Z	DEBUG	bs:sprmgr	sessionpeermanager/sessionpeermanager.go:68	Bitswap: Added peer to session	{"session": 1, "peer": "1WRsHVY1dhNKpD", "peerCount": 1}
2023-08-15T09:52:43.127Z	DEBUG	bs:sess	session/sessionwantsender.go:[65](https://github.com/filecoin-project/lassie/actions/runs/5865827197/job/15903479085?pr=371#step:63:67)7	sws update want block presence	{"cid": "bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq", "peerID": "1WRsHVY1dhNKpD"}
2023-08-15T09:52:43.127Z	DEBUG	bs:sess	session/sessionwantsender.go:764	sws new best peer	{"peerID": "1WRsHVY1dhNKpD"}
2023-08-15T09:52:43.127Z	DEBUG	bs:sess	session/sessionwantsender.go:657	sws update want block presence	{"cid": "bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq", "peerID": "1WRsHVY1dhNKpD"}
2023-08-15T09:52:43.127Z	DEBUG	bs:sess	session/sessionwantsender.go:764	sws new best peer	{"peerID": "1WRsHVY1dhNKpD"}
2023-08-15T09:52:43.127Z	DEBUG	bs:sess	session/sessionwantsender.go:535	sws send next wants	{"newly available": ["1WRsHVY1dhNKpD"]}
2023-08-15T09:52:43.127Z	DEBUG	bs:sess	session/sessionwantsender.go:558	sws send new want block	{"cid": "bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq", "peerID": "1WRsHVY1dhNKpD"}
2023-08-15T09:52:43.127Z	DEBUG	bs:sess	session/sessionwantsender.go:580	sws sending wants	{"sends": 1}
2023-08-15T09:52:43.127Z	DEBUG	bs:peermgr	peermanager/peermanager.go:155	pm SendWants	{"peer": "1WRsHVY1dhNKpD", "wantBlocks": 1, "wantHaves": 1}
2023-08-15T09:52:43.127Z	DEBUG	bs:peermgr	peermanager/peermanager.go:159	pm SendWants no peerQueue for	{"peer": "1WRsHVY1dhNKpD"}
2023-08-15T09:52:43.127Z	DEBUG	bitswap_network	network/connecteventmanager.go:140	connectEventManager detected peer connectivity	{"peer": "1WRsHVY1dhNKpD"}
2023-08-15T09:52:43.127Z	DEBUG	bs:peermgr	peermanager/peermanager.go:91	pm Connected	{"peer": "1WRsHVY1dhNKpD"}
2023-08-15T09:52:43.127Z	DEBUG	bs:peermgr	peermanager/peermanager.go:203	pm getOrCreate new peer	{"peer": "1WRsHVY1dhNKpD"}
2023-08-15T09:52:43.127Z	DEBUG	bitswap	messagequeue/messagequeue.go:280	mq: add want have from broadcast	{"cid": "bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq", "peerID": "1WRsHVY1dhNKpD"}
2023-08-15T09:52:43.127Z	DEBUG	bs:sess	session/sessionwantsender.go:535	sws send next wants	{"newly available": null}
2023-08-15T09:52:43.127Z	DEBUG	bs:sess	session/sessionwantsender.go:546	sws want block in process, no new want block sent	{"cid": "bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}
2023-08-15T09:52:43.127Z	DEBUG	bs:sess	session/sessionwantsender.go:580	sws sending wants	{"sends": 0}
2023-08-15T09:52:43.129Z	DEBUG	mocknet	mock/mock_conn.go:148	Conn.NewStreamWithProtocol: QmRR8VvuQf4Fvr2ptGJj2qjJkmqREJXbF4jv8KkSRLsMj1 --> 1WRsHVY1dhNKpD
2023-08-15T09:52:43.129Z	DEBUG	bitswap	messagequeue/messagequeue.go:[66](https://github.com/filecoin-project/lassie/actions/runs/5865827197/job/15903479085?pr=371#step:63:68)6	sent message	{"type": "WANT_HAVE", "cid": "bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq", "local": "QmRR8VvuQf4Fvr2ptGJj2qjJkmqREJXbF4jv8KkSRLsMj1", "to": "1WRsHVY1dhNKpD"}
2023-08-15T09:52:43.129Z	WARN	bitswap_network	network/ipfs_impl.go:245	error setting deadline: set pipe: deadline not supported
2023-08-15T09:52:43.130Z	DEBUG	mocknet	mock/mock_conn.go:148	Conn.NewStreamWithProtocol: QmRR8VvuQf4Fvr2ptGJj2qjJkmqREJXbF4jv8KkSRLsMj1 --> 1WRsHVY1dhNKpD
2023-08-15T09:52:43.130Z	WARN	bitswap_network	network/ipfs_impl.go:269	error resetting deadline: set pipe: deadline not supported
2023-08-15T09:52:43.130Z	DEBUG	bs:sess	session/session.go:4[67](https://github.com/filecoin-project/lassie/actions/runs/5865827197/job/15903479085?pr=371#step:63:69)	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T09:52:43.130Z	DEBUG	basichost	basic/basic_host.go:433	negotiated: /ipfs/bitswap/1.2.0 (took 800.106µs)
2023-08-15T09:52:43.131Z	DEBUG	bitswap_network	network/ipfs_impl.go:427	bitswap net handleNewStream from QmRR8VvuQf4Fvr2ptGJj2qjJkmqREJXbF4jv8KkSRLsMj1
2023-08-15T09:52:43.131Z	DEBUG	engine	decision/engine.go:634	Bitswap engine <- msg	{"local": "1WRsHVY1dhNKpD", "from": "QmRR8VvuQf4Fvr2ptGJj2qjJkmqREJXbF4jv8KkSRLsMj1", "entryCount": 1}
2023-08-15T09:52:43.131Z	DEBUG	engine	decision/engine.go:638	Bitswap engine <- want-have	{"local": "1WRsHVY1dhNKpD", "from": "QmRR8VvuQf4Fvr2ptGJj2qjJkmqREJXbF4jv8KkSRLsMj1", "cid": "bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}
LinkSystemBlockstore.GetSize bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq
LinkSystemBlockstore.GetSize= bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq 1332
2023-08-15T09:52:43.132Z	DEBUG	engine	decision/engine.go:779	Bitswap engine: block found	{"local": "1WRsHVY1dhNKpD", "from": "QmRR8VvuQf4Fvr2ptGJj2qjJkmqREJXbF4jv8KkSRLsMj1", "cid": "bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq", "isWantBlock": false}
2023-08-15T09:52:43.132Z	DEBUG	engine	decision/engine.go:545	Bitswap process tasks	{"local": "1WRsHVY1dhNKpD", "taskCount": 1}
2023-08-15T09:52:43.132Z	DEBUG	engine	decision/engine.go:598	Bitswap engine -> msg	{"local": "1WRsHVY1dhNKpD", "to": "QmRR8VvuQf4Fvr2ptGJj2qjJkmqREJXbF4jv8KkSRLsMj1", "blockCount": 0, "presenceCount": 1, "size": 38}
2023-08-15T09:52:43.133Z	DEBUG	mocknet	mock/mock_conn.go:148	Conn.NewStreamWithProtocol: 1WRsHVY1dhNKpD --> QmRR8VvuQf4Fvr2ptGJj2qjJkmqREJXbF4jv8KkSRLsMj1
2023-08-15T09:52:43.133Z	WARN	bitswap_network	network/ipfs_impl.go:245	error setting deadline: set pipe: deadline not supported
2023-08-15T09:52:43.133Z	DEBUG	basichost	basic/basic_host.go:413	protocol mux failed: stream reset (took 2.485821ms)
2023-08-15T09:52:43.133Z	WARN	bitswap_network	network/ipfs_impl.go:2[69](https://github.com/filecoin-project/lassie/actions/runs/5865827197/job/15903479085?pr=371#step:63:71)	error resetting deadline: set pipe: deadline not supported
2023-08-15T09:52:43.133Z	DEBUG	basichost	basic/basic_host.go:433	negotiated: /ipfs/bitswap/1.2.0 (took 321.[70](https://github.com/filecoin-project/lassie/actions/runs/5865827197/job/15903479085?pr=371#step:63:72)3µs)
2023-08-15T09:52:43.134Z	DEBUG	bitswap_network	network/ipfs_impl.go:427	bitswap net handleNewStream from 1WRsHVY1dhNKpD
2023-08-15T09:52:43.134Z	DEBUG	bs:sess	session/session.go:221	Bitswap <- HAVE	{"local": "QmRR8VvuQf4Fvr2ptGJj2qjJkmqREJXbF4jv8KkSRLsMj1", "from": "1WRsHVY1dhNKpD", "cid": "bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq", "session": 1}
2023-08-15T09:52:43.134Z	DEBUG	bs:peermgr	peermanager/peermanager.go:214	pm RegisterSession	{"peer": "1WRsHVY1dhNKpD", "session": 1}
2023-08-15T09:52:43.134Z	DEBUG	bs:sess	session/sessionwantsender.go:657	sws update want block presence	{"cid": "bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq", "peerID": "1WRsHVY1dhNKpD"}
2023-08-15T09:52:43.134Z	DEBUG	bs:sess	session/sessionwantsender.go:[76](https://github.com/filecoin-project/lassie/actions/runs/5865827197/job/15903479085?pr=371#step:63:78)4	sws new best peer	{"peerID": "1WRsHVY1dhNKpD"}
2023-08-15T09:52:43.134Z	DEBUG	bs:sess	session/sessionwantsender.go:535	sws send next wants	{"newly available": null}
2023-08-15T09:52:43.134Z	DEBUG	bs:sess	session/sessionwantsender.go:546	sws want block in process, no new want block sent	{"cid": "bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}
2023-08-15T09:52:43.134Z	DEBUG	bs:sess	session/sessionwantsender.go:580	sws sending wants	{"sends": 0}
2023-08-15T09:52:43.134Z	DEBUG	bitswap-server	server/server.go:325	sent message	{"type": "HAVE", "cid": "bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq", "local": "1WRsHVY1dhNKpD", "to": "QmRR8VvuQf4Fvr2ptGJj2qjJkmqREJXbF4jv8KkSRLsMj1"}
2023-08-15T09:52:43.135Z	DEBUG	bitswap-server	server/server.go:3[79](https://github.com/filecoin-project/lassie/actions/runs/5865827197/job/15903479085?pr=371#step:63:81)	sent message	{"peer": "QmRR8VvuQf4Fvr2ptGJj2qjJkmqREJXbF4jv8KkSRLsMj1"}
2023-08-15T09:52:43.135Z	DEBUG	bitswap-server	server/server.go:2[82](https://github.com/filecoin-project/lassie/actions/runs/5865827197/job/15903479085?pr=371#step:63:84)	Bitswap.TaskWorker.Loop	{"ID": 0}
2023-08-15T09:52:43.[139](https://github.com/filecoin-project/lassie/actions/runs/5865827197/job/15903479085?pr=371#step:63:141)Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T09:52:43.151Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
```
</details>

Discussion:
@Jorropo: Thx a lot this is pretty clear, while working on #423 I was looking at changing this part of the code (backpressure free prefix-sum-like state versioning that would more aggressively use the `Full` flag on messages to resynchronize the server if the client's stream sender got behind). It sounds like the fix you propose would be pretty light, right ? If it is I think we should implement that so it could be landed faster.@hannahhoward: @Jorropo I would also suggest:
PeerManager.SendWants silently fails if you don't have a peer connection - https://github.com/ipfs/boxo/blob/main/bitswap/client/internal/peermanager/peermanager.go#L150
-- as in it does nothing and lets those wants/blocks get lost, but doesn't tell the caller that happened.

This seems like not the best behavior -- it should probably return an error to the caller to give the caller the opportunity to retry.@Jorropo: This was reverted https://github.com/ipfs/boxo/pull/444@BigLep: Per FIL Slack (https://filecoinproject.slack.com/archives/C03FFEVK30F/p1692628181061129?thread_ts=1692232716.286059&cid=C03FFEVK30F ), Kubo/Boxo maintainers will discuss/estimate next steps during 2023-08-22 standup and respond here by EOD 2023-08-22 as we understand this is important to fix for getting range requests landed for Rhea in Lassie.@BigLep: 2023-08-22 maintainer conversation:

General notes:
1. We need to rethink some of the Bitswap session code (which sessions assumes findProvs is useful)
2. Lassie is running into this bug because have disabled various aspects of the bitswap codebase (e.g., broadcasts).
3. It's a performance bug for Kubo but a showstopper for Lassie.
4. This is something we want to do, the only concern is how long it would take.  
5. If we do some of this rewrite now, will it be useful for further rewrites?  (Is this throwaway work that only helps one team?)

Next steps for @Jorropo for moving this forward:
1. Identify how should solve this
2. Estimate how long this fix would take
3. Identify how "throwaway" this work is (i.e., is it on the path of improvements to this code area we believe we should do anyways)
4. Make a decision on if/when will complete this
 
Before getting to this though @Jorropo is tied up with:
1. Go 1.20 update with @hacdias 
2. Getting Bitswap tests to reenabled and reliably passing: https://github.com/ipfs/boxo/issues/327 .   We can't be doing refactor above with flakiness persisting.  For example, it may have helped catch problems with https://github.com/ipfs/boxo/pull/435 before we merged it.

@Jorropo doesn't expect he will have https://github.com/ipfs/boxo/issues/327 completed until the end of the week, which means the estimate/decision/date won't come until week of 2023-08-28.  Per [slack message](https://filecoinproject.slack.com/archives/C03FFEVK30F/p1692657223590239?thread_ts=1692232716.286059&cid=C03FFEVK30F), Bedrock is unblocked for the short term.@BigLep: The previous maintainer conversation comment was updated to fill in more details and be clear that further work here won't get picked up until week of 2023-08-28.@hannahhoward: > Lassie is running into this bug because have disabled various aspects of the bitswap codebase (e.g., broadcasts).

Want to note this is NOT a true statement. We use stock bitswap. We do not disable broadcasts. This has never been possible. The only replacement code we offer is to the FindProvidersAsync call, substituting IPNI results.@hannahhoward: In fact, to clarify our own logs show Bitswap continues to broadcast, meaning this error should effect ANY client. The problem is while it broadcasts want haves, it never switches to requesting a WANT-BLOCK.
@Jorropo: @hannahhoward wouldn't at-worst after 30s the wantlist rebroadcast happens and unblock the session, or after 2 RTTs ?
Because if the session never ever sends a WANT-BLOCK we could get a quick win where sessions would stop using FindProvidersAsync results at all and 100% rely ony rebroadcasting that means we could do:
- Session is starving and starts a FindProvidersAsync call which is gonna connect to 10 results, this is completely asynchronous and results are never bubbled to the sessions.
- Result from FindProvidersAsync has been connected, a peerQueue is created and the sessions is notified of this new potential partner
- Session / Bitswap Client sends all of our WANT-HAVEs to this new unknown peer
- Peer respond with HAVE
- Session then sends WANT-BLOCK

This would be wasting a roundtrip, but AFAIT is a quick win.@hannahhoward: Listen, I was surprised as heck that rebroadcast doesn't do anything. But that's what the logs show on our side.

I believe the fundamental problem is that the PeerManager.SendWants fails silently when there is no peer queue. It should error and the calling code (SessionWantSender in this case) should figure out what to do with that.

You can see the chain of rebroadcasts at the end of the log for this test run.

```
2023-08-15T03:50:05.3658816Z 2023-08-15T03:49:24.539Z	DEBUG	blockservice	blockservice/blockservice.go:247	BlockService: Searching
2023-08-15T03:50:05.3659584Z 2023-08-15T03:49:24.539Z	DEBUG	bitswap	getter/getter.go:86	Bitswap.GetBlockRequest.Start	{"cid": "bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}
2023-08-15T03:50:05.3660049Z 2023-08-15T03:49:24.540Z	INFO	bs:sess	session/session.go:460	No peers - broadcasting	{"session": 1, "want-count": 1}
2023-08-15T03:50:05.3660814Z 2023-08-15T03:49:24.540Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3661634Z 2023-08-15T03:49:24.544Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3662425Z 2023-08-15T03:49:24.544Z	DEBUG	bs:sess	session/session.go:361	FindMorePeers	{"session": 1, "cid": "bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq", "pending": 1}
2023-08-15T03:50:05.3663230Z 2023-08-15T03:49:24.544Z	DEBUG	bitswap	providerquerymanager/providerquerymanager.go:329	New Provider Query on cid: bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq
2023-08-15T03:50:05.3664151Z 2023-08-15T03:49:24.544Z	DEBUG	bitswap	providerquerymanager/providerquerymanager.go:234	Beginning Find Provider Request for cid: bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq
2023-08-15T03:50:05.3664931Z 2023-08-15T03:49:24.544Z	DEBUG	lassie/bitswap	bitswaphelpers/indexerrouting.go:86	provider records requested from bitswap, sending back indexer results	{"providerCount": 1}
2023-08-15T03:50:05.3665603Z 2023-08-15T03:49:24.544Z	DEBUG	basichost	basic/basic_host.go:737	host QmdjqZU7uhXBdAdas2bAq9NUcfopNtj9noWvkhzDoBnCQV dialing 1WRsHVXm2wNTMm
2023-08-15T03:50:05.3666112Z 2023-08-15T03:49:24.544Z	DEBUG	mocknet	mock/mock_peernet.go:119	QmdjqZU7uhXBdAdas2bAq9NUcfopNtj9noWvkhzDoBnCQV (newly) dialing 1WRsHVXm2wNTMm
2023-08-15T03:50:05.3666798Z 2023-08-15T03:49:24.545Z	DEBUG	mocknet	mock/mock_peernet.go:132	QmdjqZU7uhXBdAdas2bAq9NUcfopNtj9noWvkhzDoBnCQV dialing 1WRsHVXm2wNTMm openingConn
2023-08-15T03:50:05.3667474Z 2023-08-15T03:49:24.545Z	DEBUG	mocknet	mock/mock_peernet.go:140	QmdjqZU7uhXBdAdas2bAq9NUcfopNtj9noWvkhzDoBnCQV opening connection to 1WRsHVXm2wNTMm
2023-08-15T03:50:05.3668222Z 2023-08-15T03:49:24.545Z	DEBUG	mocknet	mock/mock_conn.go:148	Conn.NewStreamWithProtocol: QmdjqZU7uhXBdAdas2bAq9NUcfopNtj9noWvkhzDoBnCQV --> 1WRsHVXm2wNTMm
2023-08-15T03:50:05.3668786Z 2023-08-15T03:49:24.545Z	DEBUG	basichost	basic/basic_host.go:433	negotiated: /ipfs/id/1.0.0 (took 72.901µs)
2023-08-15T03:50:05.3669625Z 2023-08-15T03:49:24.545Z	DEBUG	net/identify	identify/id.go:463	sending snapshot	{"seq": 2, "protocols": ["/ipfs/bitswap","/ipfs/bitswap/1.0.0","/ipfs/bitswap/1.1.0","/ipfs/bitswap/1.2.0","/ipfs/id/1.0.0","/ipfs/id/push/1.0.0"], "addrs": ["/ip4/127.0.0.1/tcp/24734"]}
2023-08-15T03:50:05.3670491Z 2023-08-15T03:49:24.545Z	DEBUG	net/identify	identify/id.go:468	/ipfs/id/1.0.0 sending message to QmdjqZU7uhXBdAdas2bAq9NUcfopNtj9noWvkhzDoBnCQV /ip6/100::ee68:9659:e2d0:d7c6/tcp/4242
2023-08-15T03:50:05.3671228Z 2023-08-15T03:49:24.545Z	DEBUG	net/identify	identify/id.go:519	/ipfs/id/1.0.0 received message from 1WRsHVXm2wNTMm /ip4/127.0.0.1/tcp/24734
2023-08-15T03:50:05.3671982Z 2023-08-15T03:49:24.546Z	DEBUG	net/identify	identify/id.go:787	QmdjqZU7uhXBdAdas2bAq9NUcfopNtj9noWvkhzDoBnCQV received listen addrs for 1WRsHVXm2wNTMm: [/ip4/127.0.0.1/tcp/24734]
2023-08-15T03:50:05.3672998Z 2023-08-15T03:49:24.546Z	WARN	net/identify	identify/id.go:811	QmdjqZU7uhXBdAdas2bAq9NUcfopNtj9noWvkhzDoBnCQV cannot unmarshal key from remote peer: 1WRsHVXm2wNTMm, asn1: syntax error: truncated tag or length
2023-08-15T03:50:05.3673720Z 2023-08-15T03:49:24.546Z	DEBUG	net/identify	identify/obsaddr.go:442	added own observed listen addr	{"observed": "/ip6/100::ee68:9659:e2d0:d7c6/tcp/4242"}
2023-08-15T03:50:05.3674449Z 2023-08-15T03:49:24.546Z	DEBUG	basichost	basic/basic_host.go:754	host QmdjqZU7uhXBdAdas2bAq9NUcfopNtj9noWvkhzDoBnCQV finished dialing 1WRsHVXm2wNTMm
2023-08-15T03:50:05.3675311Z 2023-08-15T03:49:24.546Z	DEBUG	bitswap	providerquerymanager/providerquerymanager.go:329	Received provider (1WRsHVXm2wNTMm) for cid (bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq)
2023-08-15T03:50:05.3676071Z 2023-08-15T03:49:24.546Z	DEBUG	bitswap	providerquerymanager/providerquerymanager.go:329	Finished Provider Query on cid: bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq
2023-08-15T03:50:05.3676783Z 2023-08-15T03:49:24.546Z	DEBUG	bs:sprmgr	sessionpeermanager/sessionpeermanager.go:68	Bitswap: Added peer to session	{"session": 1, "peer": "1WRsHVXm2wNTMm", "peerCount": 1}
2023-08-15T03:50:05.3677631Z 2023-08-15T03:49:24.546Z	DEBUG	bs:sess	session/sessionwantsender.go:655	sws update want block presence	{"cid": "bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq", "peerID": "1WRsHVXm2wNTMm"}
2023-08-15T03:50:05.3678193Z 2023-08-15T03:49:24.546Z	DEBUG	bs:sess	session/sessionwantsender.go:762	sws new best peer	{"peerID": "1WRsHVXm2wNTMm"}
2023-08-15T03:50:05.3679030Z 2023-08-15T03:49:24.546Z	DEBUG	bs:sess	session/sessionwantsender.go:655	sws update want block presence	{"cid": "bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq", "peerID": "1WRsHVXm2wNTMm"}
2023-08-15T03:50:05.3679595Z 2023-08-15T03:49:24.546Z	DEBUG	bs:sess	session/sessionwantsender.go:762	sws new best peer	{"peerID": "1WRsHVXm2wNTMm"}
2023-08-15T03:50:05.3680183Z 2023-08-15T03:49:24.546Z	DEBUG	bs:sess	session/sessionwantsender.go:534	sws send next wants	{"newly available": ["1WRsHVXm2wNTMm"]}
2023-08-15T03:50:05.3681054Z 2023-08-15T03:49:24.546Z	DEBUG	bs:sess	session/sessionwantsender.go:557	sws send new want block	{"cid": "bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq", "peerID": "1WRsHVXm2wNTMm"}
2023-08-15T03:50:05.3681500Z 2023-08-15T03:49:24.547Z	DEBUG	bs:sess	session/sessionwantsender.go:534	sws send next wants	{"newly available": null}
2023-08-15T03:50:05.3682429Z 2023-08-15T03:49:24.547Z	DEBUG	bs:sess	session/sessionwantsender.go:545	sws want block in process, no new want block sent	{"cid": "bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}
2023-08-15T03:50:05.3683016Z 2023-08-15T03:49:24.547Z	DEBUG	mocknet	mock/mock_peernet.go:183	1WRsHVXm2wNTMm accepting connection from QmdjqZU7uhXBdAdas2bAq9NUcfopNtj9noWvkhzDoBnCQV
2023-08-15T03:50:05.3683738Z 2023-08-15T03:49:24.547Z	DEBUG	mocknet	mock/mock_conn.go:148	Conn.NewStreamWithProtocol: 1WRsHVXm2wNTMm --> QmdjqZU7uhXBdAdas2bAq9NUcfopNtj9noWvkhzDoBnCQV
2023-08-15T03:50:05.3684223Z 2023-08-15T03:49:24.547Z	DEBUG	basichost	basic/basic_host.go:433	negotiated: /ipfs/id/1.0.0 (took 96.201µs)
2023-08-15T03:50:05.3685455Z 2023-08-15T03:49:24.547Z	DEBUG	net/identify	identify/id.go:463	sending snapshot	{"seq": 2, "protocols": ["/fil/datatransfer/1.2.0","/ipfs/bitswap","/ipfs/bitswap/1.0.0","/ipfs/bitswap/1.1.0","/ipfs/bitswap/1.2.0","/ipfs/graphsync/2.0.0","/ipfs/id/1.0.0","/ipfs/id/push/1.0.0"], "addrs": ["/ip6/100::ee68:9659:e2d0:d7c6/tcp/4242"]}
2023-08-15T03:50:05.3685945Z 2023-08-15T03:49:24.547Z	DEBUG	net/identify	identify/id.go:468	/ipfs/id/1.0.0 sending message to 1WRsHVXm2wNTMm /ip4/127.0.0.1/tcp/24734
2023-08-15T03:50:05.3686987Z 2023-08-15T03:49:24.548Z	DEBUG	net/identify	identify/id.go:519	/ipfs/id/1.0.0 received message from QmdjqZU7uhXBdAdas2bAq9NUcfopNtj9noWvkhzDoBnCQV /ip6/100::ee68:9659:e2d0:d7c6/tcp/4242
2023-08-15T03:50:05.3687828Z 2023-08-15T03:49:24.548Z	DEBUG	mocknet	mock/mock_conn.go:148	Conn.NewStreamWithProtocol: QmdjqZU7uhXBdAdas2bAq9NUcfopNtj9noWvkhzDoBnCQV --> 1WRsHVXm2wNTMm
2023-08-15T03:50:05.3688986Z 2023-08-15T03:49:24.548Z	DEBUG	bitswap	messagequeue/messagequeue.go:663	sent message	{"type": "WANT_HAVE", "cid": "bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq", "local": "QmdjqZU7uhXBdAdas2bAq9NUcfopNtj9noWvkhzDoBnCQV", "to": "1WRsHVXm2wNTMm"}
2023-08-15T03:50:05.3689564Z 2023-08-15T03:49:24.548Z	WARN	bitswap_network	network/ipfs_impl.go:245	error setting deadline: set pipe: deadline not supported
2023-08-15T03:50:05.3690278Z 2023-08-15T03:49:24.548Z	DEBUG	mocknet	mock/mock_conn.go:148	Conn.NewStreamWithProtocol: QmdjqZU7uhXBdAdas2bAq9NUcfopNtj9noWvkhzDoBnCQV --> 1WRsHVXm2wNTMm
2023-08-15T03:50:05.3690853Z 2023-08-15T03:49:24.548Z	WARN	bitswap_network	network/ipfs_impl.go:269	error resetting deadline: set pipe: deadline not supported
2023-08-15T03:50:05.3691308Z 2023-08-15T03:49:24.548Z	DEBUG	basichost	basic/basic_host.go:433	negotiated: /ipfs/bitswap/1.2.0 (took 91.601µs)
2023-08-15T03:50:05.3691981Z 2023-08-15T03:49:24.549Z	DEBUG	bitswap_network	network/ipfs_impl.go:427	bitswap net handleNewStream from QmdjqZU7uhXBdAdas2bAq9NUcfopNtj9noWvkhzDoBnCQV
2023-08-15T03:50:05.3692765Z 2023-08-15T03:49:24.549Z	DEBUG	engine	decision/engine.go:634	Bitswap engine <- msg	{"local": "1WRsHVXm2wNTMm", "from": "QmdjqZU7uhXBdAdas2bAq9NUcfopNtj9noWvkhzDoBnCQV", "entryCount": 1}
2023-08-15T03:50:05.3693683Z 2023-08-15T03:49:24.549Z	DEBUG	engine	decision/engine.go:638	Bitswap engine <- want-have	{"local": "1WRsHVXm2wNTMm", "from": "QmdjqZU7uhXBdAdas2bAq9NUcfopNtj9noWvkhzDoBnCQV", "cid": "bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}
2023-08-15T03:50:05.3694182Z LinkSystemBlockstore.GetSize bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq
2023-08-15T03:50:05.3694525Z LinkSystemBlockstore.GetSize= bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq 1332
2023-08-15T03:50:05.3695427Z 2023-08-15T03:49:24.549Z	DEBUG	engine	decision/engine.go:779	Bitswap engine: block found	{"local": "1WRsHVXm2wNTMm", "from": "QmdjqZU7uhXBdAdas2bAq9NUcfopNtj9noWvkhzDoBnCQV", "cid": "bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq", "isWantBlock": false}
2023-08-15T03:50:05.3695865Z 2023-08-15T03:49:24.549Z	DEBUG	engine	decision/engine.go:545	Bitswap process tasks	{"local": "1WRsHVXm2wNTMm", "taskCount": 1}
2023-08-15T03:50:05.3696688Z 2023-08-15T03:49:24.549Z	DEBUG	engine	decision/engine.go:598	Bitswap engine -> msg	{"local": "1WRsHVXm2wNTMm", "to": "QmdjqZU7uhXBdAdas2bAq9NUcfopNtj9noWvkhzDoBnCQV", "blockCount": 0, "presenceCount": 1, "size": 38}
2023-08-15T03:50:05.3697263Z 2023-08-15T03:49:24.549Z	DEBUG	mocknet	mock/mock_conn.go:148	Conn.NewStreamWithProtocol: 1WRsHVXm2wNTMm --> QmdjqZU7uhXBdAdas2bAq9NUcfopNtj9noWvkhzDoBnCQV
2023-08-15T03:50:05.3697668Z 2023-08-15T03:49:24.549Z	DEBUG	basichost	basic/basic_host.go:413	protocol mux failed: stream reset (took 1.057616ms)
2023-08-15T03:50:05.3698303Z 2023-08-15T03:49:24.550Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3699084Z 2023-08-15T03:49:24.550Z	DEBUG	net/identify	identify/id.go:787	1WRsHVXm2wNTMm received listen addrs for QmdjqZU7uhXBdAdas2bAq9NUcfopNtj9noWvkhzDoBnCQV: [/ip6/100::ee68:9659:e2d0:d7c6/tcp/4242]
2023-08-15T03:50:05.3699531Z 2023-08-15T03:49:24.550Z	WARN	bitswap_network	network/ipfs_impl.go:245	error setting deadline: set pipe: deadline not supported
2023-08-15T03:50:05.3700098Z 2023-08-15T03:49:24.550Z	WARN	bitswap_network	network/ipfs_impl.go:269	error resetting deadline: set pipe: deadline not supported
2023-08-15T03:50:05.3700623Z 2023-08-15T03:49:24.550Z	DEBUG	basichost	basic/basic_host.go:433	negotiated: /ipfs/bitswap/1.2.0 (took 816.112µs)
2023-08-15T03:50:05.3701048Z 2023-08-15T03:49:24.550Z	DEBUG	bitswap_network	network/ipfs_impl.go:427	bitswap net handleNewStream from 1WRsHVXm2wNTMm
2023-08-15T03:50:05.3701893Z 2023-08-15T03:49:24.550Z	DEBUG	bs:sess	session/session.go:221	Bitswap <- HAVE	{"local": "QmdjqZU7uhXBdAdas2bAq9NUcfopNtj9noWvkhzDoBnCQV", "from": "1WRsHVXm2wNTMm", "cid": "bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq", "session": 1}
2023-08-15T03:50:05.3702712Z 2023-08-15T03:49:24.551Z	DEBUG	bs:sess	session/sessionwantsender.go:655	sws update want block presence	{"cid": "bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq", "peerID": "1WRsHVXm2wNTMm"}
2023-08-15T03:50:05.3703132Z 2023-08-15T03:49:24.551Z	DEBUG	bs:sess	session/sessionwantsender.go:762	sws new best peer	{"peerID": "1WRsHVXm2wNTMm"}
2023-08-15T03:50:05.3703543Z 2023-08-15T03:49:24.551Z	DEBUG	bs:sess	session/sessionwantsender.go:534	sws send next wants	{"newly available": null}
2023-08-15T03:50:05.3704256Z 2023-08-15T03:49:24.551Z	DEBUG	bs:sess	session/sessionwantsender.go:545	sws want block in process, no new want block sent	{"cid": "bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}
2023-08-15T03:50:05.3705186Z 2023-08-15T03:49:24.550Z	DEBUG	bitswap-server	server/server.go:325	sent message	{"type": "HAVE", "cid": "bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq", "local": "1WRsHVXm2wNTMm", "to": "QmdjqZU7uhXBdAdas2bAq9NUcfopNtj9noWvkhzDoBnCQV"}
2023-08-15T03:50:05.3705717Z 2023-08-15T03:49:24.551Z	DEBUG	bitswap-server	server/server.go:379	sent message	{"peer": "QmdjqZU7uhXBdAdas2bAq9NUcfopNtj9noWvkhzDoBnCQV"}
2023-08-15T03:50:05.3706110Z 2023-08-15T03:49:24.551Z	DEBUG	bitswap-server	server/server.go:282	Bitswap.TaskWorker.Loop	{"ID": 6}
2023-08-15T03:50:05.3706871Z 2023-08-15T03:49:24.558Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3707527Z 2023-08-15T03:49:24.571Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3708152Z 2023-08-15T03:49:24.587Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3708787Z 2023-08-15T03:49:24.608Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3709446Z 2023-08-15T03:49:24.633Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3710015Z 2023-08-15T03:49:24.661Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3710641Z 2023-08-15T03:49:24.694Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3711261Z 2023-08-15T03:49:24.731Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3711893Z 2023-08-15T03:49:24.772Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3712501Z 2023-08-15T03:49:24.817Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3713113Z 2023-08-15T03:49:24.866Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3713818Z 2023-08-15T03:49:24.918Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3714499Z 2023-08-15T03:49:24.975Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3715257Z 2023-08-15T03:49:25.035Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3715893Z 2023-08-15T03:49:25.101Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3716502Z 2023-08-15T03:49:25.169Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3717115Z 2023-08-15T03:49:25.242Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3717725Z 2023-08-15T03:49:25.319Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3718356Z 2023-08-15T03:49:25.400Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3718916Z 2023-08-15T03:49:25.484Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3719534Z 2023-08-15T03:49:25.573Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3720284Z 2023-08-15T03:49:25.667Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3720991Z 2023-08-15T03:49:25.763Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3721613Z 2023-08-15T03:49:25.864Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3722224Z 2023-08-15T03:49:25.968Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3722830Z 2023-08-15T03:49:26.077Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3723440Z 2023-08-15T03:49:26.190Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3724049Z 2023-08-15T03:49:26.308Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3724668Z 2023-08-15T03:49:26.428Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3725276Z 2023-08-15T03:49:26.553Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3725931Z 2023-08-15T03:49:26.682Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3726621Z 2023-08-15T03:49:26.815Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3727230Z 2023-08-15T03:49:26.952Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3727945Z 2023-08-15T03:49:27.092Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3728563Z 2023-08-15T03:49:27.237Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3729176Z 2023-08-15T03:49:27.385Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3729804Z 2023-08-15T03:49:27.538Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3730411Z 2023-08-15T03:49:27.695Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3731027Z 2023-08-15T03:49:27.855Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3731667Z 2023-08-15T03:49:28.020Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3732279Z 2023-08-15T03:49:28.189Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3732889Z 2023-08-15T03:49:28.361Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3733497Z 2023-08-15T03:49:28.538Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3734112Z 2023-08-15T03:49:28.719Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3734733Z 2023-08-15T03:49:28.903Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3735347Z 2023-08-15T03:49:29.092Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3735997Z 2023-08-15T03:49:29.285Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
2023-08-15T03:50:05.3736548Z 2023-08-15T03:49:29.482Z	DEBUG	bs:sess	session/session.go:467	broadcastWantHaves	{"session": 1, "cids": [{"/":"bafybeifrrglx2issn2had5rtstn3xltla6vxmpjfwfz7o3hapvkynh4zoq"}]}
```@Jorropo: Ok intresting, what I was trying to get at is that something is left in a bad invalid state.@hannahhoward: alternate fix proposed, basically trying to keep up from getting ot an incorrect state as way to fix this issue: https://github.com/ipfs/boxo/pull/452 -- @Jorropo  I believe with this either the subsequent connect event getting processed or a rebroadcast will put us back into the correct state.@rvagg: What are the chances of this being looked at in the near future? We've had to pin Lassie to the commit I got into `main` but was subsequently reverted (https://github.com/filecoin-project/lassie/blob/9a94e077568971c9b941f00ddbff4a32cd82117b/go.mod#L13) and at some point that's going to become a compatibility or even security problem. So I need to figure out whether I need to be planning on maintaining a fork or a branch here to deal with it on my end.@BigLep: Hi @rvagg - we missed on answering your question sooner.

If I understand correctly, the initial proposed fix was merged (https://github.com/ipfs/boxo/pull/435 ) but then reverted (https://github.com/ipfs/boxo/pull/444 ).  

This hasn't been a priority for Boxo maintainers to directly address, but we understand it puts Lassie in a tough spot.  If there's a different approach that accounts for the feedback from the reverted attempt, I'll make sure maintainers give it review.  

Is https://github.com/ipfs/boxo/pull/452 such an attempt?  If so, please mark it out of draft when it's ready for review.

Thanks.   @rvagg: I believe #452 is just a proposal for how this issue might be addressed, not a proper fix, it needs to be taken further.

Here's my understanding of the state of this issue:

1. Lassie is hit acutely by this because we have a specific list of providers that we know very likely have the content we are after so we target those—not getting a response to the wants is a surprising outcome that should not occur since we have told bitswap who to send them to.
2. This is very likely to have broad impact on bitswap users but is unlikely to be as visible as it is to Lassie due to the more detached nature of the providers (being at arms length via the discovery mechanisms instead of the indexer lookup Lassie does). It'll mean that a peer seeking blocks will figure out who _likely_ has them, then attempt to ask for them, but not get any kind of response because of the race condition. It'll be more of a suboptimal state than a failure state since you can often go fishing for more peers. Perhaps though it accounts for a lot of the "I know it's on IPFS but Kubo occasionally fails to find it" problems.
3. The objection to the original fix were due to the use of this code at scale. So the tension exists between the (more common) small-client cases and the (more critical) at-scale cases. The current priority is for the latter.
4. Lassie is stuck on a commit of Boxo and at some point the monolith-dependency trap is going to force our hand in some way. My guess is that it'll probably be a fork of boxo/bitswap so we can update Boxo dependency while having an alternative version of Bitswap.

Not sure what else is to be done about this with the limited people-bandwidth we have and the current state of prioritisation across our orgs. 🤷 @gammazero: Bitswap relies on "being connected" to mean that state has been fully propagated. In other words, this means that a call to `Connected()` shouldn't return until the state change has been fully propagated (as was mentioned earlier). Specifically, a connection is not fully established until `PeerManager` has a `peerQueues` entry, since bitswap relies on that as part of being connected. Seems that there needs to be a way to force/wait for a `peerQueues` entry to either complete or fail before bitswap considers the connection fully established. PR #452 is also good to not silently fail, but it seems like there is still more to do to complete connection establishment.@Dreamacro: I can also confirm that this bug exists and that it has some far-reaching implications. I'm currently on a private libp2p network with 600 peers, and after actual file synchronization speed tests, I've seen significant rate increases with #452.

In the course of testing, I discovered an interesting phenomenon:
1. without #452 
When I use `merkledag.NewSession`, the rate is very slow and likely to hang; When using only `dag.Get`, the rate is not fast enough but acceptable
2. with #452 
When I use `merkledag.NewSession`, the rate is not fast enough but does not hang; When using only `dag.Get`, the rate is fast enough, but some peer has the memory leak.

From a quick look at boxo's code, I realize that `dag.Get` always creates sessions, I don't know if this is the expected behavior but from the code elegance point `NewSession` is more clear. Does anyone understand this phenomenon?@gammazero: Fixed by #435 

Solution patch:
diff --git a/CHANGELOG.md b/CHANGELOG.md
index bf21168f..d4244b4b 100644
--- a/CHANGELOG.md
+++ b/CHANGELOG.md
@@ -80,6 +80,8 @@ The following emojis are used to highlight certain changes:
 
 ### Fixed
 
+- Do not erroneously update the state of sent wants when a send a peer disconnected and the send did not happen. [#452](https://github.com/ipfs/boxo/pull/452)
+
 ### Security
 
 ## [v0.24.3]
diff --git a/bitswap/client/internal/peermanager/peermanager.go b/bitswap/client/internal/peermanager/peermanager.go
index 78a1d4c8..76c63606 100644
--- a/bitswap/client/internal/peermanager/peermanager.go
+++ b/bitswap/client/internal/peermanager/peermanager.go
@@ -143,13 +143,15 @@ func (pm *PeerManager) BroadcastWantHaves(ctx context.Context, wantHaves []cid.C
 
 // SendWants sends the given want-blocks and want-haves to the given peer.
 // It filters out wants that have previously been sent to the peer.
-func (pm *PeerManager) SendWants(ctx context.Context, p peer.ID, wantBlocks []cid.Cid, wantHaves []cid.Cid) {
+func (pm *PeerManager) SendWants(ctx context.Context, p peer.ID, wantBlocks []cid.Cid, wantHaves []cid.Cid) bool {
 	pm.pqLk.Lock()
 	defer pm.pqLk.Unlock()
 
-	if _, ok := pm.peerQueues[p]; ok {
-		pm.pwm.sendWants(p, wantBlocks, wantHaves)
+	if _, ok := pm.peerQueues[p]; !ok {
+		return false
 	}
+	pm.pwm.sendWants(p, wantBlocks, wantHaves)
+	return true
 }
 
 // SendCancels sends cancels for the given keys to all peers who had previously
diff --git a/bitswap/client/internal/session/session.go b/bitswap/client/internal/session/session.go
index 3e2a9b53..f11d7d83 100644
--- a/bitswap/client/internal/session/session.go
+++ b/bitswap/client/internal/session/session.go
@@ -38,7 +38,7 @@ type PeerManager interface {
 	// interested in a peer's connection state
 	UnregisterSession(uint64)
 	// SendWants tells the PeerManager to send wants to the given peer
-	SendWants(ctx context.Context, peerId peer.ID, wantBlocks []cid.Cid, wantHaves []cid.Cid)
+	SendWants(ctx context.Context, peerId peer.ID, wantBlocks []cid.Cid, wantHaves []cid.Cid) bool
 	// BroadcastWantHaves sends want-haves to all connected peers (used for
 	// session discovery)
 	BroadcastWantHaves(context.Context, []cid.Cid)
diff --git a/bitswap/client/internal/session/sessionwantsender.go b/bitswap/client/internal/session/sessionwantsender.go
index 338150ec..09a9381e 100644
--- a/bitswap/client/internal/session/sessionwantsender.go
+++ b/bitswap/client/internal/session/sessionwantsender.go
@@ -513,6 +513,7 @@ func (sws *sessionWantSender) processExhaustedWants(exhausted []cid.Cid) {
 type wantSets struct {
 	wantBlocks *cid.Set
 	wantHaves  *cid.Set
+	sent       bool
 }
 
 type allWants map[peer.ID]*wantSets
@@ -551,9 +552,6 @@ func (sws *sessionWantSender) sendNextWants(newlyAvailable []peer.ID) {
 			continue
 		}
 
-		// Record that we are sending a want-block for this want to the peer
-		sws.setWantSentTo(c, wi.bestPeer)
-
 		// Send a want-block to the chosen peer
 		toSend.forPeer(wi.bestPeer).wantBlocks.Add(c)
 
@@ -567,6 +565,16 @@ func (sws *sessionWantSender) sendNextWants(newlyAvailable []peer.ID) {
 
 	// Send any wants we've collected
 	sws.sendWants(toSend)
+
+	for c, wi := range sws.wants {
+		if wi.bestPeer != "" && wi.sentTo == "" {
+			// check if a want block was successfully sent to the best peer
+			if toSend.forPeer(wi.bestPeer).sent {
+				// Record that we are sending a want-block for this want to the peer
+				sws.setWantSentTo(c, wi.bestPeer)
+			}
+		}
+	}
 }
 
 // sendWants sends want-have and want-blocks to the appropriate peers
@@ -584,8 +592,11 @@ func (sws *sessionWantSender) sendWants(sends allWants) {
 		// precedence over want-haves.
 		wblks := snd.wantBlocks.Keys()
 		whaves := snd.wantHaves.Keys()
-		sws.pm.SendWants(sws.ctx, p, wblks, whaves)
-
+		snd.sent = sws.pm.SendWants(sws.ctx, p, wblks, whaves)
+		if !snd.sent {
+			// Do not update state if the wants not sent.
+			continue
+		}
 		// Inform the session that we've sent the wants
 		sws.onSend(p, wblks, whaves)
 



Test patch:
diff --git a/bitswap/client/internal/session/session_test.go b/bitswap/client/internal/session/session_test.go
index 061e298e..2dd1e1be 100644
--- a/bitswap/client/internal/session/session_test.go
+++ b/bitswap/client/internal/session/session_test.go
@@ -141,9 +141,11 @@ func newFakePeerManager() *fakePeerManager {
 	}
 }
 
-func (pm *fakePeerManager) RegisterSession(peer.ID, bspm.Session)                    {}
-func (pm *fakePeerManager) UnregisterSession(uint64)                                 {}
-func (pm *fakePeerManager) SendWants(context.Context, peer.ID, []cid.Cid, []cid.Cid) {}
+func (pm *fakePeerManager) RegisterSession(peer.ID, bspm.Session) {}
+func (pm *fakePeerManager) UnregisterSession(uint64)              {}
+func (pm *fakePeerManager) SendWants(context.Context, peer.ID, []cid.Cid, []cid.Cid) bool {
+	return true
+}
 func (pm *fakePeerManager) BroadcastWantHaves(ctx context.Context, cids []cid.Cid) {
 	select {
 	case pm.wantReqs <- wantReq{cids}:
diff --git a/bitswap/client/internal/session/sessionwantsender_test.go b/bitswap/client/internal/session/sessionwantsender_test.go
index ac094ac0..e5589dd5 100644
--- a/bitswap/client/internal/session/sessionwantsender_test.go
+++ b/bitswap/client/internal/session/sessionwantsender_test.go
@@ -82,7 +82,7 @@ func (*mockPeerManager) UnregisterSession(uint64)                      {}
 func (*mockPeerManager) BroadcastWantHaves(context.Context, []cid.Cid) {}
 func (*mockPeerManager) SendCancels(context.Context, []cid.Cid)        {}
 
-func (pm *mockPeerManager) SendWants(ctx context.Context, p peer.ID, wantBlocks []cid.Cid, wantHaves []cid.Cid) {
+func (pm *mockPeerManager) SendWants(ctx context.Context, p peer.ID, wantBlocks []cid.Cid, wantHaves []cid.Cid) bool {
 	pm.lk.Lock()
 	defer pm.lk.Unlock()
 
@@ -92,6 +92,7 @@ func (pm *mockPeerManager) SendWants(ctx context.Context, p peer.ID, wantBlocks
 		pm.peerSends[p] = sw
 	}
 	sw.add(wantBlocks, wantHaves)
+	return true
 }
 
 func (pm *mockPeerManager) waitNextWants() map[peer.ID]*sentWants {
diff --git a/bitswap/client/internal/sessionmanager/sessionmanager_test.go b/bitswap/client/internal/sessionmanager/sessionmanager_test.go
index e8259b1d..bad26ad9 100644
--- a/bitswap/client/internal/sessionmanager/sessionmanager_test.go
+++ b/bitswap/client/internal/sessionmanager/sessionmanager_test.go
@@ -66,10 +66,10 @@ type fakePeerManager struct {
 	cancels []cid.Cid
 }
 
-func (*fakePeerManager) RegisterSession(peer.ID, bspm.Session)                    {}
-func (*fakePeerManager) UnregisterSession(uint64)                                 {}
-func (*fakePeerManager) SendWants(context.Context, peer.ID, []cid.Cid, []cid.Cid) {}
-func (*fakePeerManager) BroadcastWantHaves(context.Context, []cid.Cid)            {}
+func (*fakePeerManager) RegisterSession(peer.ID, bspm.Session)                         {}
+func (*fakePeerManager) UnregisterSession(uint64)                                      {}
+func (*fakePeerManager) SendWants(context.Context, peer.ID, []cid.Cid, []cid.Cid) bool { return true }
+func (*fakePeerManager) BroadcastWantHaves(context.Context, []cid.Cid)                 {}
 func (fpm *fakePeerManager) SendCancels(ctx context.Context, cancels []cid.Cid) {
 	fpm.lk.Lock()
 	defer fpm.lk.Unlock()