request_response (at least!) cancels its own dials due to race condition

[MatthiasvB]

Summary

I'm building a file sharing app that uses request_response to actually transport the bits.

There are many conditions when this fails, one of them is when I have multiple files queued up, discover the target node, and try sending them all at once.

It seems some weird interaction of all these request_response threads started at once ends up cancelling all of them, something to do with peer conditions (see logs below)

I have to "manually" take great care to send all queued up files sequentially, in order for dialing not to break

In the logs, lines such as Is dialing: false --- Is connected: false are logged from a patched version of this code

Expected behavior

I should not have to care about when a request is sent

Actual behavior

I can not initiate multiple file transfers using request_response at once if the target peer isn't connected yet, because dialing fails

Relevant log output

mDNS discovered a new peer: 12D3KooWD9smX6tANTiVamKw9KKLKgBfzq2Hx2fzNUnNHRc4NAFw
Currently pending files: 5
Sending chunk
Sending chunk
Sending chunk
Sending chunk
Sending chunk
Is dialing: false  ---  Is connected: false
Is dialing: true  ---  Is connected: false
Dial peer condition false: DisconnectedAndNotDialing
Is dialing: true  ---  Is connected: false
Dial peer condition false: DisconnectedAndNotDialing
Is dialing: true  ---  Is connected: false
Dial peer condition false: DisconnectedAndNotDialing
Is dialing: true  ---  Is connected: false
Dial peer condition false: DisconnectedAndNotDialing
Outbound request failed to peer 12D3KooWD9smX6tANTiVamKw9KKLKgBfzq2Hx2fzNUnNHRc4NAFw with error: Failed to dial the requested peer
Dial Failure
Outbound request failed to peer 12D3KooWD9smX6tANTiVamKw9KKLKgBfzq2Hx2fzNUnNHRc4NAFw with error: Failed to dial the requested peer
Dial Failure
Outbound request failed to peer 12D3KooWD9smX6tANTiVamKw9KKLKgBfzq2Hx2fzNUnNHRc4NAFw with error: Failed to dial the requested peer
Dial Failure
Outbound request failed to peer 12D3KooWD9smX6tANTiVamKw9KKLKgBfzq2Hx2fzNUnNHRc4NAFw with error: Failed to dial the requested peer
Dial Failure
Outbound request failed to peer 12D3KooWD9smX6tANTiVamKw9KKLKgBfzq2Hx2fzNUnNHRc4NAFw with error: Failed to dial the requested peer
Dial Failure

Possible Solution

No response

Version

0.55.0

Would you like to work on fixing this bug?

No

[elenaf9]

Thanks for opening the issue. I am surprised that this gone unnoticed for such a long time.

The following is happening:

1. When trying to send a request to a disconnected peer, we buffer the request and initiate a new dial.
2. The dial condition is DisconnectedAndNotDialing, so if there is already a pending dial then the dial will fail.
3. On any outbound dial failure, all pending outbound requests are drained and reported as failed.

#6000 is fixing this issue by ignoring dial-condition errors in request-response. @MatthiasvB can you please test if that PR is fixing your issue?

[MatthiasvB]

Thank you @elenaf9 for tackling that so promptly. I will test this asap, probably over the weekend

[jxs]

Hi Matthias, thanks for bringing this!
cc @nazar-pc had you noticed this before?