webrtc-rs / webrtc

A pure Rust implementation of WebRTC
https://webrtc.rs
Apache License 2.0
3.95k stars 347 forks source link

Sometimes negotiation fails #562

Open simbleau opened 2 months ago

simbleau commented 2 months ago

This just started happening recently with matchbox, and there was no change to matchbox. I get this is probably related to a recent webrtc push.

On Chrome, when I connect through matchbox, it sometimes fails, logs:

2024-05-03T23:42:25.561950Z  INFO matchbox_signaling::signaling_server::handlers: `127.0.0.1:61851` connected.
2024-05-03T23:42:25.561986Z  INFO bevy_rtc::server::systems: 127.0.0.1:61851 assigned b2989786-3ee3-4199-bbb1-214ad170cf3e
2024-05-03T23:42:25.562124Z  INFO matchbox_signaling::signaling_server::handlers: b2989786-3ee3-4199-bbb1-214ad170cf3e -> {"IdAssigned":"b2989786-3ee3-4199-bbb1-214ad170cf3e"}
2024-05-03T23:42:25.562139Z  INFO bevy_rtc::server::systems: Client joined: b2989786-3ee3-4199-bbb1-214ad170cf3e
2024-05-03T23:42:25.563147Z  INFO log: mDNS is using 0.0.0.0:5353 as dest_addr    
2024-05-03T23:42:25.563311Z  INFO log: Looping and listening Ok(0.0.0.0:5353)    
2024-05-03T23:42:25.563640Z  INFO log: signaling state changed to have-local-offer    
2024-05-03T23:42:25.563825Z  WARN log: [controlled]: could not listen udp fe80::9b19:da11:32a:7d29: io error: Can't assign requested address (os error 49)    
2024-05-03T23:42:25.563860Z  WARN log: [controlled]: could not listen udp fe80::1: io error: Can't assign requested address (os error 49)    
2024-05-03T23:42:25.563877Z  WARN log: [controlled]: could not listen udp fe80::bc76:eff:fe41:c14a: io error: Can't assign requested address (os error 49)    
2024-05-03T23:42:25.563893Z  WARN log: [controlled]: could not listen udp fe80::ce81:b1c:bd2c:69e: io error: Can't assign requested address (os error 49)    
2024-05-03T23:42:25.563908Z  WARN log: [controlled]: could not listen udp fe80::10b9:2cff:fe63:f1cf: io error: Can't assign requested address (os error 49)    
2024-05-03T23:42:25.563924Z  WARN log: [controlled]: could not listen udp fe80::3912:4d94:598b:327c: io error: Can't assign requested address (os error 49)    
2024-05-03T23:42:25.563939Z  WARN log: [controlled]: could not listen udp fe80::81c:49a5:f765:a4c: io error: Can't assign requested address (os error 49)    
2024-05-03T23:42:25.564054Z  WARN log: [controlled]: could not listen udp fe80::4939:ddd:4b5f:5c18: io error: Can't assign requested address (os error 49)    
2024-05-03T23:42:25.564074Z  WARN log: [controlled]: could not listen udp fe80::fa13:6804:a39b:1b43: io error: Can't assign requested address (os error 49)    
2024-05-03T23:42:25.564091Z  WARN log: [controlled]: could not listen udp fe80::ec6c:289e:274a:f79b: io error: Can't assign requested address (os error 49)    
2024-05-03T23:42:25.564293Z  WARN log: [controlled]: could not listen udp fe80::5cbb:88ff:fef3:51b1: io error: Can't assign requested address (os error 49)    
2024-05-03T23:42:25.564312Z  WARN log: [controlled]: could not listen udp fe80::531a:8a73:6e04:c06d: io error: Can't assign requested address (os error 49)    
2024-05-03T23:42:25.564329Z  WARN log: [controlled]: could not listen udp fe80::951d:e2d8:b0fa:2948: io error: Can't assign requested address (os error 49)    
2024-05-03T23:42:25.564346Z  WARN log: [controlled]: could not listen udp fe80::c88:a6ff:fefe:1fdf: io error: Can't assign requested address (os error 49)    
2024-05-03T23:42:25.564362Z  WARN log: [controlled]: could not listen udp fe80::1d78:c95f:b04e:d1fe: io error: Can't assign requested address (os error 49)    
2024-05-03T23:42:25.564380Z  WARN log: [controlled]: could not listen udp fe80::4afb:bfcf:8f0b:74fd: io error: Can't assign requested address (os error 49)    
2024-05-03T23:42:25.572205Z  WARN log: [controlled]: failed to resolve stun host: stun1.l.google.com:19302: io error: No available ipv6 IP address found!    
2024-05-03T23:42:25.572240Z  WARN log: [controlled]: failed to resolve stun host: stun.l.google.com:19302: io error: No available ipv6 IP address found!

