matchbox icon indicating copy to clipboard operation
matchbox copied to clipboard

Published 20 hours ago • verified publisher icon johanhelsing

Connections fail if Firefox peer connects after native peers on local network

Open johanhelsing opened this issue 8 months ago • 4 comments

Cross-play appears to be broken in this very specific case.

To reproduce:

  1. Start signaling: cargo run -p matchbox_server
  2. Run native client: cargo run -p bevy_ggrs_example
  3. Run Firefox client: cargo run -p bevy_ggrs_example --target wasm32-unknown-unknown and open http://127.0.0.1:1334 in Firefox

Connection is never established.

Environment

  • Windows 11
  • Firefox 119.0

Tested revisions

  • main (1a2b5e88)

Additional details

It doesn't happen with Native and Chrome on the same system.

It doesn't happen if the browser connects to the signaling server first.

Both peers were on the same local network, behind NAT. Connections were sucessful happen when connecting to a native peer outside the NAT.

Logs

Firefox

INFO C:\Users\Johan\.cargo\registry\src\index.crates.io-6f17d22bba15001f\bevy_winit-0.11.3\src\system.rs:51 Creating new window "App" (0v0) [wasm.js:433:9](http://127.0.0.1:1334/api/wasm.js)
WEBGL_debug_renderer_info is deprecated in Firefox and will be removed. Please use RENDERER. [wasm.js:808:18](http://127.0.0.1:1334/api/wasm.js)
INFO C:\Users\Johan\.cargo\registry\src\index.crates.io-6f17d22bba15001f\bevy_render-0.11.3\src\renderer\mod.rs:133 AdapterInfo { name: "ANGLE (NVIDIA, NVIDIA GeForce GTX 980 Direct3D11 vs_5_0 ps_5_0)", vendor: 4318, device: 0, device_type: Other, driver: "", driver_info: "", backend: Gl } [wasm.js:433:9](http://127.0.0.1:1334/api/wasm.js)
WARN C:\Users\Johan\.cargo\registry\src\index.crates.io-6f17d22bba15001f\bevy_pbr-0.11.3\src\ssao\mod.rs:98 ScreenSpaceAmbientOcclusionPlugin not loaded. GPU lacks support: TextureFormat::R16Float does not support TextureUsages::STORAGE_BINDING. [wasm.js:433:9](http://127.0.0.1:1334/api/wasm.js)
INFO examples\bevy_ggrs\src\main.rs:82 connecting to matchbox server: "ws://127.0.0.1:3536/bevy_ggrs?next=2" [wasm.js:433:9](http://127.0.0.1:1334/api/wasm.js)
DEBUG  Starting WebRtcSocket log.target = "matchbox_socket::webrtc_socket::socket";
log.module_path = "matchbox_socket::webrtc_socket::socket";
log.file = "matchbox_socket\\src\\webrtc_socket\\socket.rs";
log.line = 653; [wasm.js:433:9](http://127.0.0.1:1334/api/wasm.js)
Uncaught (in promise) Error: Using exceptions for control flow, don't mind me. This isn't actually an error!
    __wbindgen_throw http://127.0.0.1:1334/api/wasm.js:1909
    __wbg_finalize_init http://127.0.0.1:1334/api/wasm.js:2002
    __wbg_init http://127.0.0.1:1334/api/wasm.js:2036
[wasm.js:1909:7](http://127.0.0.1:1334/api/wasm.js)
DEBUG  Received {"IdAssigned":"e0e9a2aa-620b-4cb9-be14-e7ee91e0f4eb"} log.target = "matchbox_socket::webrtc_socket";
log.module_path = "matchbox_socket::webrtc_socket";
log.file = "matchbox_socket\\src\\webrtc_socket\\mod.rs";
log.line = 71; [wasm.js:433:9](http://127.0.0.1:1334/api/wasm.js)
DEBUG  IdAssigned(PeerId(e0e9a2aa-620b-4cb9-be14-e7ee91e0f4eb)) log.target = "matchbox_socket::webrtc_socket";
log.module_path = "matchbox_socket::webrtc_socket";
log.file = "matchbox_socket\\src\\webrtc_socket\\mod.rs";
log.line = 189; [wasm.js:433:9](http://127.0.0.1:1334/api/wasm.js)
WARN C:\Users\Johan\.cargo\registry\src\index.crates.io-6f17d22bba15001f\bevy_asset-0.11.3\src\asset_server.rs:534 encountered an error while loading an asset: InvalidFont [wasm.js:433:9](http://127.0.0.1:1334/api/wasm.js)
DEBUG  Received {"Signal":{"sender":"3c88baa0-1460-451b-a7ad-7a1c759802fa","data":{"Offer":"v=0\r\no=- 8519950814743650138 303764200 IN IP4 0.0.0.0\r\ns=-\r\nt=0 0\r\na=fingerprint:sha-256 9F:ED:05:91:0D:E7:CF:95:31:6C:7D:45:5E:1E:6B:32:B8:70:BB:45:66:DE:48:70:4D:75:61:4F:54:72:38:DB\r\na=group:BUNDLE 0\r\nm=application 9 UDP/DTLS/SCTP webrtc-datachannel\r\nc=IN IP4 0.0.0.0\r\na=setup:actpass\r\na=mid:0\r\na=sendrecv\r\na=sctp-port:5000\r\na=ice-ufrag:xzMqOOrhKOIRZMWT\r\na=ice-pwd:jXApNcgxcZUmmEAnsblGBdXhaUdHeVcp\r\n"}}} log.target = "matchbox_socket::webrtc_socket";
log.module_path = "matchbox_socket::webrtc_socket";
log.file = "matchbox_socket\\src\\webrtc_socket\\mod.rs";
log.line = 71; [wasm.js:433:9](http://127.0.0.1:1334/api/wasm.js)
DEBUG  Signal { sender: PeerId(3c88baa0-1460-451b-a7ad-7a1c759802fa), data: Offer("v=0\r\no=- 8519950814743650138 303764200 IN IP4 0.0.0.0\r\ns=-\r\nt=0 0\r\na=fingerprint:sha-256 9F:ED:05:91:0D:E7:CF:95:31:6C:7D:45:5E:1E:6B:32:B8:70:BB:45:66:DE:48:70:4D:75:61:4F:54:72:38:DB\r\na=group:BUNDLE 0\r\nm=application 9 UDP/DTLS/SCTP webrtc-datachannel\r\nc=IN IP4 0.0.0.0\r\na=setup:actpass\r\na=mid:0\r\na=sendrecv\r\na=sctp-port:5000\r\na=ice-ufrag:xzMqOOrhKOIRZMWT\r\na=ice-pwd:jXApNcgxcZUmmEAnsblGBdXhaUdHeVcp\r\n") } log.target = "matchbox_socket::webrtc_socket";
log.module_path = "matchbox_socket::webrtc_socket";
log.file = "matchbox_socket\\src\\webrtc_socket\\mod.rs";
log.line = 189; [wasm.js:433:9](http://127.0.0.1:1334/api/wasm.js)
DEBUG  handshake_accept log.target = "matchbox_socket::webrtc_socket::wasm";
log.module_path = "matchbox_socket::webrtc_socket::wasm";
log.file = "matchbox_socket\\src\\webrtc_socket\\wasm.rs";
log.line = 194; [wasm.js:433:9](http://127.0.0.1:1334/api/wasm.js)
DEBUG  received offer log.target = "matchbox_socket::webrtc_socket::wasm";
log.module_path = "matchbox_socket::webrtc_socket::wasm";
log.file = "matchbox_socket\\src\\webrtc_socket\\wasm.rs";
log.line = 233; [wasm.js:433:9](http://127.0.0.1:1334/api/wasm.js)
DEBUG  set remote_description from offer log.target = "matchbox_socket::webrtc_socket::wasm";
log.module_path = "matchbox_socket::webrtc_socket::wasm";
log.file = "matchbox_socket\\src\\webrtc_socket\\wasm.rs";
log.line = 243; [wasm.js:433:9](http://127.0.0.1:1334/api/wasm.js)
DEBUG  created answer log.target = "matchbox_socket::webrtc_socket::wasm";
log.module_path = "matchbox_socket::webrtc_socket::wasm";
log.file = "matchbox_socket\\src\\webrtc_socket\\wasm.rs";
log.line = 250; [wasm.js:433:9](http://127.0.0.1:1334/api/wasm.js)
DEBUG  Ice gathering completed log.target = "matchbox_socket::webrtc_socket::wasm";
log.module_path = "matchbox_socket::webrtc_socket::wasm";
log.file = "matchbox_socket\\src\\webrtc_socket\\wasm.rs";
log.line = 450; [wasm.js:433:9](http://127.0.0.1:1334/api/wasm.js)
DEBUG  waiting for data channels to open log.target = "matchbox_socket::webrtc_socket::wasm";
log.module_path = "matchbox_socket::webrtc_socket::wasm";
log.file = "matchbox_socket\\src\\webrtc_socket\\wasm.rs";
log.line = 335; [wasm.js:433:9](http://127.0.0.1:1334/api/wasm.js)
DEBUG  -> {"Signal":{"receiver":"3c88baa0-1460-451b-a7ad-7a1c759802fa","data":{"Answer":"v=0\r\no=mozilla...THIS_IS_SDPARTA-99.0 5148800727462569654 0 IN IP4 0.0.0.0\r\ns=-\r\nt=0 0\r\na=sendrecv\r\na=fingerprint:sha-256 95:9F:6D:17:A0:CD:4B:D8:8E:5F:EE:36:54:E2:89:4C:78:17:26:E0:E2:27:50:6D:93:A7:93:3C:78:D6:E7:FA\r\na=group:BUNDLE 0\r\na=ice-options:trickle\r\na=msid-semantic:WMS *\r\nm=application 53987 UDP/DTLS/SCTP webrtc-datachannel\r\nc=IN IP4 89.10.87.54\r\na=candidate:0 1 UDP 2122187007 ab262a74-5a98-4288-a132-b40d75613cbb.local 53987 typ host\r\na=candidate:2 1 UDP 2122252543 da201c88-6abc-46a3-9af7-ed16f91dfc09.local 53988 typ host\r\na=candidate:4 1 TCP 2105458943 ab262a74-5a98-4288-a132-b40d75613cbb.local 9 typ host tcptype active\r\na=candidate:5 1 TCP 2105524479 da201c88-6abc-46a3-9af7-ed16f91dfc09.local 9 typ host tcptype active\r\na=candidate:1 1 UDP 1685987327 89.10.87.54 53987 typ srflx raddr 0.0.0.0 rport 0\r\na=sendrecv\r\na=end-of-candidates\r\na=ice-pwd:da3132e0f5b7c2775a510574b5767931\r\na=ice-ufrag:d5898e91\r\na=mid:0\r\na=setup:active\r\na=sctp-port:5000\r\na=max-message-size:1073741823\r\n"}}} log.target = "matchbox_socket::webrtc_socket";
log.module_path = "matchbox_socket::webrtc_socket";
log.file = "matchbox_socket\\src\\webrtc_socket\\mod.rs";
log.line = 64; [wasm.js:433:9](http://127.0.0.1:1334/api/wasm.js)
DEBUG  Received {"Signal":{"sender":"3c88baa0-1460-451b-a7ad-7a1c759802fa","data":{"IceCandidate":"{\"candidate\":\"candidate:201166800 1 udp 2130706431 192.168.1.136 60356 typ host\",\"sdpMid\":\"\",\"sdpMLineIndex\":0,\"usernameFragment\":null}"}}} log.target = "matchbox_socket::webrtc_socket";
log.module_path = "matchbox_socket::webrtc_socket";
log.file = "matchbox_socket\\src\\webrtc_socket\\mod.rs";
log.line = 71; [wasm.js:433:9](http://127.0.0.1:1334/api/wasm.js)
DEBUG  Signal { sender: PeerId(3c88baa0-1460-451b-a7ad-7a1c759802fa), data: IceCandidate("{\"candidate\":\"candidate:201166800 1 udp 2130706431 192.168.1.136 60356 typ host\",\"sdpMid\":\"\",\"sdpMLineIndex\":0,\"usernameFragment\":null}") } log.target = "matchbox_socket::webrtc_socket";
log.module_path = "matchbox_socket::webrtc_socket";
log.file = "matchbox_socket\\src\\webrtc_socket\\mod.rs";
log.line = 189; [wasm.js:433:9](http://127.0.0.1:1334/api/wasm.js)
DEBUG  ice candidate received: RtcIceCandidateInit { obj: Object { obj: JsValue(Object({"candidate":"candidate:201166800 1 udp 2130706431 192.168.1.136 60356 typ host","sdpMid":"","sdpMLineIndex":0,"usernameFragment":null})) } } log.target = "matchbox_socket::webrtc_socket::wasm";
log.module_path = "matchbox_socket::webrtc_socket::wasm";
log.file = "matchbox_socket\\src\\webrtc_socket\\wasm.rs";
log.line = 382; [wasm.js:433:9](http://127.0.0.1:1334/api/wasm.js)
DEBUG  Received {"Signal":{"sender":"3c88baa0-1460-451b-a7ad-7a1c759802fa","data":{"IceCandidate":"{\"candidate\":\"candidate:2187365727 1 udp 2130706431 172.26.80.1 60357 typ host\",\"sdpMid\":\"\",\"sdpMLineIndex\":0,\"usernameFragment\":null}"}}} log.target = "matchbox_socket::webrtc_socket";
log.module_path = "matchbox_socket::webrtc_socket";
log.file = "matchbox_socket\\src\\webrtc_socket\\mod.rs";
log.line = 71; [wasm.js:433:9](http://127.0.0.1:1334/api/wasm.js)
DEBUG  Signal { sender: PeerId(3c88baa0-1460-451b-a7ad-7a1c759802fa), data: IceCandidate("{\"candidate\":\"candidate:2187365727 1 udp 2130706431 172.26.80.1 60357 typ host\",\"sdpMid\":\"\",\"sdpMLineIndex\":0,\"usernameFragment\":null}") } log.target = "matchbox_socket::webrtc_socket";
log.module_path = "matchbox_socket::webrtc_socket";
log.file = "matchbox_socket\\src\\webrtc_socket\\mod.rs";
log.line = 189; [wasm.js:433:9](http://127.0.0.1:1334/api/wasm.js)
DEBUG  ice candidate received: RtcIceCandidateInit { obj: Object { obj: JsValue(Object({"candidate":"candidate:2187365727 1 udp 2130706431 172.26.80.1 60357 typ host","sdpMid":"","sdpMLineIndex":0,"usernameFragment":null})) } } log.target = "matchbox_socket::webrtc_socket::wasm";
log.module_path = "matchbox_socket::webrtc_socket::wasm";
log.file = "matchbox_socket\\src\\webrtc_socket\\wasm.rs";
log.line = 382; [wasm.js:433:9](http://127.0.0.1:1334/api/wasm.js)
DEBUG  Received {"Signal":{"sender":"3c88baa0-1460-451b-a7ad-7a1c759802fa","data":{"IceCandidate":"{\"candidate\":\"candidate:2296203666 1 udp 2130706431 172.20.224.1 60358 typ host\",\"sdpMid\":\"\",\"sdpMLineIndex\":0,\"usernameFragment\":null}"}}} log.target = "matchbox_socket::webrtc_socket";
log.module_path = "matchbox_socket::webrtc_socket";
log.file = "matchbox_socket\\src\\webrtc_socket\\mod.rs";
log.line = 71; [wasm.js:433:9](http://127.0.0.1:1334/api/wasm.js)
DEBUG  Signal { sender: PeerId(3c88baa0-1460-451b-a7ad-7a1c759802fa), data: IceCandidate("{\"candidate\":\"candidate:2296203666 1 udp 2130706431 172.20.224.1 60358 typ host\",\"sdpMid\":\"\",\"sdpMLineIndex\":0,\"usernameFragment\":null}") } log.target = "matchbox_socket::webrtc_socket";
log.module_path = "matchbox_socket::webrtc_socket";
log.file = "matchbox_socket\\src\\webrtc_socket\\mod.rs";
log.line = 189; [wasm.js:433:9](http://127.0.0.1:1334/api/wasm.js)
DEBUG  Received {"Signal":{"sender":"3c88baa0-1460-451b-a7ad-7a1c759802fa","data":{"IceCandidate":"{\"candidate\":\"candidate:2724628134 1 udp 1694498815 89.10.87.54 53983 typ srflx raddr 0.0.0.0 rport 53983\",\"sdpMid\":\"\",\"sdpMLineIndex\":0,\"usernameFragment\":null}"}}} log.target = "matchbox_socket::webrtc_socket";
log.module_path = "matchbox_socket::webrtc_socket";
log.file = "matchbox_socket\\src\\webrtc_socket\\mod.rs";
log.line = 71; [wasm.js:433:9](http://127.0.0.1:1334/api/wasm.js)
DEBUG  Signal { sender: PeerId(3c88baa0-1460-451b-a7ad-7a1c759802fa), data: IceCandidate("{\"candidate\":\"candidate:2724628134 1 udp 1694498815 89.10.87.54 53983 typ srflx raddr 0.0.0.0 rport 53983\",\"sdpMid\":\"\",\"sdpMLineIndex\":0,\"usernameFragment\":null}") } log.target = "matchbox_socket::webrtc_socket";
log.module_path = "matchbox_socket::webrtc_socket";
log.file = "matchbox_socket\\src\\webrtc_socket\\mod.rs";
log.line = 189; [wasm.js:433:9](http://127.0.0.1:1334/api/wasm.js)
DEBUG  Received {"Signal":{"sender":"3c88baa0-1460-451b-a7ad-7a1c759802fa","data":{"IceCandidate":"{\"candidate\":\"candidate:2724628134 1 udp 1694498815 89.10.87.54 53984 typ srflx raddr 0.0.0.0 rport 53984\",\"sdpMid\":\"\",\"sdpMLineIndex\":0,\"usernameFragment\":null}"}}} log.target = "matchbox_socket::webrtc_socket";
log.module_path = "matchbox_socket::webrtc_socket";
log.file = "matchbox_socket\\src\\webrtc_socket\\mod.rs";
log.line = 71; [wasm.js:433:9](http://127.0.0.1:1334/api/wasm.js)
DEBUG  Signal { sender: PeerId(3c88baa0-1460-451b-a7ad-7a1c759802fa), data: IceCandidate("{\"candidate\":\"candidate:2724628134 1 udp 1694498815 89.10.87.54 53984 typ srflx raddr 0.0.0.0 rport 53984\",\"sdpMid\":\"\",\"sdpMLineIndex\":0,\"usernameFragment\":null}") } log.target = "matchbox_socket::webrtc_socket";
log.module_path = "matchbox_socket::webrtc_socket";
log.file = "matchbox_socket\\src\\webrtc_socket\\mod.rs";
log.line = 189; [wasm.js:433:9](http://127.0.0.1:1334/api/wasm.js)
DEBUG  ice connection state changed: Checking log.target = "matchbox_socket::webrtc_socket::wasm";
log.module_path = "matchbox_socket::webrtc_socket::wasm";
log.file = "matchbox_socket\\src\\webrtc_socket\\wasm.rs";
log.line = 413; [wasm.js:433:9](http://127.0.0.1:1334/api/wasm.js)
DEBUG  ice candidate received: RtcIceCandidateInit { obj: Object { obj: JsValue(Object({"candidate":"candidate:2296203666 1 udp 2130706431 172.20.224.1 60358 typ host","sdpMid":"","sdpMLineIndex":0,"usernameFragment":null})) } } log.target = "matchbox_socket::webrtc_socket::wasm";
log.module_path = "matchbox_socket::webrtc_socket::wasm";
log.file = "matchbox_socket\\src\\webrtc_socket\\wasm.rs";
log.line = 382; [wasm.js:433:9](http://127.0.0.1:1334/api/wasm.js)
DEBUG  ice candidate received: RtcIceCandidateInit { obj: Object { obj: JsValue(Object({"candidate":"candidate:2724628134 1 udp 1694498815 89.10.87.54 53983 typ srflx raddr 0.0.0.0 rport 53983","sdpMid":"","sdpMLineIndex":0,"usernameFragment":null})) } } log.target = "matchbox_socket::webrtc_socket::wasm";
log.module_path = "matchbox_socket::webrtc_socket::wasm";
log.file = "matchbox_socket\\src\\webrtc_socket\\wasm.rs";
log.line = 382; [wasm.js:433:9](http://127.0.0.1:1334/api/wasm.js)
DEBUG  ice candidate received: RtcIceCandidateInit { obj: Object { obj: JsValue(Object({"candidate":"candidate:2724628134 1 udp 1694498815 89.10.87.54 53984 typ srflx raddr 0.0.0.0 rport 53984","sdpMid":"","sdpMLineIndex":0,"usernameFragment":null})) } } log.target = "matchbox_socket::webrtc_socket::wasm";
log.module_path = "matchbox_socket::webrtc_socket::wasm";
log.file = "matchbox_socket\\src\\webrtc_socket\\wasm.rs";
log.line = 382; [wasm.js:433:9](http://127.0.0.1:1334/api/wasm.js)
DEBUG  ice connection state changed: Connected log.target = "matchbox_socket::webrtc_socket::wasm";
log.module_path = "matchbox_socket::webrtc_socket::wasm";
log.file = "matchbox_socket\\src\\webrtc_socket\\wasm.rs";
log.line = 413; [wasm.js:433:9](http://127.0.0.1:1334/api/wasm.js)
DEBUG  -> "KeepAlive" log.target = "matchbox_socket::webrtc_socket";
log.module_path = "matchbox_socket::webrtc_socket";
log.file = "matchbox_socket\\src\\webrtc_socket\\mod.rs";
log.line = 64; [wasm.js:433:9](http://127.0.0.1:1334/api/wasm.js)
DEBUG  ice connection state changed: Disconnected log.target = "matchbox_socket::webrtc_socket::wasm";
log.module_path = "matchbox_socket::webrtc_socket::wasm";
log.file = "matchbox_socket\\src\\webrtc_socket\\wasm.rs";
log.line = 413; [wasm.js:433:9](http://127.0.0.1:1334/api/wasm.js)
WebGL warning: drawArraysInstanced: Drawing to a destination rect smaller than the viewport rect. (This warning will only be given once)
DEBUG  -> "KeepAlive" log.target = "matchbox_socket::webrtc_socket";
log.module_path = "matchbox_socket::webrtc_socket";
log.file = "matchbox_socket\\src\\webrtc_socket\\mod.rs";
log.line = 64; [wasm.js:433:9](http://127.0.0.1:1334/api/wasm.js)
DEBUG  -> "KeepAlive" log.target = "matchbox_socket::webrtc_socket";
log.module_path = "matchbox_socket::webrtc_socket";
log.file = "matchbox_socket\\src\\webrtc_socket\\mod.rs";
log.line = 64; [wasm.js:433:9](http://127.0.0.1:1334/api/wasm.js)
WebRTC: ICE failed, add a TURN server and see about:webrtc for more details
DEBUG  ice connection state changed: Failed log.target = "matchbox_socket::webrtc_socket::wasm";
log.module_path = "matchbox_socket::webrtc_socket::wasm";
log.file = "matchbox_socket\\src\\webrtc_socket\\wasm.rs";
log.line = 413; [wasm.js:433:9](http://127.0.0.1:1334/api/wasm.js)
WARN  data channel closed: Event { obj: Object { obj: JsValue(Event) } } log.target = "matchbox_socket::webrtc_socket::wasm";
log.module_path = "matchbox_socket::webrtc_socket::wasm";
log.file = "matchbox_socket\\src\\webrtc_socket\\wasm.rs";
log.line = 533;

Native

     Running `target\debug\bevy_ggrs_example.exe`
2023-10-29T12:02:14.951574Z  INFO bevy_winit::system: Creating new window "App" (0v0)
2023-10-29T12:02:15.283049Z  WARN wgpu_hal::vulkan::instance: Unable to find layer: VK_LAYER_KHRONOS_validation
2023-10-29T12:02:15.386062Z  INFO bevy_render::renderer: AdapterInfo { name: "NVIDIA GeForce GTX 970", vendor: 4318, device: 5058, device_type: DiscreteGpu, driver: "NVIDIA", driver_info: "522.25", backend: Vulkan }
2023-10-29T12:02:15.724791Z  INFO bevy_diagnostic::system_information_diagnostics_plugin::internal: SystemInfo { os: "Windows 11 Pro", kernel: "22621", cpu: "AMD Ryzen 9 3900X 12-Core Processor", core_count: "12", memory: "31.9 GiB" }
2023-10-29T12:02:15.731981Z  INFO bevy_ggrs_example: connecting to matchbox server: "ws://127.0.0.1:3536/bevy_ggrs?next=2"
2023-10-29T12:02:15.732274Z DEBUG matchbox_socket::webrtc_socket::socket: Starting WebRtcSocket
2023-10-29T12:02:15.735788Z DEBUG matchbox_socket::webrtc_socket: Received {"IdAssigned":"3c88baa0-1460-451b-a7ad-7a1c759802fa"}
2023-10-29T12:02:15.735929Z DEBUG matchbox_socket::webrtc_socket: IdAssigned(PeerId(3c88baa0-1460-451b-a7ad-7a1c759802fa))
2023-10-29T12:02:25.740345Z DEBUG matchbox_socket::webrtc_socket: -> "KeepAlive"
2023-10-29T12:02:35.752577Z DEBUG matchbox_socket::webrtc_socket: -> "KeepAlive"
2023-10-29T12:02:45.760558Z DEBUG matchbox_socket::webrtc_socket: -> "KeepAlive"
2023-10-29T12:02:55.765519Z DEBUG matchbox_socket::webrtc_socket: -> "KeepAlive"
2023-10-29T12:03:05.779657Z DEBUG matchbox_socket::webrtc_socket: -> "KeepAlive"
2023-10-29T12:03:15.786190Z DEBUG matchbox_socket::webrtc_socket: -> "KeepAlive"
2023-10-29T12:03:25.789497Z DEBUG matchbox_socket::webrtc_socket: -> "KeepAlive"
2023-10-29T12:03:35.799671Z DEBUG matchbox_socket::webrtc_socket: -> "KeepAlive"
2023-10-29T12:03:45.804609Z DEBUG matchbox_socket::webrtc_socket: -> "KeepAlive"
2023-10-29T12:03:53.300067Z DEBUG matchbox_socket::webrtc_socket: Received {"NewPeer":"e0e9a2aa-620b-4cb9-be14-e7ee91e0f4eb"}
2023-10-29T12:03:53.300329Z DEBUG matchbox_socket::webrtc_socket: NewPeer(PeerId(e0e9a2aa-620b-4cb9-be14-e7ee91e0f4eb))
2023-10-29T12:03:53.300988Z DEBUG matchbox_socket::webrtc_socket::native: making offer
2023-10-29T12:03:53.303899Z  INFO webrtc_ice::mdns: mDNS is using 0.0.0.0:5353 as dest_addr
2023-10-29T12:03:53.310711Z  INFO webrtc_mdns::conn: Looping and listening Ok(0.0.0.0:5353)
2023-10-29T12:03:53.314912Z  INFO webrtc::peer_connection: signaling state changed to have-local-offer
2023-10-29T12:03:53.315223Z DEBUG matchbox_socket::webrtc_socket: -> {"Signal":{"receiver":"e0e9a2aa-620b-4cb9-be14-e7ee91e0f4eb","data":{"Offer":"v=0\r\no=- 8519950814743650138 303764200 IN IP4 0.0.0.0\r\ns=-\r\nt=0 0\r\na=fingerprint:sha-256 9F:ED:05:91:0D:E7:CF:95:31:6C:7D:45:5E:1E:6B:32:B8:70:BB:45:66:DE:48:70:4D:75:61:4F:54:72:38:DB\r\na=group:BUNDLE 0\r\nm=application 9 UDP/DTLS/SCTP webrtc-datachannel\r\nc=IN IP4 0.0.0.0\r\na=setup:actpass\r\na=mid:0\r\na=sendrecv\r\na=sctp-port:5000\r\na=ice-ufrag:xzMqOOrhKOIRZMWT\r\na=ice-pwd:jXApNcgxcZUmmEAnsblGBdXhaUdHeVcp\r\n"}}}
2023-10-29T12:03:53.315831Z  WARN webrtc_ice::agent::agent_gather: [controlled]: could not listen udp 169.254.94.44: io error: The requested address is not valid in its context. (os error 10049)
2023-10-29T12:03:53.316296Z  WARN webrtc_ice::agent::agent_gather: [controlled]: could not listen udp 5cfd:7ed4:515f::5605: io error: The requested address is not valid in its context. (os error 10049)
2023-10-29T12:03:53.316497Z  WARN webrtc_ice::agent::agent_gather: [controlled]: could not listen udp 169.254.248.146: io error: The requested address is not valid in its context. (os error 10049)
2023-10-29T12:03:53.316677Z  WARN webrtc_ice::agent::agent_gather: [controlled]: could not listen udp 5cfd:7ed4:515f:0:ab34:b3c9:5c24:ea8a: io error: The requested address is not valid in its context. (os error 10049)
2023-10-29T12:03:53.317126Z DEBUG matchbox_socket::webrtc_socket::native: storing pending IceCandidate signal: "{\"candidate\":\"candidate:201166800 1 udp 2130706431 192.168.1.136 60356 typ host\",\"sdpMid\":\"\",\"sdpMLineIndex\":0,\"usernameFragment\":null}"
2023-10-29T12:03:53.317541Z  WARN webrtc_ice::agent::agent_gather: [controlled]: could not listen udp 5cfd:7ed4:515f:0:54c8:2120:d311:a4e: io error: The requested address is not valid in its context. (os error 10049)
2023-10-29T12:03:53.317769Z  WARN webrtc_ice::agent::agent_gather: [controlled]: could not listen udp 169.254.96.39: io error: The requested address is not valid in its context. (os error 10049)
2023-10-29T12:03:53.317960Z  WARN webrtc_ice::agent::agent_gather: [controlled]: could not listen udp 169.254.67.196: io error: The requested address is not valid in its context. (os error 10049)
2023-10-29T12:03:53.318132Z  WARN webrtc_ice::agent::agent_gather: [controlled]: could not listen udp 169.254.132.47: io error: The requested address is not valid in its context. (os error 10049)
2023-10-29T12:03:53.318372Z  WARN webrtc_ice::agent::agent_gather: [controlled]: could not listen udp 80fe::a3b3:d815:e444:4880: io error: The requested address is not valid in its context. (os error 10049)
2023-10-29T12:03:53.318893Z DEBUG matchbox_socket::webrtc_socket::native: storing pending IceCandidate signal: "{\"candidate\":\"candidate:2187365727 1 udp 2130706431 172.26.80.1 60357 typ host\",\"sdpMid\":\"\",\"sdpMLineIndex\":0,\"usernameFragment\":null}"
2023-10-29T12:03:53.319134Z  WARN webrtc_ice::agent::agent_gather: [controlled]: could not listen udp 80fe::1deb:8d08:5e05:52cb: io error: The requested address is not valid in its context. (os error 10049)
2023-10-29T12:03:53.319332Z  WARN webrtc_ice::agent::agent_gather: [controlled]: could not listen udp ::100: io error: The requested address is not valid in its context. (os error 10049)
2023-10-29T12:03:53.319596Z  WARN webrtc_ice::agent::agent_gather: [controlled]: could not listen udp 80fe::4e6:38b5:441a:737d: io error: The requested address is not valid in its context. (os error 10049)
2023-10-29T12:03:53.319826Z  WARN webrtc_ice::agent::agent_gather: [controlled]: could not listen udp 169.254.243.234: io error: The requested address is not valid in its context. (os error 10049)
2023-10-29T12:03:53.320010Z  WARN webrtc_ice::agent::agent_gather: [controlled]: could not listen udp 169.254.10.123: io error: The requested address is not valid in its context. (os error 10049)
2023-10-29T12:03:53.320274Z DEBUG matchbox_socket::webrtc_socket::native: storing pending IceCandidate signal: "{\"candidate\":\"candidate:2296203666 1 udp 2130706431 172.20.224.1 60358 typ host\",\"sdpMid\":\"\",\"sdpMLineIndex\":0,\"usernameFragment\":null}"
2023-10-29T12:03:53.325795Z  WARN webrtc_ice::agent::agent_gather: [controlled]: could not get server reflexive address udp6 stun:stun.l.google.com:19302: io error: A socket operation was attempted to an unreachable network. (os error 10051)
2023-10-29T12:03:53.345834Z DEBUG matchbox_socket::webrtc_socket::native: storing pending IceCandidate signal: "{\"candidate\":\"candidate:2724628134 1 udp 1694498815 89.10.87.54 53983 typ srflx raddr 0.0.0.0 rport 53983\",\"sdpMid\":\"\",\"sdpMLineIndex\":0,\"usernameFragment\":null}"
2023-10-29T12:03:53.360887Z  WARN webrtc_ice::agent::agent_gather: [controlled]: could not get server reflexive address udp6 stun:stun1.l.google.com:19302: io error: A socket operation was attempted to an unreachable network. (os error 10051)
2023-10-29T12:03:53.717915Z DEBUG matchbox_socket::webrtc_socket::native: storing pending IceCandidate signal: "{\"candidate\":\"candidate:2724628134 1 udp 1694498815 89.10.87.54 53984 typ srflx raddr 0.0.0.0 rport 53984\",\"sdpMid\":\"\",\"sdpMLineIndex\":0,\"usernameFragment\":null}"
2023-10-29T12:03:53.795358Z DEBUG matchbox_socket::webrtc_socket: Received {"Signal":{"sender":"e0e9a2aa-620b-4cb9-be14-e7ee91e0f4eb","data":{"Answer":"v=0\r\no=mozilla...THIS_IS_SDPARTA-99.0 5148800727462569654 0 IN IP4 0.0.0.0\r\ns=-\r\nt=0 0\r\na=sendrecv\r\na=fingerprint:sha-256 95:9F:6D:17:A0:CD:4B:D8:8E:5F:EE:36:54:E2:89:4C:78:17:26:E0:E2:27:50:6D:93:A7:93:3C:78:D6:E7:FA\r\na=group:BUNDLE 0\r\na=ice-options:trickle\r\na=msid-semantic:WMS *\r\nm=application 53987 UDP/DTLS/SCTP webrtc-datachannel\r\nc=IN IP4 89.10.87.54\r\na=candidate:0 1 UDP 2122187007 ab262a74-5a98-4288-a132-b40d75613cbb.local 53987 typ host\r\na=candidate:2 1 UDP 2122252543 da201c88-6abc-46a3-9af7-ed16f91dfc09.local 53988 typ host\r\na=candidate:4 1 TCP 2105458943 ab262a74-5a98-4288-a132-b40d75613cbb.local 9 typ host tcptype active\r\na=candidate:5 1 TCP 2105524479 da201c88-6abc-46a3-9af7-ed16f91dfc09.local 9 typ host tcptype active\r\na=candidate:1 1 UDP 1685987327 89.10.87.54 53987 typ srflx raddr 0.0.0.0 rport 0\r\na=sendrecv\r\na=end-of-candidates\r\na=ice-pwd:da3132e0f5b7c2775a510574b5767931\r\na=ice-ufrag:d5898e91\r\na=mid:0\r\na=setup:active\r\na=sctp-port:5000\r\na=max-message-size:1073741823\r\n"}}}
2023-10-29T12:03:53.795657Z DEBUG matchbox_socket::webrtc_socket: Signal { sender: PeerId(e0e9a2aa-620b-4cb9-be14-e7ee91e0f4eb), data: Answer("v=0\r\no=mozilla...THIS_IS_SDPARTA-99.0 5148800727462569654 0 IN IP4 0.0.0.0\r\ns=-\r\nt=0 0\r\na=sendrecv\r\na=fingerprint:sha-256 95:9F:6D:17:A0:CD:4B:D8:8E:5F:EE:36:54:E2:89:4C:78:17:26:E0:E2:27:50:6D:93:A7:93:3C:78:D6:E7:FA\r\na=group:BUNDLE 0\r\na=ice-options:trickle\r\na=msid-semantic:WMS *\r\nm=application 53987 UDP/DTLS/SCTP webrtc-datachannel\r\nc=IN IP4 89.10.87.54\r\na=candidate:0 1 UDP 2122187007 ab262a74-5a98-4288-a132-b40d75613cbb.local 53987 typ host\r\na=candidate:2 1 UDP 2122252543 da201c88-6abc-46a3-9af7-ed16f91dfc09.local 53988 typ host\r\na=candidate:4 1 TCP 2105458943 ab262a74-5a98-4288-a132-b40d75613cbb.local 9 typ host tcptype active\r\na=candidate:5 1 TCP 2105524479 da201c88-6abc-46a3-9af7-ed16f91dfc09.local 9 typ host tcptype active\r\na=candidate:1 1 UDP 1685987327 89.10.87.54 53987 typ srflx raddr 0.0.0.0 rport 0\r\na=sendrecv\r\na=end-of-candidates\r\na=ice-pwd:da3132e0f5b7c2775a510574b5767931\r\na=ice-ufrag:d5898e91\r\na=mid:0\r\na=setup:active\r\na=sctp-port:5000\r\na=max-message-size:1073741823\r\n") }
2023-10-29T12:03:53.796032Z  INFO webrtc::peer_connection: signaling state changed to stable
2023-10-29T12:03:53.796471Z DEBUG matchbox_socket::webrtc_socket: -> {"Signal":{"receiver":"e0e9a2aa-620b-4cb9-be14-e7ee91e0f4eb","data":{"IceCandidate":"{\"candidate\":\"candidate:201166800 1 udp 2130706431 192.168.1.136 60356 typ host\",\"sdpMid\":\"\",\"sdpMLineIndex\":0,\"usernameFragment\":null}"}}}
2023-10-29T12:03:53.796647Z DEBUG matchbox_socket::webrtc_socket: -> {"Signal":{"receiver":"e0e9a2aa-620b-4cb9-be14-e7ee91e0f4eb","data":{"IceCandidate":"{\"candidate\":\"candidate:2187365727 1 udp 2130706431 172.26.80.1 60357 typ host\",\"sdpMid\":\"\",\"sdpMLineIndex\":0,\"usernameFragment\":null}"}}}
2023-10-29T12:03:53.796825Z DEBUG matchbox_socket::webrtc_socket: -> {"Signal":{"receiver":"e0e9a2aa-620b-4cb9-be14-e7ee91e0f4eb","data":{"IceCandidate":"{\"candidate\":\"candidate:2296203666 1 udp 2130706431 172.20.224.1 60358 typ host\",\"sdpMid\":\"\",\"sdpMLineIndex\":0,\"usernameFragment\":null}"}}}
2023-10-29T12:03:53.797042Z DEBUG matchbox_socket::webrtc_socket: -> {"Signal":{"receiver":"e0e9a2aa-620b-4cb9-be14-e7ee91e0f4eb","data":{"IceCandidate":"{\"candidate\":\"candidate:2724628134 1 udp 1694498815 89.10.87.54 53983 typ srflx raddr 0.0.0.0 rport 53983\",\"sdpMid\":\"\",\"sdpMLineIndex\":0,\"usernameFragment\":null}"}}}
2023-10-29T12:03:53.797216Z DEBUG matchbox_socket::webrtc_socket: -> {"Signal":{"receiver":"e0e9a2aa-620b-4cb9-be14-e7ee91e0f4eb","data":{"IceCandidate":"{\"candidate\":\"candidate:2724628134 1 udp 1694498815 89.10.87.54 53984 typ srflx raddr 0.0.0.0 rport 53984\",\"sdpMid\":\"\",\"sdpMLineIndex\":0,\"usernameFragment\":null}"}}}
2023-10-29T12:03:53.797455Z  INFO webrtc_ice::agent::agent_internal: [controlling]: Setting new connection state: Checking
2023-10-29T12:03:53.797718Z  INFO webrtc::peer_connection: ICE connection state changed: checking
2023-10-29T12:03:53.798721Z  INFO webrtc_mdns::conn: Received query result
2023-10-29T12:03:53.798860Z  INFO webrtc_mdns::conn: Received query result
2023-10-29T12:03:53.798958Z  INFO webrtc_mdns::conn: Received query result
2023-10-29T12:03:53.799048Z  INFO webrtc_mdns::conn: Received query result
2023-10-29T12:03:55.808477Z DEBUG matchbox_socket::webrtc_socket: -> "KeepAlive"
2023-10-29T12:04:05.810834Z DEBUG matchbox_socket::webrtc_socket: -> "KeepAlive"
2023-10-29T12:04:15.812005Z DEBUG matchbox_socket::webrtc_socket: -> "KeepAlive"
2023-10-29T12:04:23.983210Z  WARN webrtc_ice::agent::agent_internal: [controlling]: Failed to close candidate udp4 srflx 89.10.87.54:53987 related 0.0.0.0:0: the agent is closed
2023-10-29T12:04:23.983359Z  WARN webrtc_ice::agent::agent_internal: [controlling]: Failed to close candidate udp4 prflx 192.168.1.136:53987 related :0: the agent is closed
2023-10-29T12:04:23.983449Z  WARN webrtc_ice::agent::agent_internal: [controlling]: Failed to close candidate udp4 host ab262a74-5a98-4288-a132-b40d75613cbb.local:9: the agent is closed
2023-10-29T12:04:23.983527Z  WARN webrtc_ice::agent::agent_internal: [controlling]: Failed to close candidate udp4 host ab262a74-5a98-4288-a132-b40d75613cbb.local:53987: the agent is closed
2023-10-29T12:04:23.983595Z  WARN webrtc_ice::agent::agent_internal: [controlling]: Failed to close candidate udp4 host da201c88-6abc-46a3-9af7-ed16f91dfc09.local:9: the agent is closed
2023-10-29T12:04:23.983662Z  WARN webrtc_ice::agent::agent_internal: [controlling]: Failed to close candidate udp4 host da201c88-6abc-46a3-9af7-ed16f91dfc09.local:53988: the agent is closed
2023-10-29T12:04:23.983732Z  INFO webrtc_ice::agent::agent_internal: [controlling]: Setting new connection state: Failed
2023-10-29T12:04:23.983883Z  INFO webrtc::peer_connection: ICE connection state changed: failed
2023-10-29T12:04:23.984087Z  INFO webrtc::peer_connection: peer connection state changed: failed

johanhelsing avatar Oct 29 '23 12:10 johanhelsing