search

godotengine / webrtc-native

The official GDNative WebRTC implementation for non-html exports.
MIT License
207 stars 30 forks source link

rpc_id and rpc commands not reliable #21

Closed PhilipWee closed 4 years ago

PhilipWee commented 4 years ago

When using the webrtc plugin, I created a script to check the network latency and perform error correction:

#TIMING COORDINATION

var sent_timings = []
var received_timings = []

func perform_latency_correction(id):
    for _i in range(9):

        sent_timings.append(curTime)
        rpc_id(id,"send_response_to_server")
        yield(get_tree().create_timer(0.05),"timeout")
    while len(received_timings) < 9:
        print('stuck')
        print(len(sent_timings))
        print(len(received_timings))
        yield(get_tree().create_timer(0.05),"timeout")
    var time_diffs = []
    for i in range(9):
        time_diffs.append(received_timings[i] - sent_timings[i])
    time_diffs.sort()
    var total_lag = time_diffs[4]
    print(received_timings)
    print(sent_timings)
    print("Total Lag:",total_lag)

remote func store_response_from_client():
    yield(fakeLag(),"timeout")
    received_timings.append(curTime)

remote func send_response_to_server():
    yield(fakeLag(),"timeout")
    rpc_id(1,"store_response_from_client")

#Function for simulating lag
func fakeLag():
    return get_tree().create_timer(FAKE_LAG_SECS)

#TIMING COORDINATION

However, this function fails intermittently, with some rpc_id calls not reaching the other user image

Interestingly, we no longer experience the intermittent issue when adding a print statement before the rpc call

#TIMING COORDINATION

var sent_timings = []
var received_timings = []

func perform_latency_correction(id):
    for _i in range(9):
        print('WITH THIS PRINT IT WILL NO LONGER FAIL')
        sent_timings.append(curTime)
        rpc_id(id,"send_response_to_server")
        yield(get_tree().create_timer(0.05),"timeout")
    while len(received_timings) < 9:
        print('stuck')
        print(len(sent_timings))
        print(len(received_timings))
        yield(get_tree().create_timer(0.05),"timeout")
    var time_diffs = []
    for i in range(9):
        time_diffs.append(received_timings[i] - sent_timings[i])
    time_diffs.sort()
    var total_lag = time_diffs[4]
    print(received_timings)
    print(sent_timings)
    print("Total Lag:",total_lag)

remote func store_response_from_client():
    yield(fakeLag(),"timeout")
    received_timings.append(curTime)

remote func send_response_to_server():
    yield(fakeLag(),"timeout")
    rpc_id(1,"store_response_from_client")

#Function for simulating lag
func fakeLag():
    return get_tree().create_timer(FAKE_LAG_SECS)

#TIMING COORDINATION

The above code always returning this: image

Other things that we have tried: Running two rpc_id commands in a row with the print command (THIS WORKS):

func perform_latency_correction(id):
    for _i in range(9):
        print('WITH THIS PRINT IT WILL NO LONGER FAIL')
        sent_timings.append(curTime)
        rpc_id(id,"send_response_to_server")
        rpc_id(id,"send_response_to_server")
        yield(get_tree().create_timer(0.05),"timeout")

Running two rpc_id commands in a row without the print command (DOES NOT WORK):

func perform_latency_correction(id):
    for _i in range(9):

        sent_timings.append(curTime)
        rpc_id(id,"send_response_to_server")
        rpc_id(id,"send_response_to_server")
        yield(get_tree().create_timer(0.05),"timeout")

Note that the above command, when fails for both rpc calls

Sample webrtc debug print when above fails with this output: image

Godot Engine v3.2.1.stable.official - https://godotengine.org
OpenGL ES 3.0 Renderer: GeForce RTX 2070 with Max-Q Design/PCIe/SSE2

