test_p2p is not working when trivial_signaling_server is remote.

[fred4d]

Many months ago with older code I had followed the P2P example and had successfully integrated peer-to-peer connections in my work. I have updated to recent code (yesterday) and in both my code and test_p2p I cannot connect through a trivial_signaling_server hosted remotely. Here is the output from test_p2p run on different computers as server/client (not even peer-to-peer yet):

C:\install>test_p2p.exe --identity-local str:Fred --signaling-server [redacted].net:10000 --server
0.002538 Initialized low level socket/threading support.
0.005875 Creating listen socket, local virtual port 0
9.456763 Creating signaling session for peer 'str:Dan'
9.456966 [#2557448975 P2P str:Dan vport 0] Accepting
9.458360 [#2557448975 P2P str:Dan vport 0] Relay candidates enabled by P2P_Transport_ICE_Enable, but P2P_TURN_ServerList is empty
9.479485 Got remote candidate 'candidate:47202818 0 udp 2130706431 fe80::d06d:6887:6e67:ca56 49666 typ host'
9.479686 Got a rendezvous candidate at "[fe80::d06d:6887:6e67:ca56]:49666"
9.480165 Got remote candidate 'candidate:53002755 0 udp 2130706175 fe80::b814:8dcd:bb9b:78de 49667 typ host'
9.480587 Got a rendezvous candidate at "[fe80::b814:8dcd:bb9b:78de]:49667"
9.480950 Got remote candidate 'candidate:55689732 0 udp 2130705919 fe80::a8dd:69bc:b5b9:65a7 49668 typ host'
9.481305 Got a rendezvous candidate at "[fe80::a8dd:69bc:b5b9:65a7]:49668"
9.481883 Got remote candidate 'candidate:34685445 0 udp 2130705663 10.242.162.133 49669 typ host'
9.482774 Got a rendezvous candidate at "10.242.162.133:49669"
9.483069 Got remote candidate 'candidate:24887814 0 udp 2130705407 2601:643:4301:ffc0::3152 49670 typ host'
9.483386 Got a rendezvous candidate at "[2601:643:4301:ffc0::3152]:49670"
9.483690 Got remote candidate 'candidate:61096455 0 udp 2130705151 fe80::f9f6:fef0:10ec:a14f 49671 typ host'
9.483983 Got a rendezvous candidate at "[fe80::f9f6:fef0:10ec:a14f]:49671"
9.484274 Got remote candidate 'candidate:23872008 0 udp 2130704895 10.0.0.207 49672 typ host'
9.484563 Got a rendezvous candidate at "10.0.0.207:49672"
9.484849 Got remote candidate 'candidate:41861641 0 udp 2130704639 fe80::6ce8:1ee0:6057:1c59 49673 typ host'
9.485147 Got a rendezvous candidate at "[fe80::6ce8:1ee0:6057:1c59]:49673"
9.485473 SteamNetworkingSockets lock held for 27.6ms. (Performance warning.) AcceptConnection,BFinishCryptoHandshake,FinalizeLocalCrypto,P2P::AcceptConnection,CSteamNetworkConnectionP2P::CheckInitICE,CConnectionTransportP2PICE_Valve::Init,CConnectionTransportP2PICE_Valve::RecvRendezvous(x9)
This is usually a symptom of a general performance problem such as thread starvation.
9.485776 Waited 6.9ms for SteamNetworkingSockets lock [ServiceThread]
9.488563 [#2557448975 P2P str:Dan vport 0] finding route
9.491560 Got remote candidate 'candidate:57740655 0 udp 1677721855 73.158.93.251 49672 typ srflx'
9.491619 Got a rendezvous candidate at "73.158.93.251:49672"
9.644941 WSASendTo [2601:643:4301:ffc0::3152]:49670 failed, returned -1, last error=0x2741 The requested address is not valid in its context.
9.846370 WSASendTo [2601:643:4301:ffc0::3152]:49670 failed, returned -1, last error=0x2741 The requested address is not valid in its context.
9.946943 WSASendTo [2601:643:4301:ffc0::3152]:49670 failed, returned -1, last error=0x2741 The requested address is not valid in its context.
9.997818 WSASendTo [2601:643:4301:ffc0::3152]:49670 failed, returned -1, last error=0x2741 The requested address is not valid in its context.
10.048949 WSASendTo [2601:643:4301:ffc0::3152]:49670 failed, returned -1, last error=0x2741 The requested address is not valid in its context.
10.098991 WSASendTo [2601:643:4301:ffc0::3152]:49670 failed, returned -1, last error=0x2741 The requested address is not valid in its context.
19.459016 [#2557448975 P2P str:Dan vport 0] problem detected locally (5008): Timed out attempting to negotiate rendezvous
19.698714 [#2557448975 P2P str:Dan vport 0] Guessed ICE failure to be 5001: Never received any remote candidates
19.700211 SteamNetworkingSockets lock held for 241.3ms. (Performance warning.) ServiceThread,CSteamNetworkConnectionBase::Think(x2),P2P::SetRendezvousCommonFieldsAndSendSignal,P2PTransportThink,CSteamNetworkingICESession::Think,CSteamNetworkingICESession::Think_TestPeerConnectivity
This is usually a symptom of a general performance problem such as thread starvation.
19.700720 [#2557448975 P2P str:Dan vport 0] problem detected locally, reason 5008: Timed out attempting to negotiate rendezvous
19.701350 Shutting down low level socket/threading support.

C:\install>test_p2p --identity-local str:Dan --identity-remote str:Fred --signaling-server [redacted].net:10000 --client
0.003564 Initialized low level socket/threading support.
0.093110 Connecting to 'str:Fred', virtual port 0, from local virtual port 0.
0.093347 Creating signaling session for peer 'str:Fred'
0.097802 [#2868680494 P2P str:Fred vport 0] Relay candidates enabled by P2P_Transport_ICE_Enable, but P2P_TURN_ServerList is empty
0.131627 SteamNetworkingSockets lock held for 36.5ms. (Performance warning.) ConnectP2PCustomSignaling,Base::BInitConnection,GetIdentity,FinalizeLocalCrypto,CSteamNetworkConnectionP2P::CheckInitICE,CConnectionTransportP2PICE_Valve::Init
This is usually a symptom of a general performance problem such as thread starvation.
0.132033 Sending msg 'Greetings!'
0.132105 Waited 2.4ms for SteamNetworkingSockets lock [ServiceThread]
0.135526 [#2868680494 P2P str:Fred vport 0] Entered connecting state
0.195420 [#2868680494 P2P str:Fred vport 0] Sending P2P ConnectRequest
0.238255 [#2868680494 P2P str:Fred vport 0] Sending P2P ConnectRequest
0.448491 Got remote candidate 'candidate:47374689 0 udp 2130706431 fe80::a8ae:3024:ad51:cbb3 57697 typ host'
0.448596 Got a rendezvous candidate at "[fe80::a8ae:3024:ad51:cbb3]:57697"
0.449386 Got remote candidate 'candidate:19784034 0 udp 2130706175 10.0.0.82 57698 typ host'
0.449680 Got a rendezvous candidate at "10.0.0.82:57698"
0.449956 Got remote candidate 'candidate:36036963 0 udp 2130705919 fe80::2d28:5126:bc73:b41d 57699 typ host'
0.450239 Got a rendezvous candidate at "[fe80::2d28:5126:bc73:b41d]:57699"
0.450533 Got remote candidate 'candidate:37839204 0 udp 2130705663 fe80::24e4:a332:7c89:1908 57700 typ host'
0.450826 Got a rendezvous candidate at "[fe80::24e4:a332:7c89:1908]:57700"
0.451131 Got remote candidate 'candidate:44654949 0 udp 2130705407 fe80::45a0:6447:6fd5:55aa 57701 typ host'
0.451411 Got a rendezvous candidate at "[fe80::45a0:6447:6fd5:55aa]:57701"
0.451690 Got remote candidate 'candidate:33939814 0 udp 2130705151 10.242.174.98 57702 typ host'
0.451930 Got a rendezvous candidate at "10.242.174.98:57702"
0.452169 Got remote candidate 'candidate:48685415 0 udp 2130704895 fe80::10ea:99a0:c327:df52 57703 typ host'
0.452409 Got a rendezvous candidate at "[fe80::10ea:99a0:c327:df52]:57703"
0.452637 Got remote candidate 'candidate:54878568 0 udp 2130704639 fe80::edcc:5f88:c546:e080 57704 typ host'
0.452847 Got a rendezvous candidate at "[fe80::edcc:5f88:c546:e080]:57704"
0.453078 [#2868680494 P2P str:Fred vport 0] Received ConnectOK in P2P Rendezvous.
0.453751 [#2868680494 P2P str:Fred vport 0] finding route
0.453794 SteamNetworkingSockets lock held for 5.5ms. (Performance warning.) ReceivedP2PCustomSignal,InternalReceivedP2PSignal,P2P::ProcessSignal,CConnectionTransportP2PICE_Valve::RecvRendezvous(x9),BRecvCryptoHandshake,BFinishCryptoHandshake(x2)
This is usually a symptom of a general performance problem such as thread starvation.
0.454065 [#2868680494 P2P str:Fred vport 0] finding route
0.454068 Waited 5.6ms for SteamNetworkingSockets lock [ServiceThread]
10.448574 [#2868680494 P2P str:Fred vport 0] problem detected locally (5008): Timed out attempting to negotiate rendezvous
10.448803 [#2868680494 P2P str:Fred vport 0] Guessed ICE failure to be 5001: Never received any remote candidates
10.449642 [#2868680494 P2P str:Fred vport 0] problem detected locally, reason 5008: Timed out attempting to negotiate rendezvous
10.449734 Shutting down low level socket/threading support.

[eddiejames]

Experiencing the same issue using the native ICE client. I will try and test with webrtc as well.

[eddiejames]

Same issue with webrtc enabled. Interestingly, my behavior under linux and windows is different. I can't connect between the two, and can't connect client/server on the same linux machine, but I can connect client/server on the same windows machine. Need to check windows to windows and linux to linux later.

[eddiejames]

Did some bisecting and came to the conclusion that this bug was likely introduced in 23dfdbf

test_p2p works fine at b794235 but doesn't work at 85c9d73

I didn't get further in the bisect because test_p2p just crashed on the client side at b7aa2f5

[fred4d]

Is there an ETA for when an attempted fix might occur? Or is the recommendation to rollback to, for example, b794235?

Thanks!

[LeventSevgili]

Hey,

We did some tests with test_p2p and i want to share some details.

All tests are WebRTC enabled and connecting to a remote signaling server.

First test: Linux Server and Linux Client with 1.4.1 Release failed
I switched to tag->1.4.1 Release and built the project on Linux with WebRTC Enabled and tests enabled. I used below commands to connect a client to a server. Basic stuff. Client stucks at finding route when connecting to the server. (Also stuck with the beta native ICE). On the other hand, for Windows, iOS and Android it worked quite fine.

./test_p2p --server --identity-local str:levent --signaling-server [remote-server].com:10000
./test_p2p --client --identity-local str:unal --identity-remote str:levent --signaling-server [remote-server].com:10000

Second test: Linux Server and Linux Client 1.4.0 Release success
I switched to tag ->1.4.0 Release and built the project on Linux again, i run the same tests with above commands, it worked nice. no problem at all connecting the client to the server via signaling server, it was success.

Third test: Windows Server and Windows Client 1.4.1 Release success
I switched to tag ->1.4.1 Release and built the project on Windows, i run the same tests with above commands, it worked nice. no problem at all connecting the client to the server via signaling server, it was success.

So it seems, some stuff seems broken for Linux after 1.4.0 tag.
The exact commit is already seems figured out at previous posts. Cheerz ^^

Thanks!