PeerConnectionLost escaping

[cburgdorf]

What is wrong?

This blasted out of our CI run.

DEBUG  06-02 12:30:58  async_process_runner.py  b'\x1b[1m\x1b[31m   ERROR  2020-06-02 12:30:58,526           ETHPeerPool  unexpected error during peer connection\n'
   DEBUG  06-02 12:30:58  async_process_runner.py  b'Traceback (most recent call last):\n'
   DEBUG  06-02 12:30:58  async_process_runner.py  b'  File "/home/circleci/repo/trinity/protocol/common/peer.py", line 239, in maybe_connect_more_peers\n'
   DEBUG  06-02 12:30:58  async_process_runner.py  b'    candidate_counts = await asyncio.gather(*(\n'
   DEBUG  06-02 12:30:58  async_process_runner.py  b'  File "/home/circleci/repo/p2p/peer_pool.py", line 220, in _add_peers_from_backend\n'
   DEBUG  06-02 12:30:58  async_process_runner.py  b'    await self.connect_to_nodes(candidates)\n'
   DEBUG  06-02 12:30:58  async_process_runner.py  b'  File "/home/circleci/repo/p2p/peer_pool.py", line 411, in connect_to_nodes\n'
   DEBUG  06-02 12:30:58  async_process_runner.py  b'    await asyncio.gather(*(self.connect_to_node(node) for node in batch))\n'
   DEBUG  06-02 12:30:58  async_process_runner.py  b'  File "/home/circleci/repo/p2p/peer_pool.py", line 467, in connect_to_node\n'
   DEBUG  06-02 12:30:58  async_process_runner.py  b'    await self.start_peer(peer)\n'
   DEBUG  06-02 12:30:58  async_process_runner.py  b'  File "/home/circleci/repo/p2p/peer_pool.py", line 281, in start_peer\n'
   DEBUG  06-02 12:30:58  async_process_runner.py  b'    self._add_peer(peer, ())\n'
   DEBUG  06-02 12:30:58  async_process_runner.py  b'  File "/home/circleci/repo/p2p/peer_pool.py", line 319, in _add_peer\n'
   DEBUG  06-02 12:30:58  async_process_runner.py  b'    subscriber.register_peer(peer)\n'
   DEBUG  06-02 12:30:58  async_process_runner.py  b'  File "/home/circleci/repo/trinity/components/builtin/network_db/eth1_peer_db/tracker.py", line 114, in register_peer\n'
   DEBUG  06-02 12:30:58  async_process_runner.py  b'    genesis_hash=peer.chain_info.genesis_hash,\n'
   DEBUG  06-02 12:30:58  async_process_runner.py  b'  File "/home/circleci/repo/.tox/py38-wheel-cli/lib/python3.8/site-packages/cached_property.py", line 35, in __get__\n'
   DEBUG  06-02 12:30:58  async_process_runner.py  b'    value = obj.__dict__[self.func.__name__] = self.func(obj)\n'
   DEBUG  06-02 12:30:58  async_process_runner.py  b'  File "/home/circleci/repo/trinity/protocol/common/peer.py", line 109, in chain_info\n'
   DEBUG  06-02 12:30:58  async_process_runner.py  b'    return self.connection.get_logic(ChainInfo.name, ChainInfo)\n'
   DEBUG  06-02 12:30:58  async_process_runner.py  b'  File "/home/circleci/repo/p2p/connection.py", line 269, in get_logic\n'
   DEBUG  06-02 12:30:58  async_process_runner.py  b'    if not self.has_logic(name):\n'
   DEBUG  06-02 12:30:58  async_process_runner.py  b'  File "/home/circleci/repo/p2p/connection.py", line 265, in has_logic\n'
   DEBUG  06-02 12:30:58  async_process_runner.py  b'    raise PeerConnectionLost("Cannot look up subprotocol when connection is closing")\n'
   DEBUG  06-02 12:30:58  async_process_runner.py  b'p2p.exceptions.PeerConnectionLost: Cannot look up subprotocol when connection is closing\x1b[0m\n'

How can it be fixed

🤷

[gsalgado]

I've already mentioned in another PR that it seems like a terrible idea to me to have an @property (Peer.chain_info) that is expected to raise an exception like PeerConnectionLost. Most of the time we won't notice that (specially if it is not documented, as is the case here) and will end up writing code that leak it. One easy way to fix this would be to turn those properties into methods and document that they can raise that exception, but I believe the real issue here is the fact that our behavior/logic stuff uses the async contextmanager fire-and-forget anti-pattern and we end up with a Peer running after behaviors have crashed/exited. I'm currently working on fixing that so maybe we'll also get rid of this once I'm done there

[cburgdorf]

I agree this is a weak spot and continues to be a source of errors. I'm happy if we can find a better way to deal with that 👍

[gsalgado]

So,

trinity/p2p/connection.py

Lines 279 to 280 in e7f3a27

	if self.is_closing:
	raise PeerConnectionLost("Cannot look up subprotocol when connection is closing")

was added to fix an issue (#1352) when connecting two trinity instances: #1364

However, I can no longer reproduce that issue since the recent work I did on ensuring we can reliably connect 2 trinity instances (#1302). While working on that I found/fixed various situations in which a Peer(Service) instance would stop running but wouldn't terminate properly (e.g #1630), which could be the cause of the issue reported in #1352

Given that, I suspect we no longer need to raise PeerConnectionLost() in Connection.has_logic(), which doesn't really make sense as has_logic() is a synchronous method and it should only be called on a still-running Peer (which is not the case if connection.closing is True).

[carver]

I suspect we no longer need to raise PeerConnectionLost() in Connection.has_logic(), which doesn't really make sense as has_logic() is a synchronous method and it should only be called on a still-running Peer (which is not the case if connection.closing is True).

Let's say I agree that this shouldn't ever happen in properly-written code. We still have to decide what has_logic() will do when it happens anyway. Before the patch, it was a really confusing error: UnknownAPI gets raised. A PeerConnectionLost at least describes what's actually happening (the peer is closing).

If we became successful at the goal of never calling has_logic() on a closing peer, then this if test would never evaluate to True, so it doesn't seem to do harm to leave it in.

[gsalgado]

If we became successful at the goal of never calling has_logic() on a closing peer, then this if test would never evaluate to True, so it doesn't seem to do harm to leave it in.

The problem is that we don't usually call has_logic() directly, but we do so indirectly via Peer properties (e.g. peer.chain_info), and it is highly unintuitive that it could raise a PeerConnectionLost, which is why every once in a while we seem to find/introduce code that leaks that and causes trinity to crash

[gsalgado]

And as I wrote that I realized my changes are not making things any better as it's still easy to overlook the fact that these properties can raise an exception (now an UnknwonAPI, which is worse as you pointed out).

Anyway, you're right that we should probably not stop raising a PeerConnectionLost, at least as a safety net, but ideally we should try and fix our callsites to check that the peer is alive before using those APIs. I'm proposing another alternative in #1840 and it's probably better to move this discussion there