Join Button Pressed
Connected 1832737670
Peer connected 1
(opensslidentity.cc:45): Making key pair
(peerconnection.cc:849): Session: 2527941224590814886 is destroyed.
(opensslidentity.cc:93): Returning key pair
(opensslcertificate.cc:58): Making certificate for WebRTC
(opensslcertificate.cc:105): Returning certificate
(opensslidentity.cc:45): Making key pair
(peerconnection.cc:5072): AddSctpDataStream called when sctp_transport_ is NULL.
(peerconnection.cc:5072): AddSctpDataStream called when sctp_transport_ is NULL.
(peerconnection.cc:5072): AddSctpDataStream called when sctp_transport_ is NULL.
(opensslidentity.cc:93): Returning key pair
(opensslcertificate.cc:58): Making certificate for WebRTC
Setting Network Peer
WwwREf1QdjIYlK2M
(opensslcertificate.cc:105): Returning certificate
Network Players: {1832737670:{char:res://Players/Axeman.tscn, name:Philip Wee}}

Got offer: 1
(webrtcsdp.cc:2955): Ignored line: a=sctpmap:5000 webrtc-datachannel 1024
(webrtcsdp.cc:1727): AddSctpDataCodec: Got SCTP Port Number 5000
(p2ptransportchannel.cc:437): Set backup connection ping interval to 25000 milliseconds.
(p2ptransportchannel.cc:446): Set ICE receiving timeout to 2500 milliseconds
(p2ptransportchannel.cc:453): Set ping most likely connection to 0
(p2ptransportchannel.cc:460): Set stable_writable_connection_ping_interval to 2500
(p2ptransportchannel.cc:473): Set presume writable when fully relayed to 0
(p2ptransportchannel.cc:482): Set regather_on_failed_networks_interval to 300000
(p2ptransportchannel.cc:501): Set receiving_switching_delay to 1000
(dtlssrtptransport.cc:57): Setting RTCP Transport on data transport 0000000000000000
(dtlssrtptransport.cc:62): Setting RTP Transport on data transport 000000000EA983B0
(p2ptransportchannel.cc:385): Received remote ICE parameters: ufrag=gb33, renomination disabled
(peerconnection.cc:3506): Session: 7894624426572364422 Old state: kStable New state: kHaveRemoteOffer
(peerconnection.cc:4756): Local and Remote descriptions must be applied to get the SSL Role of the SCTP transport.
(peerconnection.cc:4778): Local and Remote descriptions must be applied to get the SSL Role of the session.
(peerconnection.cc:5393): data is not ready to use the remote candidate because the local or remote description is not set.
(peerconnection.cc:5393): data is not ready to use the remote candidate because the local or remote description is not set.
(peerconnection.cc:5393): data is not ready to use the remote candidate because the local or remote description is not set.
createdanswer
(webrtcsdp.cc:2955): Ignored line: a=sctpmap:5000 webrtc-datachannel 1024
(webrtcsdp.cc:1727): AddSctpDataCodec: Got SCTP Port Number 5000
(dtlssrtptransport.cc:57): Setting RTCP Transport on data transport 0000000000000000
(dtlssrtptransport.cc:62): Setting RTP Transport on data transport 000000000EA983B0
(p2ptransportchannel.cc:374): Set ICE ufrag: /HXf pwd: x7vYNbzdu+jkqXyraYP+/hjv on transport data
(dtlstransport.cc:383): DtlsTransport[data|1|__]: DTLS setup complete.
(peerconnection.cc:3506): Session: 7894624426572364422 Old state: kHaveRemoteOffer New state: kStable
(peerconnection.cc:3463): Changing IceConnectionState 0 => 1
(basicportallocator.cc:339): Start getting ports with prune_turn_ports disabled
(basicportallocator.cc:107): Filtered out ignored networks:
(basicportallocator.cc:109): Net[Software:::1/128:Loopback:id=4]
(basicportallocator.cc:109): Net[Software:127.0.0.1/32:Loopback:id=3]
(basicportallocator.cc:829): Network manager has started
(basicportallocator.cc:107): Filtered out ignored networks:
(basicportallocator.cc:109): Net[Software:::1/128:Loopback:id=4]
(basicportallocator.cc:109): Net[Software:127.0.0.1/32:Loopback:id=3]
(basicportallocator.cc:744): Allocate ports on 3 networks
(basicportallocator.cc:1284): Net[LogMeIn:2620:9b::192d:fd47/128:Ethernet:id=2]: Allocation Phase=Udp
(port.cc:328): Port[000000000EB45AF0::1:0:local:Net[LogMeIn:2620:9b::192d:fd47/128:Ethernet:id=2]]: Port created with network cost 0
(basicportallocator.cc:1355): AllocationSequence: UDPPort will be handling the STUN candidate generation.
(basicportallocator.cc:851): Adding allocated port for data
(basicportallocator.cc:871): Port[000000000EB45AF0:data:1:0:local:Net[LogMeIn:2620:9b::192d:fd47/128:Ethernet:id=2]]: Added port to allocator
(basicportallocator.cc:889): Port[000000000EB45AF0:data:1:0:local:Net[LogMeIn:2620:9b::192d:fd47/128:Ethernet:id=2]]: Gathered candidate: Cand[:3490071206:1:udp:2122262783:[2620:9b::192d:fd47]:49514:local::0:/HXf:x7vYNbzdu+jkqXyraYP+/hjv:2:0:0]
(basicportallocator.cc:917): Port[000000000EB45AF0:data:1:0:local:Net[LogMeIn:2620:9b::192d:fd47/128:Ethernet:id=2]]: Port ready.
(port.cc:1086): Conn[000000000EB5C890:data:Net[LogMeIn:2620:9b::192d:fd47/128:Ethernet:id=2]:yubgnfM1:1:0:local:udp:[2620:9b::192d:fd47]:49514->z034NaYK:1:2122262783:local:udp:[2620:9b::192d:fd47]:57717|C--W|-|0|0|9115049250747470334|-]: Connection created
(p2ptransportchannel.cc:1074): Channel[data|1|__]: Created connection with origin: 2, total: 1
(p2ptransportchannel.cc:1716): Channel[data|1|__]: Transport channel state changed from 0 to 2
(jseptransportcontroller.cc:1158): data Transport 1 state changed. Check if state is complete.
(p2ptransportchannel.cc:1288): Channel[data|1|__]: Have a pingable connection for the first time; starting to ping.
(stunport.cc:392): Port[000000000EB45AF0:data:1:0:local:Net[LogMeIn:2620:9b::192d:fd47/128:Ethernet:id=2]]: Starting STUN host lookup for stun.l.google.com:19302
(basicportallocator.cc:1284): Net[Realtek:192.168.0.105/32:Ethernet:id=1]: Allocation Phase=Udp
(port.cc:328): Port[000000000EB8DF60::1:0:local:Net[Realtek:192.168.0.105/32:Ethernet:id=1]]: Port created with network cost 0
(basicportallocator.cc:1355): AllocationSequence: UDPPort will be handling the STUN candidate generation.
(basicportallocator.cc:851): Adding allocated port for data
(basicportallocator.cc:871): Port[000000000EB8DF60:data:1:0:local:Net[Realtek:192.168.0.105/32:Ethernet:id=1]]: Added port to allocator
(basicportallocator.cc:889): Port[000000000EB8DF60:data:1:0:local:Net[Realtek:192.168.0.105/32:Ethernet:id=1]]: Gathered candidate: Cand[:1221703924:1:udp:2122194687:192.168.0.105:49515:local::0:/HXf:x7vYNbzdu+jkqXyraYP+/hjv:1:0:0]
(basicportallocator.cc:917): Port[000000000EB8DF60:data:1:0:local:Net[Realtek:192.168.0.105/32:Ethernet:id=1]]: Port ready.
(port.cc:1086): Conn[000000000EB9B1E0:data:Net[Realtek:192.168.0.105/32:Ethernet:id=1]:B4NH1TxE:1:0:local:udp:192.168.0.105:49515->U3KkwIDF:1:2122194687:local:udp:192.168.0.105:57718|C--W|-|0|0|9114756780654345726|-]: Connection created
(p2ptransportchannel.cc:1074): Channel[data|1|__]: Created connection with origin: 2, total: 2
(port.cc:1086): Conn[000000000EB9BE70:data:Net[Realtek:192.168.0.105/32:Ethernet:id=1]:B4NH1TxE:1:0:local:udp:192.168.0.105:49515->QdUELJ5+:1:2122129151:local:udp:172.27.29.15:57719|C--W|-|0|0|9114475305677635070|-]: Connection created
(p2ptransportchannel.cc:1074): Channel[data|1|__]: Created connection with origin: 2, total: 3
(port.cc:1086): Conn[000000000EB9CB00:data:Net[Realtek:192.168.0.105/32:Ethernet:id=1]:B4NH1TxE:1:0:local:udp:192.168.0.105:49515->3lvkWPsm:1:1685987071:stun:udp:219.75.109.151:57718|C--W|-|0|0|7241259335668219390|-]: Connection created
(p2ptransportchannel.cc:1074): Channel[data|1|__]: Created connection with origin: 2, total: 4
(p2ptransportchannel.cc:1716): Channel[data|1|__]: Transport channel state changed from 2 to 1
(jseptransportcontroller.cc:1158): data Transport 1 state changed. Check if state is complete.
(stunport.cc:392): Port[000000000EB8DF60:data:1:0:local:Net[Realtek:192.168.0.105/32:Ethernet:id=1]]: Starting STUN host lookup for stun.l.google.com:19302
(basicportallocator.cc:1284): Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]: Allocation Phase=Udp
(port.cc:328): Port[000000000EB998F0::1:0:local:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]]: Port created with network cost 0
(basicportallocator.cc:1355): AllocationSequence: UDPPort will be handling the STUN candidate generation.
(basicportallocator.cc:851): Adding allocated port for data
(basicportallocator.cc:871): Port[000000000EB998F0:data:1:0:local:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]]: Added port to allocator
(basicportallocator.cc:889): Port[000000000EB998F0:data:1:0:local:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]]: Gathered candidate: Cand[:3192801181:1:udp:2122129151:172.27.29.15:49516:local::0:/HXf:x7vYNbzdu+jkqXyraYP+/hjv:5:0:0]
(basicportallocator.cc:917): Port[000000000EB998F0:data:1:0:local:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]]: Port ready.
(port.cc:1086): Conn[000000000EBA7DF0:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->U3KkwIDF:1:2122194687:local:udp:192.168.0.105:57718|C--W|-|0|0|9114475305677635071|-]: Connection created
(p2ptransportchannel.cc:1074): Channel[data|1|__]: Created connection with origin: 2, total: 5
(port.cc:1086): Conn[000000000EBA8A80:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->QdUELJ5+:1:2122129151:local:udp:172.27.29.15:57719|C--W|-|0|0|9114475305677503998|-]: Connection created
(p2ptransportchannel.cc:1074): Channel[data|1|__]: Created connection with origin: 2, total: 6
(port.cc:1086): Conn[000000000EBA9710:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->3lvkWPsm:1:1685987071:stun:udp:219.75.109.151:57718|C--W|-|0|0|7241259335668088318|-]: Connection created
(p2ptransportchannel.cc:1074): Channel[data|1|__]: Created connection with origin: 2, total: 7
(stunport.cc:392): Port[000000000EB998F0:data:1:0:local:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]]: Starting STUN host lookup for stun.l.google.com:19302
(port.cc:1711): Conn[000000000EB5C890:data:Net[LogMeIn:2620:9b::192d:fd47/128:Ethernet:id=2]:yubgnfM1:1:0:local:udp:[2620:9b::192d:fd47]:49514->z034NaYK:1:2122262783:local:udp:[2620:9b::192d:fd47]:57717|C--W|-|0|0|9115049250747470334|-]: Sent STUN ping, id=54625555654b65315061514c, use_candidate=0, nomination=0
(stunport.cc:405): Port[000000000EB45AF0:data:1:0:local:Net[LogMeIn:2620:9b::192d:fd47/128:Ethernet:id=2]]: StunPort: stun host lookup received error 0
(basicportallocator.cc:991): Port[000000000EB45AF0:data:1:0:local:Net[LogMeIn:2620:9b::192d:fd47/128:Ethernet:id=2]]: Port completed gathering candidates.
(thread.cc:273): Waiting for the thread to join, but blocking calls have been disallowed
(thread.cc:273): Waiting for the thread to join, but blocking calls have been disallowed
(thread.cc:273): Waiting for the thread to join, but blocking calls have been disallowed
(port.cc:1243): Conn[000000000EB5C890:data:Net[LogMeIn:2620:9b::192d:fd47/128:Ethernet:id=2]:yubgnfM1:1:0:local:udp:[2620:9b::192d:fd47]:49514->z034NaYK:1:2122262783:local:udp:[2620:9b::192d:fd47]:57717|C--I|-|0|0|9115049250747470334|-]: Received STUN ping, id=35666546336150526278432f
(port.cc:807): Port[000000000EB45AF0:data:1:0:local:Net[LogMeIn:2620:9b::192d:fd47/128:Ethernet:id=2]]: Sent STUN ping response, to=[2620:9b::192d:fd47]:57717, id=35666546336150526278432f
(p2ptransportchannel.cc:933): Not switching the selected connection on controlled side yet: Conn[000000000EB5C890:data:Net[LogMeIn:2620:9b::192d:fd47/128:Ethernet:id=2]:yubgnfM1:1:0:local:udp:[2620:9b::192d:fd47]:49514->z034NaYK:1:2122262783:local:udp:[2620:9b::192d:fd47]:57717|CR-I|-|1|0|9115049250747470334|-]
(port.cc:1655): Conn[000000000EB5C890:data:Net[LogMeIn:2620:9b::192d:fd47/128:Ethernet:id=2]:yubgnfM1:1:0:local:udp:[2620:9b::192d:fd47]:49514->z034NaYK:1:2122262783:local:udp:[2620:9b::192d:fd47]:57717|CR-I|-|1|0|9115049250747470334|-]: Received STUN ping response, id=54625555654b65315061514c, code=0, rtt=7, pings_since_last_response=54625555654b65315061514c
(p2ptransportchannel.cc:253): Switching selected connection due to: candidate pair state changed
(p2ptransportchannel.cc:1674): Channel[data|1|__]: New selected connection: Conn[000000000EB5C890:data:Net[LogMeIn:2620:9b::192d:fd47/128:Ethernet:id=2]:yubgnfM1:1:0:local:udp:[2620:9b::192d:fd47]:49514->z034NaYK:1:2122262783:local:udp:[2620:9b::192d:fd47]:57717|CRWS|S|1|0|9115049250747470334|7]
(dtlstransport.cc:808): DtlsTransport[data|1|__]: configuring DTLS handshake timeout 50 based on ICE RTT 7
(opensslstreamadapter.cc:760): BeginSSL with peer.
(openssladapter.cc:819): SSL_connect:TLS client enter_early_data
(openssladapter.cc:819): SSL_connect:TLS client read_hello_verify_request
(openssladapter.cc:829): SSL_connect:error in TLS client read_hello_verify_request
(dtlstransport.cc:717): DtlsTransport[data|1|__]: DtlsTransport: Started DTLS handshake
(srtptransport.cc:354): The params in SRTP transport are reset.
(basicportallocator.cc:1087): All candidates gathered for data:1:0
(p2ptransportchannel.cc:766): P2PTransportChannel: data, component 1 gathering complete
(basicportallocator.cc:889): Port[000000000EB8DF60:data:1:0:local:Net[Realtek:192.168.0.105/32:Ethernet:id=1]]: Gathered candidate: Cand[:3382296128:1:udp:1685987071:219.75.109.151:49515:stun:192.168.0.105:49515:/HXf:x7vYNbzdu+jkqXyraYP+/hjv:1:0:0]
(basicportallocator.cc:894): Discarding candidate because port is already done gathering.
(basicportallocator.cc:991): Port[000000000EB8DF60:data:1:0:local:Net[Realtek:192.168.0.105/32:Ethernet:id=1]]: Port completed gathering candidates.
(openssladapter.cc:819): SSL_connect:TLS client read_server_hello
(openssladapter.cc:819): SSL_connect:TLS client read_server_certificate
(openssladapter.cc:819): SSL_connect:TLS client read_certificate_status
(openssladapter.cc:819): SSL_connect:TLS client verify_server_certificate
(opensslstreamadapter.cc:1084): Accepted peer certificate.
(openssladapter.cc:819): SSL_connect:TLS client read_server_key_exchange
(openssladapter.cc:819): SSL_connect:TLS client read_certificate_request
(openssladapter.cc:819): SSL_connect:TLS client read_server_hello_done
(openssladapter.cc:819): SSL_connect:TLS client send_client_certificate
(openssladapter.cc:819): SSL_connect:TLS client send_client_key_exchange
(openssladapter.cc:819): SSL_connect:TLS client send_client_certificate_verify
(openssladapter.cc:819): SSL_connect:TLS client send_client_finished
(openssladapter.cc:819): SSL_connect:TLS client finish_flight
(openssladapter.cc:819): SSL_connect:TLS client read_session_ticket
(openssladapter.cc:829): SSL_connect:error in TLS client read_session_ticket
(openssladapter.cc:819): SSL_connect:TLS client process_change_cipher_spec
(openssladapter.cc:819): SSL_connect:TLS client read_server_finished
(openssladapter.cc:819): SSL_connect:TLS client finish_client_handshake
(openssladapter.cc:819): SSL_connect:TLS client done
(dtlstransport.cc:645): DtlsTransport[data|1|__]: DTLS handshake complete.
(jseptransportcontroller.cc:1088):  Transport data writability changed to 1.
(dtlssrtptransport.cc:215): Extracting keys from transport: data
(peerconnection.cc:5223): Changing to ICE connected state because all transports are writable.
(peerconnection.cc:3463): Changing IceConnectionState 1 => 2
(srtptransport.cc:294): SRTP activated with negotiated parameters: send cipher_suite 1 recv cipher_suite 1
(sctptransport.cc:233): cricket::SctpTransport::UsrSctpWrapper::InitializeUsrSctp
Player connected
1 is connected. RPCing register player now
Network Players: {1:{char:res://Players/Axeman.tscn, name:Philip Wee}, 1832737670:{char:res://Players/Axeman.tscn, name:Philip Wee}}

(port.cc:1243): Conn[000000000EB9B1E0:data:Net[Realtek:192.168.0.105/32:Ethernet:id=1]:B4NH1TxE:1:0:local:udp:192.168.0.105:49515->U3KkwIDF:1:2122194687:local:udp:192.168.0.105:57718|C--W|-|0|0|9114756780654345726|-]: Received STUN ping, id=45396f433158367534554950
(port.cc:807): Port[000000000EB8DF60:data:1:0:local:Net[Realtek:192.168.0.105/32:Ethernet:id=1]]: Sent STUN ping response, to=192.168.0.105:57718, id=45396f433158367534554950
(p2ptransportchannel.cc:2284): Selecting connection for triggered check: Conn[000000000EB9B1E0:data:Net[Realtek:192.168.0.105/32:Ethernet:id=1]:B4NH1TxE:1:0:local:udp:192.168.0.105:49515->U3KkwIDF:1:2122194687:local:udp:192.168.0.105:57718|CR-W|-|0|0|9114756780654345726|-]
(port.cc:1711): Conn[000000000EB9B1E0:data:Net[Realtek:192.168.0.105/32:Ethernet:id=1]:B4NH1TxE:1:0:local:udp:192.168.0.105:49515->U3KkwIDF:1:2122194687:local:udp:192.168.0.105:57718|CR-W|-|0|0|9114756780654345726|-]: Sent STUN ping, id=614678514d745a7a59447244, use_candidate=0, nomination=0
(port.cc:1655): Conn[000000000EB9B1E0:data:Net[Realtek:192.168.0.105/32:Ethernet:id=1]:B4NH1TxE:1:0:local:udp:192.168.0.105:49515->U3KkwIDF:1:2122194687:local:udp:192.168.0.105:57718|CR-I|-|0|0|9114756780654345726|-]: Received STUN ping response, id=614678514d745a7a59447244, code=0, rtt=0, pings_since_last_response=614678514d745a7a59447244
(port.cc:1357): Conn[000000000EB9BE70:data:Net[Realtek:192.168.0.105/32:Ethernet:id=1]:B4NH1TxE:1:0:local:udp:192.168.0.105:49515->QdUELJ5+:1:2122129151:local:udp:172.27.29.15:57719|C--W|-|0|0|9114475305677635070|-]: Connection pruned
(port.cc:1357): Conn[000000000EB9CB00:data:Net[Realtek:192.168.0.105/32:Ethernet:id=1]:B4NH1TxE:1:0:local:udp:192.168.0.105:49515->3lvkWPsm:1:1685987071:stun:udp:219.75.109.151:57718|C--W|-|0|0|7241259335668219390|-]: Connection pruned
(port.cc:1711): Conn[000000000EBA7DF0:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->U3KkwIDF:1:2122194687:local:udp:192.168.0.105:57718|C--W|-|0|0|9114475305677635071|-]: Sent STUN ping, id=47574a57576d73734648427a, use_candidate=0, nomination=0
(port.cc:1243): Conn[000000000EBA8A80:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->QdUELJ5+:1:2122129151:local:udp:172.27.29.15:57719|C--W|-|0|0|9114475305677503998|-]: Received STUN ping, id=38314544426b6b6c49525162
(port.cc:807): Port[000000000EB998F0:data:1:0:local:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]]: Sent STUN ping response, to=172.27.29.15:57719, id=38314544426b6b6c49525162
(p2ptransportchannel.cc:2284): Selecting connection for triggered check: Conn[000000000EBA8A80:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->QdUELJ5+:1:2122129151:local:udp:172.27.29.15:57719|CR-W|-|0|0|9114475305677503998|-]
(port.cc:1711): Conn[000000000EBA8A80:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->QdUELJ5+:1:2122129151:local:udp:172.27.29.15:57719|CR-W|-|0|0|9114475305677503998|-]: Sent STUN ping, id=544e4a6a352f5978556b684b, use_candidate=0, nomination=0
(port.cc:1655): Conn[000000000EBA8A80:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->QdUELJ5+:1:2122129151:local:udp:172.27.29.15:57719|CR-I|-|0|0|9114475305677503998|-]: Received STUN ping response, id=544e4a6a352f5978556b684b, code=0, rtt=1, pings_since_last_response=544e4a6a352f5978556b684b
(port.cc:1357): Conn[000000000EBA9710:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->3lvkWPsm:1:1685987071:stun:udp:219.75.109.151:57718|C--W|-|0|0|7241259335668088318|-]: Connection pruned
(port.cc:1711): Conn[000000000EBA7DF0:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->U3KkwIDF:1:2122194687:local:udp:192.168.0.105:57718|C--I|-|0|0|9114475305677635071|-]: Sent STUN ping, id=56394839584f2b5568684a37, use_candidate=0, nomination=0
(port.cc:1711): Conn[000000000EBA7DF0:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->U3KkwIDF:1:2122194687:local:udp:192.168.0.105:57718|C--I|-|0|0|9114475305677635071|-]: Sent STUN ping, id=58654b4d45316e4135745a57, use_candidate=0, nomination=0
(port.cc:1711): Conn[000000000EBA7DF0:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->U3KkwIDF:1:2122194687:local:udp:192.168.0.105:57718|C--I|-|0|0|9114475305677635071|-]: Sent STUN ping, id=6d6659316a4e457838335a5a, use_candidate=0, nomination=0
(port.cc:1711): Conn[000000000EBA7DF0:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->U3KkwIDF:1:2122194687:local:udp:192.168.0.105:57718|C--I|-|0|0|9114475305677635071|-]: Sent STUN ping, id=7434474c41725a7270483055, use_candidate=0, nomination=0
(port.cc:1711): Conn[000000000EBA7DF0:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->U3KkwIDF:1:2122194687:local:udp:192.168.0.105:57718|C--I|-|0|0|9114475305677635071|-]: Sent STUN ping, id=7a515049675152637747746e, use_candidate=0, nomination=0
(port.cc:1711): Conn[000000000EBA7DF0:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->U3KkwIDF:1:2122194687:local:udp:192.168.0.105:57718|C--I|-|0|0|9114475305677635071|-]: Sent STUN ping, id=427a39714351524d366b4c6d, use_candidate=0, nomination=0
(port.cc:1711): Conn[000000000EBA7DF0:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->U3KkwIDF:1:2122194687:local:udp:192.168.0.105:57718|C--I|-|0|0|9114475305677635071|-]: Sent STUN ping, id=7a6f4868306c727142624951, use_candidate=0, nomination=0
(port.cc:1711): Conn[000000000EBA7DF0:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->U3KkwIDF:1:2122194687:local:udp:192.168.0.105:57718|C--I|-|0|0|9114475305677635071|-]: Sent STUN ping, id=6850627256504f434533724b, use_candidate=0, nomination=0
(port.cc:1758): Connection deleted with number of pings sent: 0
(p2ptransportchannel.cc:2122): Channel[data|1|RW]: Removed connection 000000000EB9BE70 (6 remaining)
(port.cc:1758): Connection deleted with number of pings sent: 0
(p2ptransportchannel.cc:2122): Channel[data|1|RW]: Removed connection 000000000EB9CB00 (5 remaining)
(port.cc:1758): Connection deleted with number of pings sent: 0
(p2ptransportchannel.cc:2122): Channel[data|1|RW]: Removed connection 000000000EBA9710 (4 remaining)
(port.cc:1711): Conn[000000000EBA7DF0:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->U3KkwIDF:1:2122194687:local:udp:192.168.0.105:57718|C--I|-|0|0|9114475305677635071|-]: Sent STUN ping, id=567175774871306664563868, use_candidate=0, nomination=0
(port.cc:1711): Conn[000000000EBA7DF0:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->U3KkwIDF:1:2122194687:local:udp:192.168.0.105:57718|C--I|-|0|0|9114475305677635071|-]: Sent STUN ping, id=4d38557266765171476f314b, use_candidate=0, nomination=0
(port.cc:1711): Conn[000000000EBA7DF0:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->U3KkwIDF:1:2122194687:local:udp:192.168.0.105:57718|C--I|-|0|0|9114475305677635071|-]: Sent STUN ping, id=337a777039337351654b5845, use_candidate=0, nomination=0
(port.cc:1711): Conn[000000000EBA7DF0:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->U3KkwIDF:1:2122194687:local:udp:192.168.0.105:57718|C--I|-|0|0|9114475305677635071|-]: Sent STUN ping, id=6331436a5168364c44436451, use_candidate=0, nomination=0
(port.cc:1448): Conn[000000000EBA7DF0:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->U3KkwIDF:1:2122194687:local:udp:192.168.0.105:57718|C--I|-|0|0|9114475305677635071|-]: Timed out after 15015 ms without a response, rtt=6000
(p2ptransportchannel.cc:1716): Channel[data|1|RW]: Transport channel state changed from 1 to 2
(jseptransportcontroller.cc:1158): data Transport 1 state changed. Check if state is complete.
(port.cc:1758): Connection deleted with number of pings sent: 13
(p2ptransportchannel.cc:2122): Channel[data|1|RW]: Removed connection 000000000EBA7DF0 (3 remaining)
(stunport.cc:87): Binding request timed out from 172.27.29.15:49516 (ZeroTier One [a0cbf4b62aaa1de6])
(basicportallocator.cc:991): Port[000000000EB998F0:data:1:0:local:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]]: Port completed gathering candidates.

