Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Ensure all INIT have a verification tag of 0 as per the spec #341

Open
wants to merge 1 commit into
base: master
Choose a base branch
from

Conversation

jmelancongen
Copy link

Description

We've been seeing issues with one of our tests that sometime hangs while opening a DataChannel between two peers. Looking at the detailed logs we've been seeing this pattern:

[Producer] sending INIT
[Consumer] failed validating packet init chunk expects a verification tag of 0 on the packet when out-of-the-blue
[Consumer] sending INIT
[Producer] failed validating packet init chunk expects a verification tag of 0 on the packet when out-of-the-blue
...2 seconds pause...
[Producer] sending INIT
[Consumer] failed validating packet init chunk expects a verification tag of 0 on the packet when out-of-the-blue
[Consumer] sending INIT
[Producer] failed validating packet init chunk expects a verification tag of 0 on the packet when out-of-the-blue

and the data channel never opens

We've found out that there is a PR from a year ago in webrtc-rs that seems to fit exactly the issue we are hitting:
webrtc-rs/webrtc#405

Where the fix was to ensure the init packet always uses the 0 tag, instead of using the Association state which might be different? We're just bringing that same fix here.

Copy link

codecov bot commented Jul 10, 2024

Codecov Report

All modified and coverable lines are covered by tests ✅

Project coverage is 81.26%. Comparing base (c3b3847) to head (dbd061d).

Additional details and impacted files
@@            Coverage Diff             @@
##           master     #341      +/-   ##
==========================================
- Coverage   81.32%   81.26%   -0.06%     
==========================================
  Files          51       51              
  Lines        3336     3336              
==========================================
- Hits         2713     2711       -2     
- Misses        479      480       +1     
- Partials      144      145       +1     
Flag Coverage Δ
go 81.26% <100.00%> (-0.06%) ⬇️
wasm 68.55% <100.00%> (+1.13%) ⬆️

Flags with carried forward coverage won't be shown. Click here to find out more.

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

@Sean-Der
Copy link
Member

Sean-Der commented Jul 10, 2024

@jmelancongen Is this Pion on both sides when you see this happen? I would like to create a reproduce (I can help with that!)

Thank you so much for sending this PR over!

@jmelancongen
Copy link
Author

I agree a reproducer or test would be nice. In the scenario where we are seeing this it is Pion on both sides so it should be doable. The specific test we are doing is a validation of our TURN provider, and I'm guessing the fact that there is a real network is important, I'm suspecting a specific packet being lost at the wrong moment during the initialization. I was lucky to find the webrtc-rs PR early so I haven't looked too deeply in the entire interaction, but we'll assemble the complete logs from the test and post them here and take a deeper look into it!

@jmelancongen
Copy link
Author

Here is the SCTP handshake part of our test: sctp-handshake-hang.txt

From what I was told, the test runs every minute in multiple locations, and it reproduces the issue once every 2-3 weeks globally. I've boiled down the logs to these bits:

[00:10:46.9180-Dbg] [producer] [0xc0002401e0] sending INIT
[00:10:46.9631-Dbg] [consumer] [0xc0002723c0] sending INIT
[00:10:46.9632-Dbg] [consumer] [0xc0002723c0] chunkInit received in state 'CookieWait'
[00:10:46.9632-Dbg] [consumer] sending INIT ACK
[00:10:47.0227-Dbg] [producer] [0xc0002401e0] chunkInit received in state 'CookieWait'
[00:10:47.0227-Dbg] [producer] sending INIT ACK
[00:10:47.9187-Dbg] [producer] [0xc0002401e0] sending INIT
[00:10:47.9491-Wrn] [consumer] [0xc0002723c0] failed validating packet init chunk expects a verification tag of 0 on the packet when out-of-the-blue
[00:10:47.9632-Dbg] [consumer] [0xc0002723c0] sending INIT
[00:10:47.9954-Wrn] [producer] [0xc0002401e0] failed validating packet init chunk expects a verification tag of 0 on the packet when out-of-the-blue

I believe the specific problem stems from:

  • High enough latency that both sides send their INIT before receiving the other side
  • Both sides receive the INIT of the other
  • Both INIT ACK are lost

I'm not too sure how to isolate those conditions in a smaller self-contained reproducer though. Since it feels like it needs the relay to be triggered. I'm also not very familiar with the testing framework for pion sadly, but it might be easier to reproduce this way?

@Sean-Der
Copy link
Member

Fantastic! I can write a test for that today, that will be pretty easy to reproduce.

@jmelancongen
Copy link
Author

Sorry for the ping but did you have time to check on that? I'd would love to have the fix so we can remove a workaround on our side

RFC 4960 Section 8.5.1 specifies that a packet containing an INIT
chunk MUST set the verificate tag of the packet to 0.

The current code follows that only if it has not received and
handled an INIT packet from the peer yet. In which case the
peerVerificationTag will not be zero, and any subsequent INIT will be
invalid and refused by the peer. This is a problem if the INIT ACK was
lost.

If both peers have this behavior, and both INIT ACKs were lost, we
fall into a situation where the initialization will never complete.

Resolve this scenario by ensuring the packet with the INIT chunk
always set the tag to zero, as is required.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants