Add Goodbye Message When Disconnecting With Peers

[nisdas]

Resolves #4814

• We now send goodbye messages to clients, when we disconnect to them in case we hit our peer limit.
• Also we do not add timeout's to our primary context when passing it down to its sub-methods. This leads to the child methods adopting the parent context's deadlines and leads to early timeouts when performing handshakes with other peers.

cc @q9f , @AgeManning

[shayzluf]

can we please name "2" what is this code?

[protolambda]

My topaz prysm testnet node (on debug log level) has logged hundreds of thousands of lines over the past days, most of which are level=debug msg="Sending Goodbye message to peer" Reason="fault/error" peer=16Uiu2HAm4TsWtLtCmsS4szLRUacQiNFVAcJxZPHjPiDS9XnHLRC6 prefix=sync (with different peer IDs).

Also getting a lot "Failed to decode goodbye stream message" error="stream reset" peer=16Uiu2HAm7XYQgKi27yjvd1G433rJJzpCyrKvzbjeE54DA4n8y6FP prefix=sync topic="/eth2/beacon_chain/req/goodbye/1/ssz_snappy"

Also, the "failed to decode goodbye" sometimes logs up to 8 times, the exact same

Logs excerpt (literally hundreds of thousands of lines of logs, can't share it all, but you get the idea): https://gist.github.com/protolambda/a087de4f44a03deeff0c2a78f50c07ca

Can it be that this functionality is horribly broken in some unexpected way?

[protolambda]

4 days of running in debug mode:

$ sudo docker logs 8cb989bbd69b 2>&1 | cut -c34- | grep "Goodbye" | wc -l
780398
$ sudo docker logs 8cb989bbd69b 2>&1 | cut -c34- | grep "Sending Goodbye message to peer\" Reason=\"fault/error" | wc -l
780509
$ sudo docker logs 8cb989bbd69b 2>&1 | cut -c34- | grep "Goodbye" | wc -l
780599
$ sudo docker logs 8cb989bbd69b 2>&1 | cut -c34- | wc -l
1889091

That's a lot of log messages...

[prestonvanloon]

Are you at max peers? You'll kick anyone that tries to connect to you if you have max peers and they are probably retrying anyway.

[prestonvanloon]

Seeing this often in prod too. @nisdas It may be logging too much or sending multiple good bye to the same peer.

[protolambda]

At max peers yes, around 100 (changed upwards from default). docker image 9a7fbadca570, commit 2eac24c

[protolambda]

Still, if that's max-peers, and it logs goodbye because of failed connect, then that's almost 800.000 connection attempts to my node in 4 days. So maybe the goodbye code is correct, but the connection attempts are way too much.

[prestonvanloon]

Confirmed we are logging more than once per peer. Possibly sending multiple goodbye messages. Some peers logging as much as 50+ on a single node.

Graph link for @nisdas https://kibana.prylabs.network/goto/873081efd6a6753438a9e8f253e6fd1a

[protolambda]

Even at 50 per peer, that's 16000 connection attempts, over 4 days