Godot version: v3.2.1 WebRTC version: v0.3 (Both debug and release versions have the issue)

Relevant files: Network.zip We used the multiplayer_client.gd ws_webrtc_client.gd from the bomber demo but perhaps with some slight changes so that could be causing the issue too

If you would like the whole game file please drop me a message I'll send the entire file over

Faless commented 4 years ago

Yes, please provide MINIMUM reproduction project.

On Sat, Aug 22, 2020, 09:04 Philip Andrew Wee De Wang < notifications@github.com> wrote:

When using the webrtc plugin, I created a script to check the network latency and perform error correction:

TIMING COORDINATION

var sent_timings = [] var received_timings = []

func perform_latency_correction(id): for _i in range(9):

  sent_timings.append(curTime)
  rpc_id(id,"send_response_to_server")
  yield(get_tree().create_timer(0.05),"timeout")

while len(received_timings) < 9: print('stuck') print(len(sent_timings)) print(len(received_timings)) yield(get_tree().create_timer(0.05),"timeout") var time_diffs = [] for i in range(9): time_diffs.append(received_timings[i] - sent_timings[i]) time_diffs.sort() var total_lag = time_diffs[4] print(received_timings) print(sent_timings) print("Total Lag:",total_lag)

remote func store_response_from_client(): yield(fakeLag(),"timeout") received_timings.append(curTime)