(end of output)

Other times, It works fine, and here's what that stack looks like.


2024-05-03T23:46:54.364256Z  INFO matchbox_signaling::signaling_server::handlers: `127.0.0.1:62967` connected.
2024-05-03T23:46:54.364325Z  INFO bevy_rtc::server::systems: 127.0.0.1:62967 assigned b6b22df6-d86f-4b88-8212-2dfbcaf09a70
2024-05-03T23:46:54.364764Z  INFO matchbox_signaling::signaling_server::handlers: b6b22df6-d86f-4b88-8212-2dfbcaf09a70 -> {"IdAssigned":"b6b22df6-d86f-4b88-8212-2dfbcaf09a70"}
2024-05-03T23:46:54.364816Z  INFO bevy_rtc::server::systems: Host ready: b6b22df6-d86f-4b88-8212-2dfbcaf09a70
2024-05-03T23:46:54.364822Z  INFO bevy_rtc::server::systems: Ready for clients (broadcasting on 0.0.0.0:3536)
2024-05-03T23:46:57.473407Z  INFO matchbox_signaling::signaling_server::handlers: `127.0.0.1:62981` connected.
2024-05-03T23:46:57.473446Z  INFO bevy_rtc::server::systems: 127.0.0.1:62981 assigned de7bb88f-e780-4074-8430-dbe9875736da
2024-05-03T23:46:57.473574Z  INFO matchbox_signaling::signaling_server::handlers: de7bb88f-e780-4074-8430-dbe9875736da -> {"IdAssigned":"de7bb88f-e780-4074-8430-dbe9875736da"}
2024-05-03T23:46:57.473608Z  INFO bevy_rtc::server::systems: Client joined: de7bb88f-e780-4074-8430-dbe9875736da
2024-05-03T23:46:57.477490Z  INFO log: mDNS is using 0.0.0.0:5353 as dest_addr    
2024-05-03T23:46:57.477852Z  INFO log: Looping and listening Ok(0.0.0.0:5353)    
2024-05-03T23:46:57.478833Z  INFO log: signaling state changed to have-local-offer    
2024-05-03T23:46:57.479157Z  WARN log: [controlled]: could not listen udp fe80::ce81:b1c:bd2c:69e: io error: Can't assign requested address (os error 49)    
2024-05-03T23:46:57.479198Z  WARN log: [controlled]: could not listen udp fe80::3912:4d94:598b:327c: io error: Can't assign requested address (os error 49)    
2024-05-03T23:46:57.479306Z  WARN log: [controlled]: could not listen udp fe80::531a:8a73:6e04:c06d: io error: Can't assign requested address (os error 49)    
2024-05-03T23:46:57.479326Z  WARN log: [controlled]: could not listen udp fe80::181e:9aff:feff:7d52: io error: Can't assign requested address (os error 49)    
2024-05-03T23:46:57.479765Z  WARN log: [controlled]: could not listen udp fe80::bc76:eff:fe41:c14a: io error: Can't assign requested address (os error 49)    
2024-05-03T23:46:57.479789Z  WARN log: [controlled]: could not listen udp fe80::10b9:2cff:fe63:f1cf: io error: Can't assign requested address (os error 49)    
2024-05-03T23:46:57.479808Z  WARN log: [controlled]: could not listen udp fe80::ec6c:289e:274a:f79b: io error: Can't assign requested address (os error 49)    
2024-05-03T23:46:57.479827Z  WARN log: [controlled]: could not listen udp fe80::81c:49a5:f765:a4c: io error: Can't assign requested address (os error 49)    
2024-05-03T23:46:57.479846Z  WARN log: [controlled]: could not listen udp fe80::1d78:c95f:b04e:d1fe: io error: Can't assign requested address (os error 49)    
2024-05-03T23:46:57.479865Z  WARN log: [controlled]: could not listen udp fe80::fa13:6804:a39b:1b43: io error: Can't assign requested address (os error 49)    
2024-05-03T23:46:57.479884Z  WARN log: [controlled]: could not listen udp fe80::4939:ddd:4b5f:5c18: io error: Can't assign requested address (os error 49)    
2024-05-03T23:46:57.479904Z  WARN log: [controlled]: could not listen udp fe80::951d:e2d8:b0fa:2948: io error: Can't assign requested address (os error 49)    
2024-05-03T23:46:57.479922Z  WARN log: [controlled]: could not listen udp fe80::1: io error: Can't assign requested address (os error 49)    
2024-05-03T23:46:57.479936Z  WARN log: [controlled]: could not listen udp fe80::9b19:da11:32a:7d29: io error: Can't assign requested address (os error 49)    
2024-05-03T23:46:57.479951Z  WARN log: [controlled]: could not listen udp fe80::4afb:bfcf:8f0b:74fd: io error: Can't assign requested address (os error 49)    
2024-05-03T23:46:57.479965Z  WARN log: [controlled]: could not listen udp fe80::5cbb:88ff:fef3:51b1: io error: Can't assign requested address (os error 49)    
2024-05-03T23:46:57.489198Z  WARN log: [controlled]: failed to resolve stun host: stun.l.google.com:19302: io error: No available ipv6 IP address found!    
2024-05-03T23:46:57.489687Z  WARN log: [controlled]: failed to resolve stun host: stun1.l.google.com:19302: io error: No available ipv6 IP address found!    
2024-05-03T23:46:57.911135Z  INFO log: signaling state changed to stable    
2024-05-03T23:46:57.911571Z  INFO log: [controlling]: Setting new connection state: Checking    
2024-05-03T23:46:57.911672Z  INFO log: ICE connection state changed: checking    
2024-05-03T23:46:57.912367Z  INFO log: Received query result    
2024-05-03T23:46:57.913000Z  WARN log: [controlling]: discard success message from (172.20.11.10:52948), no such remote    
2024-05-03T23:46:59.027702Z  INFO log: [controlling]: Setting new connection state: Connected    
2024-05-03T23:46:59.027778Z  INFO log: ICE connection state changed: connected    
2024-05-03T23:46:59.028654Z  WARN log: Unsupported Extension Type 0 35    
2024-05-03T23:46:59.028707Z  WARN log: Unsupported Extension Type 0 35    
2024-05-03T23:46:59.029027Z  WARN log: Unsupported Extension Type 0 35    
2024-05-03T23:46:59.029083Z  WARN log: Unsupported Extension Type 0 35    
2024-05-03T23:46:59.029295Z  WARN log: Unsupported Extension Type 0 35    
2024-05-03T23:46:59.029325Z  WARN log: Unsupported Extension Type 0 35    
2024-05-03T23:46:59.029413Z  WARN log: Unsupported Extension Type 0 35    
2024-05-03T23:46:59.029437Z  WARN log: Unsupported Extension Type 0 35    
2024-05-03T23:46:59.029512Z  WARN log: Unsupported Extension Type 0 35    
2024-05-03T23:46:59.029535Z  WARN log: Unsupported Extension Type 0 35    
2024-05-03T23:46:59.029666Z  WARN log: Unsupported Extension Type 0 35    
2024-05-03T23:46:59.029697Z  WARN log: Unsupported Extension Type 0 35    
2024-05-03T23:46:59.032549Z  INFO log: peer connection state changed: connected