Malformed messages: RLP decoding errors with superfluous bytes (related to compression in Ping/Pong/Disconnect)

[veox]

• py-evm Version: trinity-v0.1.0-alpha.20-147-g07cabc7f (git master, commit 07cabc7)
• OS: Arch Linux
• Python Version (python --version): 3.7.2
• Environment (output of pip freeze): gist

What is wrong?

Newly-occurring noisy traceback while decoding RLP:

   DEBUG  01-15 13:04:13            FullServer  Receiving handshake from Address(13.114.245.142:udp:27850|tcp:27850)
...
   DEBUG  01-15 13:24:02               ETHPeer  Finished P2P handshake with <Node(0x8735@13.114.245.142)>, using sub-protocol (eth, 63)
   DEBUG  01-15 13:04:13               ETHPeer  Malformed message from peer ETHPeer <Node(0x8735@13.114.245.142)>: CMD:Ping Error: MalformedMessage("Malformed Ping message: DecodingError('RLP string ends with 2 superfluous bytes')")       
   ERROR  01-15 13:04:13            FullServer  Unexpected error handling handshake                                                                                                                                                            
Traceback (most recent call last):                                                                                                                                                                                                             
  File "/home/veox/src/trinity/p2p/protocol.py", line 95, in decode_payload                                                                                                                                                                    
    data = rlp.decode(rlp_data, sedes=decoder, recursive_cache=True)                                                                                                                                                                           
  File "/home/veox/src/trinity/.virtualenv/trinity/lib/python3.7/site-packages/rlp/codec.py", line 233, in decode                                                                                                                              
    raise DecodingError(msg, rlp)                                                                                                                                                                                                              
rlp.exceptions.DecodingError: RLP string ends with 2 superfluous bytes                                                                                                                                                                         
                                                                                                                                                                                                                                               
The above exception was the direct cause of the following exception:                                                                                                                                                                           
                                                                                                                                                                                                                                               
Traceback (most recent call last):                                                                                                                                                                                                             
  File "/home/veox/src/trinity/trinity/server.py", line 185, in receive_handshake                                                                                                                                                              
    await self._receive_handshake(reader, writer)                                                                                                                                                                                              
  File "/home/veox/src/trinity/trinity/server.py", line 276, in _receive_handshake                                                                                                                                                             
    await self.wait(self.do_handshake(peer))                                                                                                                                                                                                   
  File "/home/veox/src/trinity/p2p/cancellable.py", line 20, in wait                                                                                                                                                                           
    return await self.wait_first(awaitable, token=token, timeout=timeout)                                                                                                                                                                     
  File "/home/veox/src/trinity/p2p/cancellable.py", line 42, in wait_first                                                                                                                                                                    
    return await token_chain.cancellable_wait(*awaitables, timeout=timeout)                                                                                                                                                                    
  File "/home/veox/src/trinity/.virtualenv/trinity/lib/python3.7/site-packages/cancel_token/token.py", line 152, in cancellable_wait                                                                                                           
    return done.pop().result()                                                                                                                                                                                                                 
  File "/home/veox/src/trinity/trinity/server.py", line 280, in do_handshake                                                                                                                                                                  
    await peer.do_sub_proto_handshake()
  File "/home/veox/src/trinity/p2p/peer.py", line 300, in do_sub_proto_handshake
    cmd, msg = await self.read_msg()
  File "/home/veox/src/trinity/p2p/peer.py", line 435, in read_msg                                                                                                                                                                             
    decoded_msg = cast(Dict[str, Any], cmd.decode(msg))                                                                                                                                                                                        
  File "/home/veox/src/trinity/p2p/protocol.py", line 115, in decode                                                               
    return self.decode_payload(encoded_payload)                                                                                                                                          
  File "/home/veox/src/trinity/p2p/protocol.py", line 97, in decode_payload                                                                                                             
    raise MalformedMessage(f"Malformed {type(self).__name__} message: {err!r}") from err                                                                                                                                                       
p2p.exceptions.MalformedMessage: Malformed Ping message: DecodingError('RLP string ends with 2 superfluous bytes')

The above IP shows many versions on ethernodes; but mostly:

• Parity/v1.10.6-stable
• Parity-Ethereum/v2.2.6-beta
• Parity-Ethereum/v2.1.10-stable

---

Also variant with a different message:

   DEBUG  01-15 13:04:39            FullServer  Receiving handshake from Address(89.40.10.150:udp:55106|tcp:55106)                                                                                                                            
   DEBUG  01-15 13:04:39               ETHPeer  Finished P2P handshake with <Node(0x9d45@89.40.10.150)>, using sub-protocol (eth, 63)
   DEBUG  01-15 13:04:39               ETHPeer  Malformed message from peer ETHPeer <Node(0x9d45@89.40.10.150)>: CMD:Disconnect Error: MalformedMessage("Malformed Disconnect message: DecodingError('RLP string ends with 3 superfluous bytes)")
   ERROR  01-15 13:04:39            FullServer  Unexpected error handling handshake