remote func send_response_to_server(): yield(fakeLag(),"timeout") rpc_id(1,"store_response_from_client")

Function for simulating lag

func fakeLag(): return get_tree().create_timer(FAKE_LAG_SECS)

TIMING COORDINATION

However, this function fails intermittently, with some rpc_id calls not reaching the other user [image: image] https://user-images.githubusercontent.com/41712275/90951508-3857f980-e48e-11ea-8341-2b80f7e67b97.png

Interestingly, we no longer experience the intermittent issue when adding a print statement before the rpc call

TIMING COORDINATION

var sent_timings = [] var received_timings = []

func perform_latency_correction(id): for _i in range(9): print('WITH THIS PRINT IT WILL NO LONGER FAIL') sent_timings.append(curTime) rpc_id(id,"send_response_to_server") yield(get_tree().create_timer(0.05),"timeout") while len(received_timings) < 9: print('stuck') print(len(sent_timings)) print(len(received_timings)) yield(get_tree().create_timer(0.05),"timeout") var time_diffs = [] for i in range(9): time_diffs.append(received_timings[i] - sent_timings[i]) time_diffs.sort() var total_lag = time_diffs[4] print(received_timings) print(sent_timings) print("Total Lag:",total_lag)

remote func store_response_from_client(): yield(fakeLag(),"timeout") received_timings.append(curTime)

