TunnelCommunity: failed to decrypt message

[ichorid]

Latest devel, traceback on console:

[PID:34076] 2020-10-31 20:08:42,494 - ERROR <community:352> TriblerTunnelCommunity.on_packet(): Exception occurred while handling packet!
Traceback (most recent call last):
  File "/home/tribler/src/pyipv8/ipv8/community.py", line 348, in on_packet
    result = handler(source_address, data)
  File "/home/tribler/src/pyipv8/ipv8/messaging/anonymization/community.py", line 611, in on_cell
    cell.decrypt(self.crypto, circuit=circuit, relay_session_keys=self.relay_session_keys.get(circuit_id))
  File "/home/tribler/src/pyipv8/ipv8/messaging/anonymization/payload.py", line 265, in decrypt
    self.message = crypto.decrypt_str(self.message,
  File "/home/tribler/src/pyipv8/ipv8/messaging/anonymization/tunnelcrypto.py", line 87, in decrypt_str
    return aesgcm.decrypt(salt + content, 0)
  File "/home/tribler/.pyenv/versions/tribler382/lib/python3.8/site-packages/libnacl/aead.py", line 59, in decrypt
    return libnacl.crypto_aead_chacha20poly1305_ietf_decrypt(ctxt, aad, nonce, self.sk)
  File "/home/tribler/.pyenv/versions/tribler382/lib/python3.8/site-packages/libnacl/__init__.py", line 829, in crypto_aead_chacha20poly1305_ietf_decrypt
    raise ValueError('Failed to decrypt message')
ValueError: Failed to decrypt message

[egbertbouman]

Do you remember if this happened directly after a re-start? Did the TunnelCommunity continue to work normally?

[ichorid]

Yes, it happened just after a restart. I don't know if TunnelCommunity was able to work normally, I did not checked it.

[egbertbouman]

OK, thanks! In that case, it's probably an old packet. I'll fix this in IPv8.

[kozlovsky]

Reappeared in 7.10:

ipv8/messaging/anonymization/tunnelcrypto.py:79

    def decrypt_str(self, content, key, salt):
        # content contains the tag and salt_explicit in plaintext
        if len(content) < 24:
            raise CryptoException("truncated content")

        aead = AEAD(key)
        return aead.decrypt(salt + content, 0)  # ValueError: Failed to decrypt message

[sentry-for-tribler[bot]]

Sentry issue: TRIBLER-7F

[egbertbouman]

When using TunnelCrypto.encrypt_str/decrypt_str manually (i.e., without going through CellPayload), the ValueError should be caught.

Also, in _ours_on_created_extended, the CryptoException should be a ValueError.

[sentry-for-tribler[bot]]

Occurred in 7.11: Sentry issue: TRIBLER-DM

ERROR:TriblerTunnelCommunity:Exception occurred while handling packet!, 
Traceback (most recent call last):, 
  File "ipv8/messaging/anonymization/community.py", line 647, in on_packet_from_circuit, 
  File "ipv8/messaging/anonymization/community.py", line 42, in wrapper, 
  File "tribler_core/components/tunnel/community/tunnel_community.py", line 243, in on_balance_request_cell, 
  File "tribler_core/components/tunnel/community/tunnel_community.py", line 265, in on_balance_request, 
KeyError: 3857729069, 
(Timestamp: 1646452374695, traceback timestamp: 1646448603557), 
ERROR:TriblerTunnelCommunity:Exception occurred while handling packet!, 
Traceback (most recent call last):, 
  File "ipv8/messaging/anonymization/community.py", line 647, in on_packet_from_circuit, 
  File "ipv8/messaging/anonymization/community.py", line 42, in wrapper, 
  File "tribler_core/components/tunnel/community/tunnel_community.py", line 243, in on_balance_request_cell, 
  File "tribler_core/components/tunnel/community/tunnel_community.py", line 265, in on_balance_request, 
KeyError: 3857729069

[qstokkink]

For the most recent traceback, the tunnel_community traceback is a false positive for the core error. The printed tracebacks are not from the Python interpreter, but from a logging statement. This is an excerpt from line 647:

try:
    handler = self.decode_map_private[msg_id]
    result = handler(source_address, data, circuit_id)  # line 647, in on_packet_from_circuit, 
    if iscoroutine(result):
        self.register_anonymous_task('on_packet_from_circuit', ensure_future(result), ignore=(Exception,))
except Exception:
    self.logger.error("Exception occurred while handling packet!\n"
                      + ''.join(format_exception(*sys.exc_info())))

Looking at the timing of events in the Sentry issue, I'd suspect the subprocess | file -b /Applications/Tribler.app/Contents/MacOS/tribler call to have caused this particular crash.

[qstokkink]

@Tribler/dev It seems this original issue has long-since been fixed in https://github.com/Tribler/tribler/pull/5717, neither of the linked Sentry issues still exist, and the cause for reopening this issue was a false positive. Can we close this issue?

[drew2a]

As I'm the current Tribler master this week, I've taken the responsibility to close this issue :)