Tons of "Failed to decrypt and verify packet"

[Etienne Dechamps]

Yes, most definitely. This "Failed to decrypt and verify packet" message 
can be caused by node UDP addresses getting messed up (because then tinc 
tries to decrypt their packets using the wrong key), which is precisely 
what b54fde67 fixes. This is definitely it, and in fact you nailed it in 
your message when you said "I'd rather think tinc uses the wrong key to 
decrypt": this is exactly what's happening.

You will hit the issue nearly every time tinc receives an UDP packet 
from an address/port it doesn't know (which often happens when NATs are 
involved, or when using local discovery). Note that when this happens 
UDP addresses for *other nodes* get corrupted, which quickly causes the 
chaos you're seeing.

I had the exact same issue as you while testing my LocalDiscovery 
changes, which is why I decided to fix it, and the result is b54fde67 
which is the clean fix. Sorry for the bad timing :)

On 01/07/2014 20:02, Julien Muchembled wrote:
> tl;dr Wow it's just when I've finished all the below debugging, and just before sending this email that git fetches new commits by Etienne. Now I'm unable to reproduce the issue. What commit would have fixed it ? b54fde67 (Implement sptps_verify_datagram) ?
>
> Le 04/07/14 21:58, Guus Sliepen a écrit :
>> On Mon, Apr 07, 2014 at 02:36:10AM +0200, Julien Muchembled wrote:
>>
>>> So I continued to bisect.
>>> Commit 0da0728 ("Use AES-256-GCM for the SPTPS protocol") is really the first bad commit.
>>
>> Not unexpected. Thanks for doing the bisection!
>
> The bug reported by many Windows users seemed to be the same but now I see mails saying the issue would be solved for some people. I've just tested again with a recent 1.1 commit (762db91) and I can still reproduce the issue, so I'm still stuck with 1.1pre9
>
> I tried to see if it could be an environment issue by running my testcase in a fresh install of Debian Sid, and now I am in front of the most strange bug I've even seen.
> I am unable to reproduce the bug in a chroot whereas the tinc binaries and all accessed files are exactly the same: I used strace to list of disk accesses (and for libraries, I downgraded a few packages to match the host).
> I have no idea anymore about what could be different between the host and the chroot, so I'll have to give up this approach. This also means I can't provide a VM so someone else could reproduce the bug.
>
> Then, I started to add logs in chacha_poly1305. What I found is that the encrypted messages are not corrupted: the data to be decrypted was really sent by another node, but the keys differs. I didn't check but I doubt it's corruption of the context on either side. I'd rather think tinc uses the wrong key to decrypt: one reason could that tinc fails to identify the sender.
>
> Next, I looked at closer tinc logs of a failure, with microseconds like those I posted on the ML.
> In the testcase, nodes are configured as follows:
>    n1 port 32573
>    n2 port 32574
>    n3 port 32575
>    n4 port 32576
> And in logs:
> 19.990549 Sending REQ_KEY to n1 (127.0.0.1 port 32573): 15 n2 n1 21 AAAAI4I5PcXYYHVLAMmSB9i/QlfZk1KW4vslBjUFMOWz/fTfQhW/Vwn56946EnXsXsAVrC8LRnSJQcD2j71oM6MmeioRwRp8jIQEqjd0SEjqIFWPll0dhprV3kLa6QFg3BjCTt/XKXd+
> 19.990549 Sending 153 bytes of metadata to n1 (127.0.0.1 port 32573)
> 20.510251 UDP address of n4 set to 127.0.0.1 port 32573
> 20.510251 Failed to decrypt and verify packet
> 20.510397 UDP address of n4 set to 127.0.0.1 port 32576
> 20.510397 Got MTU probe request 803 from n4 (127.0.0.1 port 32576)
> 20.754989 Got MTU probe request 434 from n4 (127.0.0.1 port 32576)
>
> 'Failed to decrypt and verify packet' lines always follows a wrong match of node & udp port. Other examples:
> 22.867526 Sending MTU probe length 1509 to n4 (127.0.0.1 port 32573)
> 22.867526 UDP address of n4 set to 127.0.0.1 port 32576
> 22.867526 Got MTU probe request 1496 from n4 (127.0.0.1 port 32576)
> 22.887972 Got MTU probe request 1352 from n4 (127.0.0.1 port 32576)
> 22.888209 Got MTU probe request 1404 from n4 (127.0.0.1 port 32576)
> 23.059937 Sending MTU probe length 219 to n1 (127.0.0.1 port 32573)
> 23.059937 Sending MTU probe length 560 to n1 (127.0.0.1 port 32573)
> 23.059937 Sending MTU probe length 595 to n1 (127.0.0.1 port 32573)
> 23.059937 UDP address of n4 set to 127.0.0.1 port 32573
> 23.059937 Failed to decrypt and verify packet
> 23.060306 Failed to decrypt and verify packet
> 23.060321 Failed to decrypt and verify packet
> 23.060368 Failed to decrypt and verify packet
> 23.077170 Failed to decrypt and verify packet
> 23.077221 Failed to decrypt and verify packet
>


-- 
Etienne Dechamps