remote func send_response_to_server(): yield(fakeLag(),"timeout") rpc_id(1,"store_response_from_client")

Function for simulating lag

func fakeLag(): return get_tree().create_timer(FAKE_LAG_SECS)

TIMING COORDINATION

The above code always returning this: [image: image] https://user-images.githubusercontent.com/41712275/90951582-b61c0500-e48e-11ea-9e97-799b90fe1b04.png

Other things that we have tried: Running two rpc_id commands in a row with the print command (THIS WORKS):

func perform_latency_correction(id): for _i in range(9): print('WITH THIS PRINT IT WILL NO LONGER FAIL') sent_timings.append(curTime) rpc_id(id,"send_response_to_server") rpc_id(id,"send_response_to_server") yield(get_tree().create_timer(0.05),"timeout")

Running two rpc_id commands in a row without the print command (DOES NOT WORK):

func perform_latency_correction(id): for _i in range(9):

  sent_timings.append(curTime)
  rpc_id(id,"send_response_to_server")
  rpc_id(id,"send_response_to_server")
  yield(get_tree().create_timer(0.05),"timeout")

Note that the above command, when fails for both rpc calls

Sample webrtc debug print when above fails with this output: [image: image] https://user-images.githubusercontent.com/41712275/90951796-9685dc00-e490-11ea-8ecf-eb9bc82acc4d.png

Godot Engine v3.2.1.stable.official - https://godotengine.org OpenGL ES 3.0 Renderer: GeForce RTX 2070 with Max-Q Design/PCIe/SSE2