Traceback (most recent call last):
  File "/home/veox/src/trinity/p2p/protocol.py", line 95, in decode_payload
    data = rlp.decode(rlp_data, sedes=decoder, recursive_cache=True)
  File "/home/veox/src/trinity/.virtualenv/trinity/lib/python3.7/site-packages/rlp/codec.py", line 233, in decode
    raise DecodingError(msg, rlp)
rlp.exceptions.DecodingError: RLP string ends with 3 superfluous bytes

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/home/veox/src/trinity/trinity/server.py", line 185, in receive_handshake
    await self._receive_handshake(reader, writer)
  File "/home/veox/src/trinity/trinity/server.py", line 276, in _receive_handshake
    await self.wait(self.do_handshake(peer))
  File "/home/veox/src/trinity/p2p/cancellable.py", line 20, in wait
    return await self.wait_first(awaitable, token=token, timeout=timeout)
  File "/home/veox/src/trinity/p2p/cancellable.py", line 42, in wait_first
    return await token_chain.cancellable_wait(*awaitables, timeout=timeout)
  File "/home/veox/src/trinity/.virtualenv/trinity/lib/python3.7/site-packages/cancel_token/token.py", line 152, in cancellable_wait
    return done.pop().result()
  File "/home/veox/src/trinity/trinity/server.py", line 280, in do_handshake
    await peer.do_sub_proto_handshake()
  File "/home/veox/src/trinity/p2p/peer.py", line 300, in do_sub_proto_handshake
    cmd, msg = await self.read_msg()
  File "/home/veox/src/trinity/p2p/peer.py", line 435, in read_msg
    decoded_msg = cast(Dict[str, Any], cmd.decode(msg))
  File "/home/veox/src/trinity/p2p/p2p_proto.py", line 77, in decode
    raw_decoded = cast(Dict[str, int], super().decode(data))
  File "/home/veox/src/trinity/p2p/protocol.py", line 115, in decode
    return self.decode_payload(encoded_payload)
  File "/home/veox/src/trinity/p2p/protocol.py", line 97, in decode_payload
    raise MalformedMessage(f"Malformed {type(self).__name__} message: {err!r}") from err
p2p.exceptions.MalformedMessage: Malformed Disconnect message: DecodingError('RLP string ends with 3 superfluous bytes')

The latter is from (possibly sending a too_many_peers):

• Geth/v1.8.20-stable

How can it be fixed

• git bisect to find origin of this potential regression.
• Investigate whether the messages are truly malformed.
• Fix decoding errors on trinity's end.
• Don't print tracebacks from known occurrences of malformed RLPs, and report "upstream".

[veox]

Bisect result (with 0dd33ee as good):

There are only 'skip'ped commits left to test.
The first bad commit could be any of:
94f5d27
c90e396
48238e9
We cannot bisect more!

All three are part of PR #108.

---

At first glance, it seems that PR #108 made all snappy compression compulsory:

The Next step of this would be to check if the other Node which we are communicating with, supports Snappy Compression or not. And we should get this information in the Handshake itself. Only if it is supported, then we should send Snappy Compressed Messages. Else we shouldn't Compress the messages.

As noted in the PR, this contradicts EIP-706:

The handshake message is never compressed, since it is needed to negotiate the common version.

EDIT: Nope! The other way around: see next comment.

[Bhargavasomu]

@veox I know exactly why this is showing up. The reason is because that messages coming from Ping, Pong, Disconnect commands are not being compressed while sending nor are they being treated as compressed messages while receiving them from the other peers. But the other clients are compressing these messages and that is why we are seeing the superfluous bytes message. If you observe carefully, the error messages are seen only for the above stated Ping, Pong, Disconnect commands. I will make a PR soon for this.

As noted in the PR, this contradicts EIP-706

The PR doesn't contradict any EIP. It has followed every corner of it. There is no compression being done for the Hello Command, which is our Handshake Message. It is only after the Hello Command is communicated and the versions negotiated, are we doing the Snappy Compression.

In one line, take a look at the following snippet

trinity/p2p/p2p_proto.py

Lines 98 to 101 in 07cabc7

	def __init__(self, peer: 'BasePeer') -> None:
	# For the base protocol the cmd_id_offset is always 0.
	# For the base protocol snappy compression should be disabled
	super().__init__(peer, cmd_id_offset=0, snappy_support=False)

.
This piece of the line is both the Angel and the Devil here. It makes sure that Hello Message is uncompressed which is correct. But it also makes sure that Ping, Pong, Disconnect Messages are also uncompressed which is wrong.

[veox]

Ah, gotcha! Sorry, I panicked, and didn't read in.