Join Button Pressed Connected 1832737670 Peer connected 1 (opensslidentity.cc:45): Making key pair (peerconnection.cc:849): Session: 2527941224590814886 is destroyed. (opensslidentity.cc:93): Returning key pair (opensslcertificate.cc:58): Making certificate for WebRTC (opensslcertificate.cc:105): Returning certificate (opensslidentity.cc:45): Making key pair (peerconnection.cc:5072): AddSctpDataStream called when sctptransport is NULL. (peerconnection.cc:5072): AddSctpDataStream called when sctptransport is NULL. (peerconnection.cc:5072): AddSctpDataStream called when sctptransport is NULL. (opensslidentity.cc:93): Returning key pair (opensslcertificate.cc:58): Making certificate for WebRTC Setting Network Peer WwwREf1QdjIYlK2M (opensslcertificate.cc:105): Returning certificate Network Players: {1832737670:{char:res://Players/Axeman.tscn, name:Philip Wee}}

Got offer: 1 (webrtcsdp.cc:2955): Ignored line: a=sctpmap:5000 webrtc-datachannel 1024 (webrtcsdp.cc:1727): AddSctpDataCodec: Got SCTP Port Number 5000 (p2ptransportchannel.cc:437): Set backup connection ping interval to 25000 milliseconds. (p2ptransportchannel.cc:446): Set ICE receiving timeout to 2500 milliseconds (p2ptransportchannel.cc:453): Set ping most likely connection to 0 (p2ptransportchannel.cc:460): Set stable_writable_connection_ping_interval to 2500 (p2ptransportchannel.cc:473): Set presume writable when fully relayed to 0 (p2ptransportchannel.cc:482): Set regather_on_failed_networks_interval to 300000 (p2ptransportchannel.cc:501): Set receiving_switching_delay to 1000 (dtlssrtptransport.cc:57): Setting RTCP Transport on data transport 0000000000000000 (dtlssrtptransport.cc:62): Setting RTP Transport on data transport 000000000EA983B0 (p2ptransportchannel.cc:385): Received remote ICE parameters: ufrag=gb33, renomination disabled (peerconnection.cc:3506): Session: 7894624426572364422 Old state: kStable New state: kHaveRemoteOffer (peerconnection.cc:4756): Local and Remote descriptions must be applied to get the SSL Role of the SCTP transport. (peerconnection.cc:4778): Local and Remote descriptions must be applied to get the SSL Role of the session. (peerconnection.cc:5393): data is not ready to use the remote candidate because the local or remote description is not set. (peerconnection.cc:5393): data is not ready to use the remote candidate because the local or remote description is not set. (peerconnection.cc:5393): data is not ready to use the remote candidate because the local or remote description is not set. createdanswer (webrtcsdp.cc:2955): Ignored line: a=sctpmap:5000 webrtc-datachannel 1024 (webrtcsdp.cc:1727): AddSctpDataCodec: Got SCTP Port Number 5000 (dtlssrtptransport.cc:57): Setting RTCP Transport on data transport 0000000000000000 (dtlssrtptransport.cc:62): Setting RTP Transport on data transport 000000000EA983B0 (p2ptransportchannel.cc:374): Set ICE ufrag: /HXf pwd: x7vYNbzdu+jkqXyraYP+/hjv on transport data (dtlstransport.cc:383): DtlsTransport[data|1|]: DTLS setup complete. (peerconnection.cc:3506): Session: 7894624426572364422 Old state: kHaveRemoteOffer New state: kStable (peerconnection.cc:3463): Changing IceConnectionState 0 => 1 (basicportallocator.cc:339): Start getting ports with prune_turn_ports disabled (basicportallocator.cc:107): Filtered out ignored networks: (basicportallocator.cc:109): Net[Software:::1/128:Loopback:id=4] (basicportallocator.cc:109): Net[Software:127.0.0.1/32:Loopback:id=3] (basicportallocator.cc:829): Network manager has started (basicportallocator.cc:107): Filtered out ignored networks: (basicportallocator.cc:109): Net[Software:::1/128:Loopback:id=4] (basicportallocator.cc:109): Net[Software:127.0.0.1/32:Loopback:id=3] (basicportallocator.cc:744): Allocate ports on 3 networks (basicportallocator.cc:1284): Net[LogMeIn:2620:9b::192d:fd47/128:Ethernet:id=2]: Allocation Phase=Udp (port.cc:328): Port[000000000EB45AF0::1:0:local:Net[LogMeIn:2620:9b::192d:fd47/128:Ethernet:id=2]]: Port created with network cost 0 (basicportallocator.cc:1355): AllocationSequence: UDPPort will be handling the STUN candidate generation. (basicportallocator.cc:851): Adding allocated port for data (basicportallocator.cc:871): Port[000000000EB45AF0:data:1:0:local:Net[LogMeIn:2620:9b::192d:fd47/128:Ethernet:id=2]]: Added port to allocator (basicportallocator.cc:889): Port[000000000EB45AF0:data:1:0:local:Net[LogMeIn:2620:9b::192d:fd47/128:Ethernet:id=2]]: Gathered candidate: Cand[:3490071206:1:udp:2122262783:[2620:9b::192d:fd47]:49514:local::0:/HXf:x7vYNbzdu+jkqXyraYP+/hjv:2:0:0] (basicportallocator.cc:917): Port[000000000EB45AF0:data:1:0:local:Net[LogMeIn:2620:9b::192d:fd47/128:Ethernet:id=2]]: Port ready. (port.cc:1086): Conn[000000000EB5C890:data:Net[LogMeIn:2620:9b::192d:fd47/128:Ethernet:id=2]:yubgnfM1:1:0:local:udp:[2620:9b::192d:fd47]:49514->z034NaYK:1:2122262783:local:udp:[2620:9b::192d:fd47]:57717|C--W|-|0|0|9115049250747470334|-]: Connection created (p2ptransportchannel.cc:1074): Channel[data|1|]: Created connection with origin: 2, total: 1 (p2ptransportchannel.cc:1716): Channel[data|1|]: Transport channel state changed from 0 to 2 (jseptransportcontroller.cc:1158): data Transport 1 state changed. Check if state is complete. (p2ptransportchannel.cc:1288): Channel[data|1|]: Have a pingable connection for the first time; starting to ping. (stunport.cc:392): Port[000000000EB45AF0:data:1:0:local:Net[LogMeIn:2620:9b::192d:fd47/128:Ethernet:id=2]]: Starting STUN host lookup for stun.l.google.com:19302 (basicportallocator.cc:1284): Net[Realtek:192.168.0.105/32:Ethernet:id=1]: Allocation Phase=Udp (port.cc:328): Port[000000000EB8DF60::1:0:local:Net[Realtek:192.168.0.105/32:Ethernet:id=1] http://192.168.0.105/32:Ethernet:id=1%5D]: Port created with network cost 0 (basicportallocator.cc:1355): AllocationSequence: UDPPort will be handling the STUN candidate generation. (basicportallocator.cc:851): Adding allocated port for data (basicportallocator.cc:871): Port[000000000EB8DF60:data:1:0:local:Net[Realtek:192.168.0.105/32:Ethernet:id=1] http://192.168.0.105/32:Ethernet:id=1%5D]: Added port to allocator (basicportallocator.cc:889): Port[000000000EB8DF60:data:1:0:local:Net[Realtek:192.168.0.105/32:Ethernet:id=1] http://192.168.0.105/32:Ethernet:id=1%5D]: Gathered candidate: Cand[:1221703924:1:udp:2122194687:192.168.0.105:49515:local::0:/HXf:x7vYNbzdu+jkqXyraYP+/hjv:1:0:0] (basicportallocator.cc:917): Port[000000000EB8DF60:data:1:0:local:Net[Realtek:192.168.0.105/32:Ethernet:id=1] http://192.168.0.105/32:Ethernet:id=1%5D]: Port ready. (port.cc:1086): Conn[000000000EB9B1E0:data:Net[Realtek:192.168.0.105/32:Ethernet:id=1]:B4NH1TxE:1:0:local:udp:192.168.0.105:49515- http://192.168.0.105/32:Ethernet:id=1%5D:B4NH1TxE:1:0:local:udp:192.168.0.105:49515->U3KkwIDF:1:2122194687:local:udp:192.168.0.105:57718|C--W|-|0|0|9114756780654345726|-]: Connection created (p2ptransportchannel.cc:1074): Channel[data|1|]: Created connection with origin: 2, total: 2 (port.cc:1086): Conn[000000000EB9BE70:data:Net[Realtek:192.168.0.105/32:Ethernet:id=1]:B4NH1TxE:1:0:local:udp:192.168.0.105:49515- http://192.168.0.105/32:Ethernet:id=1%5D:B4NH1TxE:1:0:local:udp:192.168.0.105:49515->QdUELJ5+:1:2122129151:local:udp:172.27.29.15:57719|C--W|-|0|0|9114475305677635070|-]: Connection created (p2ptransportchannel.cc:1074): Channel[data|1|]: Created connection with origin: 2, total: 3 (port.cc:1086): Conn[000000000EB9CB00:data:Net[Realtek:192.168.0.105/32:Ethernet:id=1]:B4NH1TxE:1:0:local:udp:192.168.0.105:49515- http://192.168.0.105/32:Ethernet:id=1%5D:B4NH1TxE:1:0:local:udp:192.168.0.105:49515->3lvkWPsm:1:1685987071:stun:udp:219.75.109.151:57718|C--W|-|0|0|7241259335668219390|-]: Connection created (p2ptransportchannel.cc:1074): Channel[data|1|]: Created connection with origin: 2, total: 4 (p2ptransportchannel.cc:1716): Channel[data|1|]: Transport channel state changed from 2 to 1 (jseptransportcontroller.cc:1158): data Transport 1 state changed. Check if state is complete. (stunport.cc:392): Port[000000000EB8DF60:data:1:0:local:Net[Realtek:192.168.0.105/32:Ethernet:id=1] http://192.168.0.105/32:Ethernet:id=1%5D]: Starting STUN host lookup for stun.l.google.com:19302 (basicportallocator.cc:1284): Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]: Allocation Phase=Udp (port.cc:328): Port[000000000EB998F0::1:0:local:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5] http://172.27.29.15/32:Ethernet:id=5%5D]: Port created with network cost 0 (basicportallocator.cc:1355): AllocationSequence: UDPPort will be handling the STUN candidate generation. (basicportallocator.cc:851): Adding allocated port for data (basicportallocator.cc:871): Port[000000000EB998F0:data:1:0:local:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5] http://172.27.29.15/32:Ethernet:id=5%5D]: Added port to allocator (basicportallocator.cc:889): Port[000000000EB998F0:data:1:0:local:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5] http://172.27.29.15/32:Ethernet:id=5%5D]: Gathered candidate: Cand[:3192801181:1:udp:2122129151:172.27.29.15:49516:local::0:/HXf:x7vYNbzdu+jkqXyraYP+/hjv:5:0:0] (basicportallocator.cc:917): Port[000000000EB998F0:data:1:0:local:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5] http://172.27.29.15/32:Ethernet:id=5%5D]: Port ready. (port.cc:1086): Conn[000000000EBA7DF0:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516- http://172.27.29.15/32:Ethernet:id=5%5D:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->U3KkwIDF:1:2122194687:local:udp:192.168.0.105:57718|C--W|-|0|0|9114475305677635071|-]: Connection created (p2ptransportchannel.cc:1074): Channel[data|1|]: Created connection with origin: 2, total: 5 (port.cc:1086): Conn[000000000EBA8A80:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516- http://172.27.29.15/32:Ethernet:id=5%5D:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->QdUELJ5+:1:2122129151:local:udp:172.27.29.15:57719|C--W|-|0|0|9114475305677503998|-]: Connection created (p2ptransportchannel.cc:1074): Channel[data|1|]: Created connection with origin: 2, total: 6 (port.cc:1086): Conn[000000000EBA9710:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516- http://172.27.29.15/32:Ethernet:id=5%5D:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->3lvkWPsm:1:1685987071:stun:udp:219.75.109.151:57718|C--W|-|0|0|7241259335668088318|-]: Connection created (p2ptransportchannel.cc:1074): Channel[data|1|]: Created connection with origin: 2, total: 7 (stunport.cc:392): Port[000000000EB998F0:data:1:0:local:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5] http://172.27.29.15/32:Ethernet:id=5%5D]: Starting STUN host lookup for stun.l.google.com:19302 (port.cc:1711): Conn[000000000EB5C890:data:Net[LogMeIn:2620:9b::192d:fd47/128:Ethernet:id=2]:yubgnfM1:1:0:local:udp:[2620:9b::192d:fd47]:49514->z034NaYK:1:2122262783:local:udp:[2620:9b::192d:fd47]:57717|C--W|-|0|0|9115049250747470334|-]: Sent STUN ping, id=54625555654b65315061514c, use_candidate=0, nomination=0 (stunport.cc:405): Port[000000000EB45AF0:data:1:0:local:Net[LogMeIn:2620:9b::192d:fd47/128:Ethernet:id=2]]: StunPort: stun host lookup received error 0 (basicportallocator.cc:991): Port[000000000EB45AF0:data:1:0:local:Net[LogMeIn:2620:9b::192d:fd47/128:Ethernet:id=2]]: Port completed gathering candidates. (thread.cc:273): Waiting for the thread to join, but blocking calls have been disallowed (thread.cc:273): Waiting for the thread to join, but blocking calls have been disallowed (thread.cc:273): Waiting for the thread to join, but blocking calls have been disallowed (port.cc:1243): Conn[000000000EB5C890:data:Net[LogMeIn:2620:9b::192d:fd47/128:Ethernet:id=2]:yubgnfM1:1:0:local:udp:[2620:9b::192d:fd47]:49514->z034NaYK:1:2122262783:local:udp:[2620:9b::192d:fd47]:57717|C--I|-|0|0|9115049250747470334|-]: Received STUN ping, id=35666546336150526278432f (port.cc:807): Port[000000000EB45AF0:data:1:0:local:Net[LogMeIn:2620:9b::192d:fd47/128:Ethernet:id=2]]: Sent STUN ping response, to=[2620:9b::192d:fd47]:57717, id=35666546336150526278432f (p2ptransportchannel.cc:933): Not switching the selected connection on controlled side yet: Conn[000000000EB5C890:data:Net[LogMeIn:2620:9b::192d:fd47/128:Ethernet:id=2]:yubgnfM1:1:0:local:udp:[2620:9b::192d:fd47]:49514->z034NaYK:1:2122262783:local:udp:[2620:9b::192d:fd47]:57717|CR-I|-|1|0|9115049250747470334|-] (port.cc:1655): Conn[000000000EB5C890:data:Net[LogMeIn:2620:9b::192d:fd47/128:Ethernet:id=2]:yubgnfM1:1:0:local:udp:[2620:9b::192d:fd47]:49514->z034NaYK:1:2122262783:local:udp:[2620:9b::192d:fd47]:57717|CR-I|-|1|0|9115049250747470334|-]: Received STUN ping response, id=54625555654b65315061514c, code=0, rtt=7, pings_since_last_response=54625555654b65315061514c (p2ptransportchannel.cc:253): Switching selected connection due to: candidate pair state changed (p2ptransportchannel.cc:1674): Channel[data|1|]: New selected connection: Conn[000000000EB5C890:data:Net[LogMeIn:2620:9b::192d:fd47/128:Ethernet:id=2]:yubgnfM1:1:0:local:udp:[2620:9b::192d:fd47]:49514->z034NaYK:1:2122262783:local:udp:[2620:9b::192d:fd47]:57717|CRWS|S|1|0|9115049250747470334|7] (dtlstransport.cc:808): DtlsTransport[data|1|__]: configuring DTLS handshake timeout 50 based on ICE RTT 7 (opensslstreamadapter.cc:760): BeginSSL with peer. (openssladapter.cc:819): SSL_connect:TLS client enter_early_data (openssladapter.cc:819): SSL_connect:TLS client read_hello_verify_request (openssladapter.cc:829): SSL_connect:error in TLS client read_hello_verify_request (dtlstransport.cc:717): DtlsTransport[data|1|]: DtlsTransport: Started DTLS handshake (srtptransport.cc:354): The params in SRTP transport are reset. (basicportallocator.cc:1087): All candidates gathered for data:1:0 (p2ptransportchannel.cc:766): P2PTransportChannel: data, component 1 gathering complete (basicportallocator.cc:889): Port[000000000EB8DF60:data:1:0:local:Net[Realtek:192.168.0.105/32:Ethernet:id=1] http://192.168.0.105/32:Ethernet:id=1%5D]: Gathered candidate: Cand[:3382296128:1:udp:1685987071:219.75.109.151:49515:stun:192.168.0.105:49515:/HXf:x7vYNbzdu+jkqXyraYP+/hjv:1:0:0] (basicportallocator.cc:894): Discarding candidate because port is already done gathering. (basicportallocator.cc:991): Port[000000000EB8DF60:data:1:0:local:Net[Realtek:192.168.0.105/32:Ethernet:id=1] http://192.168.0.105/32:Ethernet:id=1%5D]: Port completed gathering candidates. (openssladapter.cc:819): SSL_connect:TLS client read_server_hello (openssladapter.cc:819): SSL_connect:TLS client read_server_certificate (openssladapter.cc:819): SSL_connect:TLS client read_certificate_status (openssladapter.cc:819): SSL_connect:TLS client verify_server_certificate (opensslstreamadapter.cc:1084): Accepted peer certificate. (openssladapter.cc:819): SSL_connect:TLS client read_server_key_exchange (openssladapter.cc:819): SSL_connect:TLS client read_certificate_request (openssladapter.cc:819): SSL_connect:TLS client read_server_hello_done (openssladapter.cc:819): SSL_connect:TLS client send_client_certificate (openssladapter.cc:819): SSL_connect:TLS client send_client_key_exchange (openssladapter.cc:819): SSL_connect:TLS client send_client_certificate_verify (openssladapter.cc:819): SSL_connect:TLS client send_client_finished (openssladapter.cc:819): SSL_connect:TLS client finish_flight (openssladapter.cc:819): SSL_connect:TLS client read_session_ticket (openssladapter.cc:829): SSL_connect:error in TLS client read_session_ticket (openssladapter.cc:819): SSL_connect:TLS client process_change_cipher_spec (openssladapter.cc:819): SSL_connect:TLS client read_server_finished (openssladapter.cc:819): SSL_connect:TLS client finish_client_handshake (openssladapter.cc:819): SSL_connect:TLS client done (dtlstransport.cc:645): DtlsTransport[data|1|]: DTLS handshake complete. (jseptransportcontroller.cc:1088): Transport data writability changed to 1. (dtlssrtptransport.cc:215): Extracting keys from transport: data (peerconnection.cc:5223): Changing to ICE connected state because all transports are writable. (peerconnection.cc:3463): Changing IceConnectionState 1 => 2 (srtptransport.cc:294): SRTP activated with negotiated parameters: send cipher_suite 1 recv cipher_suite 1 (sctptransport.cc:233): cricket::SctpTransport::UsrSctpWrapper::InitializeUsrSctp Player connected 1 is connected. RPCing register player now Network Players: {1:{char:res://Players/Axeman.tscn, name:Philip Wee}, 1832737670:{char:res://Players/Axeman.tscn, name:Philip Wee}}

(port.cc:1243): Conn[000000000EB9B1E0:data:Net[Realtek:192.168.0.105/32:Ethernet:id=1]:B4NH1TxE:1:0:local:udp:192.168.0.105:49515- http://192.168.0.105/32:Ethernet:id=1%5D:B4NH1TxE:1:0:local:udp:192.168.0.105:49515->U3KkwIDF:1:2122194687:local:udp:192.168.0.105:57718|C--W|-|0|0|9114756780654345726|-]: Received STUN ping, id=45396f433158367534554950 (port.cc:807): Port[000000000EB8DF60:data:1:0:local:Net[Realtek:192.168.0.105/32:Ethernet:id=1] http://192.168.0.105/32:Ethernet:id=1%5D]: Sent STUN ping response, to=192.168.0.105:57718, id=45396f433158367534554950 (p2ptransportchannel.cc:2284): Selecting connection for triggered check: Conn[000000000EB9B1E0:data:Net[Realtek:192.168.0.105/32:Ethernet:id=1]:B4NH1TxE:1:0:local:udp:192.168.0.105:49515- http://192.168.0.105/32:Ethernet:id=1%5D:B4NH1TxE:1:0:local:udp:192.168.0.105:49515->U3KkwIDF:1:2122194687:local:udp:192.168.0.105:57718|CR-W|-|0|0|9114756780654345726|-] (port.cc:1711): Conn[000000000EB9B1E0:data:Net[Realtek:192.168.0.105/32:Ethernet:id=1]:B4NH1TxE:1:0:local:udp:192.168.0.105:49515- http://192.168.0.105/32:Ethernet:id=1%5D:B4NH1TxE:1:0:local:udp:192.168.0.105:49515->U3KkwIDF:1:2122194687:local:udp:192.168.0.105:57718|CR-W|-|0|0|9114756780654345726|-]: Sent STUN ping, id=614678514d745a7a59447244, use_candidate=0, nomination=0 (port.cc:1655): Conn[000000000EB9B1E0:data:Net[Realtek:192.168.0.105/32:Ethernet:id=1]:B4NH1TxE:1:0:local:udp:192.168.0.105:49515- http://192.168.0.105/32:Ethernet:id=1%5D:B4NH1TxE:1:0:local:udp:192.168.0.105:49515->U3KkwIDF:1:2122194687:local:udp:192.168.0.105:57718|CR-I|-|0|0|9114756780654345726|-]: Received STUN ping response, id=614678514d745a7a59447244, code=0, rtt=0, pings_since_last_response=614678514d745a7a59447244 (port.cc:1357): Conn[000000000EB9BE70:data:Net[Realtek:192.168.0.105/32:Ethernet:id=1]:B4NH1TxE:1:0:local:udp:192.168.0.105:49515- http://192.168.0.105/32:Ethernet:id=1%5D:B4NH1TxE:1:0:local:udp:192.168.0.105:49515->QdUELJ5+:1:2122129151:local:udp:172.27.29.15:57719|C--W|-|0|0|9114475305677635070|-]: Connection pruned (port.cc:1357): Conn[000000000EB9CB00:data:Net[Realtek:192.168.0.105/32:Ethernet:id=1]:B4NH1TxE:1:0:local:udp:192.168.0.105:49515- http://192.168.0.105/32:Ethernet:id=1%5D:B4NH1TxE:1:0:local:udp:192.168.0.105:49515->3lvkWPsm:1:1685987071:stun:udp:219.75.109.151:57718|C--W|-|0|0|7241259335668219390|-]: Connection pruned (port.cc:1711): Conn[000000000EBA7DF0:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516- http://172.27.29.15/32:Ethernet:id=5%5D:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->U3KkwIDF:1:2122194687:local:udp:192.168.0.105:57718|C--W|-|0|0|9114475305677635071|-]: Sent STUN ping, id=47574a57576d73734648427a, use_candidate=0, nomination=0 (port.cc:1243): Conn[000000000EBA8A80:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516- http://172.27.29.15/32:Ethernet:id=5%5D:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->QdUELJ5+:1:2122129151:local:udp:172.27.29.15:57719|C--W|-|0|0|9114475305677503998|-]: Received STUN ping, id=38314544426b6b6c49525162 (port.cc:807): Port[000000000EB998F0:data:1:0:local:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5] http://172.27.29.15/32:Ethernet:id=5%5D]: Sent STUN ping response, to=172.27.29.15:57719, id=38314544426b6b6c49525162 (p2ptransportchannel.cc:2284): Selecting connection for triggered check: Conn[000000000EBA8A80:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516- http://172.27.29.15/32:Ethernet:id=5%5D:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->QdUELJ5+:1:2122129151:local:udp:172.27.29.15:57719|CR-W|-|0|0|9114475305677503998|-] (port.cc:1711): Conn[000000000EBA8A80:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516- http://172.27.29.15/32:Ethernet:id=5%5D:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->QdUELJ5+:1:2122129151:local:udp:172.27.29.15:57719|CR-W|-|0|0|9114475305677503998|-]: Sent STUN ping, id=544e4a6a352f5978556b684b, use_candidate=0, nomination=0 (port.cc:1655): Conn[000000000EBA8A80:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516- http://172.27.29.15/32:Ethernet:id=5%5D:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->QdUELJ5+:1:2122129151:local:udp:172.27.29.15:57719|CR-I|-|0|0|9114475305677503998|-]: Received STUN ping response, id=544e4a6a352f5978556b684b, code=0, rtt=1, pings_since_last_response=544e4a6a352f5978556b684b (port.cc:1357): Conn[000000000EBA9710:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516- http://172.27.29.15/32:Ethernet:id=5%5D:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->3lvkWPsm:1:1685987071:stun:udp:219.75.109.151:57718|C--W|-|0|0|7241259335668088318|-]: Connection pruned (port.cc:1711): Conn[000000000EBA7DF0:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516- http://172.27.29.15/32:Ethernet:id=5%5D:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->U3KkwIDF:1:2122194687:local:udp:192.168.0.105:57718|C--I|-|0|0|9114475305677635071|-]: Sent STUN ping, id=56394839584f2b5568684a37, use_candidate=0, nomination=0 (port.cc:1711): Conn[000000000EBA7DF0:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516- http://172.27.29.15/32:Ethernet:id=5%5D:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->U3KkwIDF:1:2122194687:local:udp:192.168.0.105:57718|C--I|-|0|0|9114475305677635071|-]: Sent STUN ping, id=58654b4d45316e4135745a57, use_candidate=0, nomination=0 (port.cc:1711): Conn[000000000EBA7DF0:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516- http://172.27.29.15/32:Ethernet:id=5%5D:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->U3KkwIDF:1:2122194687:local:udp:192.168.0.105:57718|C--I|-|0|0|9114475305677635071|-]: Sent STUN ping, id=6d6659316a4e457838335a5a, use_candidate=0, nomination=0 (port.cc:1711): Conn[000000000EBA7DF0:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516- http://172.27.29.15/32:Ethernet:id=5%5D:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->U3KkwIDF:1:2122194687:local:udp:192.168.0.105:57718|C--I|-|0|0|9114475305677635071|-]: Sent STUN ping, id=7434474c41725a7270483055, use_candidate=0, nomination=0 (port.cc:1711): Conn[000000000EBA7DF0:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516- http://172.27.29.15/32:Ethernet:id=5%5D:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->U3KkwIDF:1:2122194687:local:udp:192.168.0.105:57718|C--I|-|0|0|9114475305677635071|-]: Sent STUN ping, id=7a515049675152637747746e, use_candidate=0, nomination=0 (port.cc:1711): Conn[000000000EBA7DF0:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516- http://172.27.29.15/32:Ethernet:id=5%5D:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->U3KkwIDF:1:2122194687:local:udp:192.168.0.105:57718|C--I|-|0|0|9114475305677635071|-]: Sent STUN ping, id=427a39714351524d366b4c6d, use_candidate=0, nomination=0 (port.cc:1711): Conn[000000000EBA7DF0:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516- http://172.27.29.15/32:Ethernet:id=5%5D:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->U3KkwIDF:1:2122194687:local:udp:192.168.0.105:57718|C--I|-|0|0|9114475305677635071|-]: Sent STUN ping, id=7a6f4868306c727142624951, use_candidate=0, nomination=0 (port.cc:1711): Conn[000000000EBA7DF0:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516- http://172.27.29.15/32:Ethernet:id=5%5D:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->U3KkwIDF:1:2122194687:local:udp:192.168.0.105:57718|C--I|-|0|0|9114475305677635071|-]: Sent STUN ping, id=6850627256504f434533724b, use_candidate=0, nomination=0 (port.cc:1758): Connection deleted with number of pings sent: 0 (p2ptransportchannel.cc:2122): Channel[data|1|RW]: Removed connection 000000000EB9BE70 (6 remaining) (port.cc:1758): Connection deleted with number of pings sent: 0 (p2ptransportchannel.cc:2122): Channel[data|1|RW]: Removed connection 000000000EB9CB00 (5 remaining) (port.cc:1758): Connection deleted with number of pings sent: 0 (p2ptransportchannel.cc:2122): Channel[data|1|RW]: Removed connection 000000000EBA9710 (4 remaining) (port.cc:1711): Conn[000000000EBA7DF0:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516- http://172.27.29.15/32:Ethernet:id=5%5D:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->U3KkwIDF:1:2122194687:local:udp:192.168.0.105:57718|C--I|-|0|0|9114475305677635071|-]: Sent STUN ping, id=567175774871306664563868, use_candidate=0, nomination=0 (port.cc:1711): Conn[000000000EBA7DF0:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516- http://172.27.29.15/32:Ethernet:id=5%5D:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->U3KkwIDF:1:2122194687:local:udp:192.168.0.105:57718|C--I|-|0|0|9114475305677635071|-]: Sent STUN ping, id=4d38557266765171476f314b, use_candidate=0, nomination=0 (port.cc:1711): Conn[000000000EBA7DF0:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516- http://172.27.29.15/32:Ethernet:id=5%5D:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->U3KkwIDF:1:2122194687:local:udp:192.168.0.105:57718|C--I|-|0|0|9114475305677635071|-]: Sent STUN ping, id=337a777039337351654b5845, use_candidate=0, nomination=0 (port.cc:1711): Conn[000000000EBA7DF0:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516- http://172.27.29.15/32:Ethernet:id=5%5D:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->U3KkwIDF:1:2122194687:local:udp:192.168.0.105:57718|C--I|-|0|0|9114475305677635071|-]: Sent STUN ping, id=6331436a5168364c44436451, use_candidate=0, nomination=0 (port.cc:1448): Conn[000000000EBA7DF0:data:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5]:oP+vZj9S:1:0:local:udp:172.27.29.15:49516- http://172.27.29.15/32:Ethernet:id=5%5D:oP+vZj9S:1:0:local:udp:172.27.29.15:49516->U3KkwIDF:1:2122194687:local:udp:192.168.0.105:57718|C--I|-|0|0|9114475305677635071|-]: Timed out after 15015 ms without a response, rtt=6000 (p2ptransportchannel.cc:1716): Channel[data|1|RW]: Transport channel state changed from 1 to 2 (jseptransportcontroller.cc:1158): data Transport 1 state changed. Check if state is complete. (port.cc:1758): Connection deleted with number of pings sent: 13 (p2ptransportchannel.cc:2122): Channel[data|1|RW]: Removed connection 000000000EBA7DF0 (3 remaining) (stunport.cc:87): Binding request timed out from 172.27.29.15:49516 (ZeroTier One [a0cbf4b62aaa1de6]) (basicportallocator.cc:991): Port[000000000EB998F0:data:1:0:local:Net[ZeroTier:172.27.29.15/32:Ethernet:id=5] http://172.27.29.15/32:Ethernet:id=5%5D]: Port completed gathering candidates.

Godot version: v3.2.1 WebRTC version: v0.3 (Both debug and release versions have the issue)

Relevant files: Network.zip https://github.com/godotengine/webrtc-native/files/5112085/Network.zip We used the multiplayer_client.gd ws_webrtc_client.gd from the bomber demo but perhaps with some slight changes so that could be causing the issue too

If you would like the whole game file please drop me a message I'll send the entire file over

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/godotengine/webrtc-native/issues/21, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAM4C3RXVYC5FGFKTKU3EYDSB53YRANCNFSM4QH66CVA .

PhilipWee commented 4 years ago

Hi Faless,

While creating the minimum reproducible project I believe I have found the bug😅

Google Drive link

The issue was probably because of the following code in Network.gd:

    mp_client.rtc_mp.poll()
    while mp_client.rtc_mp.get_available_packet_count() > 0:
        _log(mp_client.rtc_mp.get_packet().get_string_from_utf8())

I think it was 'stealing' the packets from the rpc call when being run, causing the rest of the code to fail

Faless commented 4 years ago

I'm glad you solved your issue, closing as it's not a bug in Godot nor the plugin.