Since send method only support std::byte and string types, I have to make a copy to ca

There are a few things here: In your example, replacing <code

You only need to do this: <div class="snippet-clipboard-content notranslate positi

Add support for sending std::vector<uint8_t> type over DC>,about paullouisageneau/datachannel-wasm

Comments (77)

jeffRTC commented on September 15, 2024

I found out that even above code doesn't work, it causes an error,

Uncaught TypeError: Cannot read property 'length' of undefined
    at lengthBytesUTF8 (main.js:841)
    at Object.allocUTF8FromString (main.js:5493)
    at RTCDataChannel.cb (main.js:5640)

from datachannel-wasm.

paullouisageneau commented on September 15, 2024

There are a few things here:

In your example, replacing channel->send(buffer) with channel->send(std::move(buffer)) will prevent a copy when passing to the wrapper, so the only copy will be your copy.
I can't really add std::vector<uint8_t> because it must stay consistent with libdatachannel, however I can add a generic send with a pointer to data and a size.
If I'm not mistaken, the Cannot read property 'length' of undefined does not seem directly related to sending as it seems to come from the error callback of the DataChannel.

from datachannel-wasm.

paullouisageneau commented on September 15, 2024

I added a method send(const byte *data, size_t size) consistent with libdatachannel in 23d52ce

Also the 'length' of undefined error should be addressed by f6c6cb7

it would be also good to remove casting again to char* type when you are passing this back to the JS side since uint8_t type already match with JS Uint8

Actually the cast does not really have an importance in practice, from JS point of view the pointer is just an untyped address in the wasm heap which can be accessed with HEAPU8, HEAPU16, or HEAPU32.

from datachannel-wasm.

jeffRTC commented on September 15, 2024

Thanks for this. I will have a look shortly.

"Error callback of the DataChannel"

Does that mean diff part of the code?

from datachannel-wasm.

jeffRTC commented on September 15, 2024

"I can add a generic send with a pointer to data and a size"

Can you add this please?

from datachannel-wasm.

paullouisageneau commented on September 15, 2024

Does that mean diff part of the code?

Yes I think so.

"I can add a generic send with a pointer to data and a size"

Can you add this please?

I added a method send(const byte *data, size_t size) in 23d52ce, you only need to reinterpret cast the pointer to your data to byte *.

from datachannel-wasm.

jeffRTC commented on September 15, 2024

Ok.

You can see that in std::transform it causes a copy to byte vector from emscripten vector. Is there any neat way to avoid this at all?

If you can tell me how should I implement uint8_t vector type in send function it would be great. I tried to do it but ran into some things related to your virtual functions & override stuff means I even had to modify websocket.cpp just to add this...

from datachannel-wasm.

paullouisageneau commented on September 15, 2024

You only need to do this:

std::vector<uint8_t> buffer = emscripten::convertJSArrayToNumberVector<uint8_t>(reader["value"]);
channel->send(reinterpret_cast<rtc::byte*>(buffer.data()), buffer.size())

from datachannel-wasm.

jeffRTC commented on September 15, 2024

No copy with this way?

from datachannel-wasm.

paullouisageneau commented on September 15, 2024

Nope, it won't copy this way.

from datachannel-wasm.

jeffRTC commented on September 15, 2024

Ok. I used it like you said but on server side I am not seeing any messages

                dc->onMessage([this, id, wDC = make_weak_ptr(dc)](const std::variant<rtc::binary, std::string> &message) {
                    if (std::holds_alternative<rtc::binary>(message))
                    {
                        std::cout << "DEBUG: GOT BINARY" << "\n";  /// THIS NOT PRINTS so the rest code doesn't execute!! 
                        
                        auto buffer = std::get<rtc::binary>(message);

                        std::string body(reinterpret_cast<const char *>(buffer.data()), buffer.size());

                        std::cout << "Message from " << id << " received: "
                                  << body
                                  << "\n";
                    }
                });

from datachannel-wasm.

paullouisageneau commented on September 15, 2024

Could you post the exact code you use to send the message? Also, are you sure dc is stored somewhere so it is not deleted this time?

from datachannel-wasm.

jeffRTC commented on September 15, 2024

dc is stored as a global var. I can send strings and view them on server but the bytes are not. You've already seen the code, but here again,

     while (true)
    {
        emscripten::val reader = stream.call<emscripten::val>("read").await();

        if (reader["done"].isTrue())
        {
            std::cout << "Stream has been ended"
                      << "\n";
            break;
        }

        auto buffer = emscripten::convertJSArrayToNumberVector<uint8_t>(reader["value"]);

        if (auto channel = dc.lock())
        {
            channel->send(reinterpret_cast<rtc::byte*>(buffer.data()), buffer.size());
        }
    }

from datachannel-wasm.

paullouisageneau commented on September 15, 2024

Are you sure the send method is actually called? (in particular, are you sure the dc.lock() succeeds?)

from datachannel-wasm.

jeffRTC commented on September 15, 2024

dc.lock works and send method actually called.

    if (auto channel = dc.lock())
    {
        std::cout << "Hey" << "\n";
        channel->send(reinterpret_cast<rtc::byte*>(buffer.data()), buffer.size());
    }

"Hey" prints too.

I can even send STRINGS but RTC::BYTE is hiding!!

from datachannel-wasm.

jeffRTC commented on September 15, 2024

I modified the send function on your JS code as follows,

		rtcSendMessage: function(dc, pBuffer, size) {
			var dataChannel = WEBRTC.dataChannelsMap[dc];
			if(dataChannel.readyState != 'open') return 0;
			if(size >= 0) {
				var heapBytes = new Uint8Array(Module['HEAPU8'].buffer, pBuffer, size);
				console.log(heapBytes)
				try{
				dataChannel.send(heapBytes.buffer);
				} catch(err) {
					console.log(err)
				}
				return size;
			}

I can see that heapBytes has successfully logged into console and no errors.

According to the MDN https://developer.mozilla.org/en-US/docs/Web/API/RTCDataChannel/send ,

Send method can throw an exception if the message has been failed to send.

I see no errors logged.

Let me know if you need to see something specific on chrome://webrtc-internals/

from datachannel-wasm.

paullouisageneau commented on September 15, 2024

OK, then it appears sending works fine, the issue must be at reception. When you say "on server side", is it also in a browser or is it compiled natively with libdatachannel?

from datachannel-wasm.

jeffRTC commented on September 15, 2024

Native libdatachannel on server not browser

from datachannel-wasm.

jeffRTC commented on September 15, 2024

Here, I could see hey prints but std::holds_alternative<rtc::binary> fails


                dc->onMessage([this, id, wDC = make_weak_ptr(dc)](const std::variant<rtc::binary, std::string> &message) {
                    std::cout << "hey" << "\n";
                    if (std::holds_alternative<rtc::binary>(message))
                    {

from datachannel-wasm.

paullouisageneau commented on September 15, 2024

I couldn't reproduce the behavior when sending binary data from a browser to libdatachannel. Does the binary data arrives as a string in your setup?

By the way, do you use the correct submodule version of libdatachannel? (i.e., obtained with git submodule update --recursive)

from datachannel-wasm.

jeffRTC commented on September 15, 2024

I'm not using submodule of this repo. I'm using your native repo on server side.

Apparently, dc->onMessage get called because I send a string in dc->onOpen and now I removed it. I see that it's not getting called anymore.

Means the server doesn't receive binary type at all.

But with Strings - I again checked, it works fine.

from datachannel-wasm.

paullouisageneau commented on September 15, 2024

OK, could you please post the verbose libdatachannel log on the server side ?

from datachannel-wasm.

paullouisageneau commented on September 15, 2024

What size is the binary message you are trying to send?

from datachannel-wasm.

jeffRTC commented on September 15, 2024

Size is 19

2020-11-29 17:49:30.671 DEBUG [1166629] [rtc::{anonymous}::doInit@46] Global initialization
2020-11-29 17:49:30.673 VERB  [1166629] [rtc::PeerConnection::PeerConnection@48] Creating PeerConnection
2020-11-29 17:49:30.673 VERB  [1166629] [rtc::PeerConnection::setRemoteDescription@118] Setting remote description: v=0
o=- 571098302157712800 0 IN IP4 127.0.0.1
s=-
t=0 0
a=group:BUNDLE 0
a=msid-semantic:WMS *
a=setup:actpass
a=ice-ufrag:+60M
a=ice-pwd:B1djhrQCnJUjOQFVijrxMcZv
a=ice-options:trickle
a=fingerprint:sha-256 27:26:68:6F:F4:56:B7:46:A8:B5:A8:D9:3A:2E:E1:64:50:CD:CD:F4:C9:51:EC:7B:DB:34:21:20:CB:E5:43:86
m=application 9 UDP/DTLS/SCTP webrtc-datachannel
c=IN IP4 0.0.0.0
a=bundle-only
a=mid:0
a=sendrecv
a=ice-options:trickle
a=sctp-port:5000
a=max-message-size:262144

2020-11-29 17:49:30.674 DEBUG [1166629] [rtc::IceTransport::IceTransport@327] Initializing ICE transport (libnice)
2020-11-29 17:49:30.674 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Created NiceStream (1 created, 0 destroyed)
2020-11-29 17:49:30.674 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Created NiceComponent (1 created, 0 destroyed)
2020-11-29 17:49:30.674 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : allocating stream id 1 (0x7efe3c01b3f0)
2020-11-29 17:49:30.674 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : Property set, role is already "controlling".
2020-11-29 17:49:30.702 DEBUG [1166629] [rtc::IceTransport::IceTransport@415] Using STUN server "stun.services.mozilla.com:3478"
2020-11-29 17:49:30.702 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : Property set, changing role to "controlled".
2020-11-29 17:49:30.703 DEBUG [1166629] [rtc::PeerConnection::processLocalDescription@749] Reciprocating application in local description, mid="0"
2020-11-29 17:49:30.785 INFO  [1166629] [rtc::PeerConnection::changeGatheringState@888] Changed gathering state to in_progress
2020-11-29 17:49:30.785 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : In ICE-FULL mode, starting candidate gathering.
2020-11-29 17:49:30.785 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : UPnP property Disabled
2020-11-29 17:49:30.785 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Failed to convert address to string for interface ‘lo’.
2020-11-29 17:49:30.785 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Failed to convert address to string for interface ‘eth0’.
2020-11-29 17:49:30.785 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Interface:  lo
2020-11-29 17:49:30.785 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: IP Address: 127.0.0.1
2020-11-29 17:49:30.785 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Ignoring loopback interface
2020-11-29 17:49:30.785 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Interface:  eth0
2020-11-29 17:49:30.785 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: IP Address: HIDDEN_FOR_PRIVACY
2020-11-29 17:49:30.785 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Interface:  lo
2020-11-29 17:49:30.786 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: IP Address: ::1
2020-11-29 17:49:30.786 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Ignoring loopback interface
2020-11-29 17:49:30.786 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Interface:  eth0
2020-11-29 17:49:30.786 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: IP Address: HIDDEN_FOR_PRIVACY
2020-11-29 17:49:30.786 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Interface:  eth0
2020-11-29 17:49:30.786 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: IP Address: fe80::f03c:92ff:fe64:cdfd%eth0
2020-11-29 17:49:30.786 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: Trying to create host candidate on port 15198
2020-11-29 17:49:30.786 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Component 0x7efe3c01bbc0: Attach source (stream 1).
2020-11-29 17:49:30.786 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Attaching source 0x7efe3c0242b0 (socket 0x7efe3c0146e0, FD 21) to context 0x7efe3c0113d0
2020-11-29 17:49:30.786 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: Trying to create host candidate on port 7691
2020-11-29 17:49:30.786 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Component 0x7efe3c01bbc0: Attach source (stream 1).
2020-11-29 17:49:30.786 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Attaching source 0x7efe3c024410 (socket 0x7efe3c025480, FD 22) to context 0x7efe3c0113d0
2020-11-29 17:49:30.786 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: Trying to create host candidate on port 29349
2020-11-29 17:49:30.786 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: Could not set IPV6 socket ToS: Protocol not available
2020-11-29 17:49:30.786 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Component 0x7efe3c01bbc0: Attach source (stream 1).
2020-11-29 17:49:30.786 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Attaching source 0x7efe3c0276e0 (socket 0x7efe3c0254f0, FD 23) to context 0x7efe3c0113d0
2020-11-29 17:49:30.786 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : Adding new srv-rflx candidate discovery 0x7efe3c027840
2020-11-29 17:49:30.786 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : discovery tick #1 with list 0x7efe3c010cc0 (1)
2020-11-29 17:49:30.786 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : discovery - scheduling cand type 1 addr 52.87.201.4.
2020-11-29 17:49:30.786 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : stream 1 component 1 STATE-CHANGE disconnected -> gathering.
2020-11-29 17:49:30.785 VERB  [1166659] [rtc::PeerConnection::processLocalDescription@828] Issuing local description: v=0
o=rtc 896040576 0 IN IP4 127.0.0.1
s=-
t=0 0
a=group:BUNDLE 0
a=msid-semantic:WMS *
a=setup:active
a=ice-ufrag:3Zej
a=ice-pwd:0Pv7RULDyaXPDeSZCA45Rd
a=ice-options:trickle
a=fingerprint:sha-256 6E:EA:D2:44:F1:19:26:7D:17:60:E8:AC:FA:2C:DB:07:B5:0F:31:DE:6E:54:A2:13:69:80:A1:9B:06:88:4E:1B
m=application 9 UDP/DTLS/SCTP webrtc-datachannel
c=IN IP4 0.0.0.0
a=bundle-only
a=mid:0
a=sendrecv
a=ice-options:trickle
a=sctp-port:5000
a=max-message-size:262144

Gathering State: in_progress
2020-11-29 17:49:30.787 VERB  [1166629] [rtc::Candidate::resolve@85] Resolving candidate (mode=simple): 1 1 UDP 2013266431 HIDDEN_FOR_PRIVACY15198 typ host
2020-11-29 17:49:30.787 VERB  [1166629] [rtc::Candidate::resolve@161] Resolved candidate: 1 1 UDP 2013266431 HIDDEN_FOR_PRIVACY15198 typ host
2020-11-29 17:49:30.787 VERB  [1166629] [rtc::Candidate::resolve@85] Resolving candidate (mode=simple): 2 1 UDP 2013266430 HIDDEN_FOR_PRIVACY 7691 typ host
2020-11-29 17:49:30.787 VERB  [1166629] [rtc::Candidate::resolve@161] Resolved candidate: 2 1 UDP 2013266430 HIDDEN_FOR_PRIVACY 7691 typ host
2020-11-29 17:49:30.787 VERB  [1166629] [rtc::Candidate::resolve@85] Resolving candidate (mode=simple): 3 1 UDP 2013266429 HIDDEN_FOR_PRIVACY 29349 typ host
2020-11-29 17:49:30.787 VERB  [1166629] [rtc::Candidate::resolve@161] Resolved candidate: 3 1 UDP 2013266429 HIDDEN_FOR_PRIVACY 29349 typ host
2020-11-29 17:49:30.787 VERB  [1166629] [rtc::PeerConnection::addRemoteCandidate@205] Adding remote candidate: a=candidate:1802928054 1 udp 2122262783 2602:ff50::37:c1bf:b4a2:a258:6ec 53451 typ host generation 0 ufrag +60M network-id 4
2020-11-29 17:49:30.787 VERB  [1166629] [rtc::Candidate::resolve@85] Resolving candidate (mode=simple): 1802928054 1 udp 2122262783 2602:ff50::37:c1bf:b4a2:a258:6ec 53451 typ host generation 0 ufrag +60M network-id 4
2020-11-29 17:49:30.787 VERB  [1166629] [rtc::Candidate::resolve@161] Resolved candidate: 1802928054 1 udp 2122262783 HIDDEN_FOR_PRIVACY 53451 typ host generation 0 ufrag +60M network-id 4
2020-11-29 17:49:30.787 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: set_remote_candidates 1 1
2020-11-29 17:49:30.787 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : Adding UDP remote candidate with addr [HIDDEN_FOR_PRIVACY]:53451 for s1/c1. U/P '(null)'/'(null)' prio: 2122262783
2020-11-29 17:49:30.787 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : creating a new pair
2020-11-29 17:49:30.788 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : pair 0x7efe3c03e030 state FROZEN (priv_add_new_check_pair)
2020-11-29 17:49:30.788 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : new pair 0x7efe3c03e030 : [fe80::f03c:92ff:fe64:cdfd]:15198 --> [HIDDEN_FOR_PRIVACY]:53451
2020-11-29 17:49:30.788 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : added a new pair 0x7efe3c03e030 with foundation '1:1802928054' to stream 1 component 1.
2020-11-29 17:49:30.788 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : stream 1 component 1 STATE-CHANGE gathering -> connecting.
2020-11-29 17:49:30.788 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : creating a new pair
2020-11-29 17:49:30.788 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : pair 0x7efe3c03e0e0 state FROZEN (priv_add_new_check_pair)
2020-11-29 17:49:30.788 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : new pair 0x7efe3c03e0e0 : [HIDDEN_FOR_PRIVACY]:7691 --> [HIDDEN_FOR_PRIVACY]:53451
2020-11-29 17:49:30.788 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : added a new pair 0x7efe3c03e0e0 with foundation '2:1802928054' to stream 1 component 1.
2020-11-29 17:49:30.788 INFO  [1166629] [rtc::PeerConnection::changeState@873] Changed state to connecting
2020-11-29 17:49:30.788 VERB  [1166629] [rtc::PeerConnection::addRemoteCandidate@205] Adding remote candidate: a=candidate:4201576948 1 udp 2122194687 HIDDEN_FOR_PRIVACY 53452 typ host generation 0 ufrag +60M network-id 1
2020-11-29 17:49:30.788 VERB  [1166629] [rtc::Candidate::resolve@85] Resolving candidate (mode=simple): 4201576948 1 udp 2122194687 HIDDEN_FOR_PRIVACY 53452 typ host generation 0 ufrag +60M network-id 1
2020-11-29 17:49:30.788 VERB  [1166629] [rtc::Candidate::resolve@161] Resolved candidate: 4201576948 1 udp 2122194687 HIDDEN_FOR_PRIVACY 53452 typ host generation 0 ufrag +60M network-id 1
2020-11-29 17:49:30.788 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: set_remote_candidates 1 1
2020-11-29 17:49:30.788 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : Adding UDP remote candidate with addr [HIDDEN_FOR_PRIVACY]:53452 for s1/c1. U/P '(null)'/'(null)' prio: 2122194687
2020-11-29 17:49:30.788 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : creating a new pair
2020-11-29 17:49:30.788 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : pair 0x7efe3c03e190 state FROZEN (priv_add_new_check_pair)
2020-11-29 17:49:30.788 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : new pair 0x7efe3c03e190 : [HIDDEN_FOR_PRIVACY]:29349 --> [HIDDEN_FOR_PRIVACY]:53452
2020-11-29 17:49:30.788 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : added a new pair 0x7efe3c03e190 with foundation '3:4201576948' to stream 1 component 1.
2020-11-29 17:49:30.788 VERB  [1166629] [rtc::PeerConnection::addRemoteCandidate@205] Adding remote candidate: a=candidate:2999745851 1 udp 2122129151 HIDDEN_FOR_PRIVACY 53453 typ host generation 0 ufrag +60M network-id 2
2020-11-29 17:49:30.787 VERB  [1166657] [rtc::PeerConnection::processLocalCandidate@842] Issuing local candidate: a=candidate:1 1 UDP 2013266431 HIDDEN_FOR_PRIVACY15198 typ host
Adding Candidate
2020-11-29 17:49:30.788 VERB  [1166657] [rtc::PeerConnection::processLocalCandidate@842] Issuing local candidate: a=candidate:2 1 UDP 2013266430 HIDDEN_FOR_PRIVACY 7691 typ host
Adding Candidate
2020-11-29 17:49:30.788 VERB  [1166657] [rtc::PeerConnection::processLocalCandidate@842] Issuing local candidate: a=candidate:3 1 UDP 2013266429 HIDDEN_FOR_PRIVACY 29349 typ host
Adding Candidate
State: connecting
2020-11-29 17:49:30.788 VERB  [1166629] [rtc::Candidate::resolve@85] Resolving candidate (mode=simple): 2999745851 1 udp 2122129151 HIDDEN_FOR_PRIVACY 53453 typ host generation 0 ufrag +60M network-id 2
2020-11-29 17:49:30.788 VERB  [1166629] [rtc::Candidate::resolve@161] Resolved candidate: 2999745851 1 udp 2122129151 HIDDEN_FOR_PRIVACY 53453 typ host generation 0 ufrag +60M network-id 2
2020-11-29 17:49:30.788 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: set_remote_candidates 1 1
2020-11-29 17:49:30.788 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : Adding UDP remote candidate with addr [HIDDEN_FOR_PRIVACY]:53453 for s1/c1. U/P '(null)'/'(null)' prio: 2122129151
2020-11-29 17:49:30.788 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : creating a new pair
2020-11-29 17:49:30.788 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : pair 0x7efe3c03e240 state FROZEN (priv_add_new_check_pair)
2020-11-29 17:49:30.788 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : new pair 0x7efe3c03e240 : [HIDDEN_FOR_PRIVACY]:29349 --> [HIDDEN_FOR_PRIVACY]:53453
2020-11-29 17:49:30.788 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : added a new pair 0x7efe3c03e240 with foundation '3:2999745851' to stream 1 component 1.
2020-11-29 17:49:30.788 VERB  [1166629] [rtc::PeerConnection::addRemoteCandidate@205] Adding remote candidate: a=candidate:917165150 1 udp 2122063615 HIDDEN_FOR_PRIVACY 53454 typ host generation 0 ufrag +60M network-id 3
2020-11-29 17:49:30.788 VERB  [1166629] [rtc::Candidate::resolve@85] Resolving candidate (mode=simple): 917165150 1 udp 2122063615 HIDDEN_FOR_PRIVACY 53454 typ host generation 0 ufrag +60M network-id 3
2020-11-29 17:49:30.789 VERB  [1166629] [rtc::Candidate::resolve@161] Resolved candidate: 917165150 1 udp 2122063615 HIDDEN_FOR_PRIVACY 53454 typ host generation 0 ufrag +60M network-id 3
2020-11-29 17:49:30.789 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: set_remote_candidates 1 1
2020-11-29 17:49:30.789 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : Adding UDP remote candidate with addr [HIDDEN_FOR_PRIVACY]:53454 for s1/c1. U/P '(null)'/'(null)' prio: 2122063615
2020-11-29 17:49:30.789 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : creating a new pair
2020-11-29 17:49:30.789 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : pair 0x7efe3c03e2f0 state FROZEN (priv_add_new_check_pair)
2020-11-29 17:49:30.789 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : new pair 0x7efe3c03e2f0 : [HIDDEN_FOR_PRIVACY]:29349 --> [HIDDEN_FOR_PRIVACY]:53454
2020-11-29 17:49:30.789 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : added a new pair 0x7efe3c03e2f0 with foundation '3:917165150' to stream 1 component 1.
2020-11-29 17:49:30.789 VERB  [1166629] [rtc::PeerConnection::addRemoteCandidate@205] Adding remote candidate: a=candidate:636846918 1 tcp 1518283007 2602:ff50::37:c1bf:b4a2:a258:6ec 9 typ host tcptype active generation 0 ufrag +60M network-id 4
2020-11-29 17:49:30.789 VERB  [1166629] [rtc::Candidate::resolve@85] Resolving candidate (mode=simple): 636846918 1 tcp 1518283007 2602:ff50::37:c1bf:b4a2:a258:6ec 9 typ host tcptype active generation 0 ufrag +60M network-id 4
2020-11-29 17:49:30.789 VERB  [1166629] [rtc::Candidate::resolve@161] Resolved candidate: 636846918 1 tcp 1518283007 HIDDEN_FOR_PRIVACY 9 typ host tcptype active generation 0 ufrag +60M network-id 4
2020-11-29 17:49:30.789 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: set_remote_candidates 1 1
2020-11-29 17:49:30.789 VERB  [1166629] [rtc::PeerConnection::addRemoteCandidate@205] Adding remote candidate: a=candidate:3035432196 1 tcp 1518214911 HIDDEN_FOR_PRIVACY 9 typ host tcptype active generation 0 ufrag +60M network-id 1
2020-11-29 17:49:30.789 VERB  [1166629] [rtc::Candidate::resolve@85] Resolving candidate (mode=simple): 3035432196 1 tcp 1518214911 HIDDEN_FOR_PRIVACY 9 typ host tcptype active generation 0 ufrag +60M network-id 1
2020-11-29 17:49:30.789 VERB  [1166629] [rtc::Candidate::resolve@161] Resolved candidate: 3035432196 1 tcp 1518214911 HIDDEN_FOR_PRIVACY 9 typ host tcptype active generation 0 ufrag +60M network-id 1
2020-11-29 17:49:30.789 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: set_remote_candidates 1 1
2020-11-29 17:49:30.789 VERB  [1166629] [rtc::PeerConnection::addRemoteCandidate@205] Adding remote candidate: a=candidate:4233069003 1 tcp 1518149375 HIDDEN_FOR_PRIVACY 9 typ host tcptype active generation 0 ufrag +60M network-id 2
2020-11-29 17:49:30.789 VERB  [1166629] [rtc::Candidate::resolve@85] Resolving candidate (mode=simple): 4233069003 1 tcp 1518149375 HIDDEN_FOR_PRIVACY 9 typ host tcptype active generation 0 ufrag +60M network-id 2
2020-11-29 17:49:30.789 VERB  [1166629] [rtc::Candidate::resolve@161] Resolved candidate: 4233069003 1 tcp 1518149375 HIDDEN_FOR_PRIVACY 9 typ host tcptype active generation 0 ufrag +60M network-id 2
2020-11-29 17:49:30.789 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: set_remote_candidates 1 1
2020-11-29 17:49:30.789 VERB  [1166629] [rtc::PeerConnection::addRemoteCandidate@205] Adding remote candidate: a=candidate:2015963310 1 tcp 1518083839 HIDDEN_FOR_PRIVACY 9 typ host tcptype active generation 0 ufrag +60M network-id 3
2020-11-29 17:49:30.789 VERB  [1166629] [rtc::Candidate::resolve@85] Resolving candidate (mode=simple): 2015963310 1 tcp 1518083839 HIDDEN_FOR_PRIVACY 9 typ host tcptype active generation 0 ufrag +60M network-id 3
2020-11-29 17:49:30.789 VERB  [1166629] [rtc::Candidate::resolve@161] Resolved candidate: 2015963310 1 tcp 1518083839 HIDDEN_FOR_PRIVACY 9 typ host tcptype active generation 0 ufrag +60M network-id 3
2020-11-29 17:49:30.789 VERB  [1166629] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: set_remote_candidates 1 1
2020-11-29 17:49:30.813 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : Pair 0x7efe3c03e030 with s/c-id 1/1 (1:1802928054) unfrozen.
2020-11-29 17:49:30.813 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : pair 0x7efe3c03e030 state WAITING (priv_conn_check_unfreeze_next)
2020-11-29 17:49:30.813 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : Pair 0x7efe3c03e0e0 with s/c-id 1/1 (2:1802928054) unfrozen.
2020-11-29 17:49:30.813 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : pair 0x7efe3c03e0e0 state WAITING (priv_conn_check_unfreeze_next)
2020-11-29 17:49:30.813 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : Pair 0x7efe3c03e190 with s/c-id 1/1 (3:4201576948) unfrozen.
2020-11-29 17:49:30.813 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : pair 0x7efe3c03e190 state WAITING (priv_conn_check_unfreeze_next)
2020-11-29 17:49:30.813 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : Pair 0x7efe3c03e240 with s/c-id 1/1 (3:2999745851) unfrozen.
2020-11-29 17:49:30.813 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : pair 0x7efe3c03e240 state WAITING (priv_conn_check_unfreeze_next)
2020-11-29 17:49:30.813 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : Pair 0x7efe3c03e2f0 with s/c-id 1/1 (3:917165150) unfrozen.
2020-11-29 17:49:30.813 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : pair 0x7efe3c03e2f0 state WAITING (priv_conn_check_unfreeze_next)
2020-11-29 17:49:30.813 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : pair 0x7efe3c03e030 state IN_PROGRESS (priv_conn_check_initiate)
2020-11-29 17:49:30.813 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : STUN-CC REQ [fe80::f03c:92ff:fe64:cdfd]:15198 --> [HIDDEN_FOR_PRIVACY]:53451, socket=21, pair=0x7efe3c03e030 (c-id:1), tie=16199083266985692841, username='+60M:3Zej' (9), password='B1djhrQCnJUjOQFVijrxMcZv' (24), prio=1845494271, controlled.
2020-11-29 17:49:30.813 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : conn_check_send: set cand_use=0 (aggressive nomination).
2020-11-29 17:49:30.813 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: conncheck created 88 - 0x7efe18003640
2020-11-29 17:49:30.813 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : timer set to 125ms, waiting+in_progress=5, nb_active=1
2020-11-29 17:49:30.813 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : stream 1: timer tick #1: 0 frozen, 1 in-progress, 4 waiting, 0 succeeded, 0 discovered, 0 nominated, 0 waiting-for-nom, 0 valid.
2020-11-29 17:49:30.838 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : pair 0x7efe3c03e0e0 state IN_PROGRESS (priv_conn_check_initiate)
2020-11-29 17:49:30.838 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : STUN-CC REQ [HIDDEN_FOR_PRIVACY]:7691 --> [HIDDEN_FOR_PRIVACY]:53451, socket=22, pair=0x7efe3c03e0e0 (c-id:1), tie=16199083266985692841, username='+60M:3Zej' (9), password='B1djhrQCnJUjOQFVijrxMcZv' (24), prio=1845494270, controlled.
2020-11-29 17:49:30.838 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : conn_check_send: set cand_use=0 (aggressive nomination).
2020-11-29 17:49:30.838 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: conncheck created 88 - 0x7efe18005430
2020-11-29 17:49:30.839 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : timer set to 125ms, waiting+in_progress=5, nb_active=1
2020-11-29 17:49:30.864 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : pair 0x7efe3c03e190 state IN_PROGRESS (priv_conn_check_initiate)
2020-11-29 17:49:30.864 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : STUN-CC REQ [HIDDEN_FOR_PRIVACY]:29349 --> [HIDDEN_FOR_PRIVACY]:53452, socket=23, pair=0x7efe3c03e190 (c-id:1), tie=16199083266985692841, username='+60M:3Zej' (9), password='B1djhrQCnJUjOQFVijrxMcZv' (24), prio=1845494269, controlled.
2020-11-29 17:49:30.864 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : conn_check_send: set cand_use=0 (aggressive nomination).
2020-11-29 17:49:30.864 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: conncheck created 88 - 0x7efe18005f50
2020-11-29 17:49:30.864 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : timer set to 125ms, waiting+in_progress=5, nb_active=1
2020-11-29 17:49:30.879 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: inbound STUN packet for 1/1 (stream/component) from [HIDDEN_FOR_PRIVACY]:53451 (100 octets) :
2020-11-29 17:49:30.879 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 :  1:1 Adding valid source candidate: HIDDEN_FOR_PRIVACY:53451 trans: 0
2020-11-29 17:49:30.879 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : STUN-CC RESP to 'HIDDEN_FOR_PRIVACY:53451', socket=22, len=92, cand=0x7efe3c017540 (c-id:1), use-cand=1.
2020-11-29 17:49:30.879 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : Found a matching pair 0x7efe3c03e0e0 (2:1802928054) (IN_PROGRESS) ...
2020-11-29 17:49:30.879 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : pair 0x7efe3c03e0e0 added for a triggered check.
2020-11-29 17:49:30.879 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : pair 0x7efe3c03e0e0 state IN_PROGRESS (priv_add_pair_to_triggered_check_queue)
2020-11-29 17:49:30.879 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : pair 0x7efe3c03e0e0 (2:1802928054) is in-progress, will be nominated on response receipt.
2020-11-29 17:49:30.879 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: agent_recv_message_unlocked: Valid STUN packet received.
2020-11-29 17:49:30.885 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: inbound STUN packet for 1/1 (stream/component) from [HIDDEN_FOR_PRIVACY]:53451 (76 octets) :
2020-11-29 17:49:30.885 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : stun_bind_process/conncheck for 0x7efe3c03e0e0: controlled,res=success,stun#=0.
2020-11-29 17:49:30.885 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : pair 0x7efe3c03e0e0 MATCHED.
2020-11-29 17:49:30.885 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : pair 0x7efe3c03e0e0 state SUCCEEDED (priv_process_response_check_for_reflexive)
2020-11-29 17:49:30.885 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : Updating nominated flag (UDP): ok_pair=0x7efe3c03e0e0 (0/1) p=0x7efe3c03e0e0 (0/1) (ucnc/mnora)
2020-11-29 17:49:30.885 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : marking pair 0x7efe3c03e0e0 (2:1802928054) as nominated (aggressive nomination, controlled, mark_on_response=1).
2020-11-29 17:49:30.885 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : changing SELECTED PAIR for component 1: 2:1802928054 (prio:8646913479229198847).
2020-11-29 17:49:30.885 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: setting SELECTED PAIR for component 1: 2:1802928054 (prio:8646913479229198847).
2020-11-29 17:49:30.885 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : stun_bind_keepalive for pair 0x7efe3c01bc30 res 28.
2020-11-29 17:49:30.885 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : resending STUN on 3 to keep the candidate alive.
2020-11-29 17:49:30.885 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: Local selected pair: 1:1 2 UDP HIDDEN_FOR_PRIVACY:7691 HOST
2020-11-29 17:49:30.885 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: Remote selected pair: 1:1 1802928054 UDP HIDDEN_FOR_PRIVACY:53451 HOST
2020-11-29 17:49:30.885 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : stream 1 component 1 STATE-CHANGE connecting -> connected.
2020-11-29 17:49:30.886 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: Finding highest priority for component 1
2020-11-29 17:49:30.886 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: Pruning pending checks. Highest nominated priority is 8646913479229198847
2020-11-29 17:49:30.886 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : pair 0x7efe3c03e030 kept IN_PROGRESS because priority 8646913483524166143 is higher than currently nominated pair 8646913479229198847
2020-11-29 17:49:30.886 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : pair 0x7efe3c03e190 will not be retransmitted.
2020-11-29 17:49:30.886 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : pair 0x7efe3c03e240 removed.
2020-11-29 17:49:30.886 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : pair 0x7efe3c03e2f0 removed.
2020-11-29 17:49:30.886 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : conn.check list status: 1 nominated, 1 valid, c-id 1.
2020-11-29 17:49:30.886 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: agent_recv_message_unlocked: Valid STUN packet received.
2020-11-29 17:49:30.886 DEBUG [1166667] [rtc::DtlsTransport::DtlsTransport@58] Initializing DTLS transport (GnuTLS)
2020-11-29 17:49:30.886 DEBUG [1166667] [rtc::DtlsTransport::start@105] Starting DTLS recv thread
2020-11-29 17:49:30.886 VERB  [1166668] [rtc::IceTransport::send@596] Send size=215
2020-11-29 17:49:30.928 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: inbound STUN packet for 1/1 (stream/component) from [HIDDEN_FOR_PRIVACY]:53451 (100 octets) :
2020-11-29 17:49:30.928 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : STUN-CC RESP to 'HIDDEN_FOR_PRIVACY:53451', socket=22, len=92, cand=0x7efe3c017540 (c-id:1), use-cand=1.
2020-11-29 17:49:30.928 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : Found a matching pair 0x7efe3c03e0e0 (2:1802928054) (SUCCEEDED) ...
2020-11-29 17:49:30.928 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : nothing to do for pair 0x7efe3c03e0e0.
2020-11-29 17:49:30.928 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: Finding highest priority for component 1
2020-11-29 17:49:30.928 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: Pruning pending checks. Highest nominated priority is 8646913479229198847
2020-11-29 17:49:30.928 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : pair 0x7efe3c03e030 kept IN_PROGRESS because priority 8646913483524166143 is higher than currently nominated pair 8646913479229198847
2020-11-29 17:49:30.928 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : pair 0x7efe3c03e190 will not be retransmitted.
2020-11-29 17:49:30.928 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : conn.check list status: 1 nominated, 1 valid, c-id 1.
2020-11-29 17:49:30.928 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : marking pair 0x7efe3c03e0e0 (2:1802928054) as nominated
2020-11-29 17:49:30.928 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: Finding highest priority for component 1
2020-11-29 17:49:30.928 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: Pruning pending checks. Highest nominated priority is 8646913479229198847
2020-11-29 17:49:30.928 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : pair 0x7efe3c03e030 kept IN_PROGRESS because priority 8646913483524166143 is higher than currently nominated pair 8646913479229198847
2020-11-29 17:49:30.928 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : pair 0x7efe3c03e190 will not be retransmitted.
2020-11-29 17:49:30.928 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : conn.check list status: 1 nominated, 1 valid, c-id 1.
2020-11-29 17:49:30.928 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: agent_recv_message_unlocked: Valid STUN packet received.
2020-11-29 17:49:30.933 VERB  [1166667] [rtc::IceTransport::RecvCallback@699] Incoming size=639
2020-11-29 17:49:30.933 VERB  [1166667] [rtc::DtlsTransport::incoming@142] Incoming size=639
2020-11-29 17:49:30.940 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 :STUN transaction retransmitted on pair 0x7efe3c03e030 (timer=2/3 2/250ms).
2020-11-29 17:49:30.978 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: inbound STUN packet for 1/1 (stream/component) from [HIDDEN_FOR_PRIVACY]:53451 (100 octets) :
2020-11-29 17:49:30.978 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : STUN-CC RESP to 'HIDDEN_FOR_PRIVACY:53451', socket=22, len=92, cand=0x7efe3c017540 (c-id:1), use-cand=1.
2020-11-29 17:49:30.978 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : Found a matching pair 0x7efe3c03e0e0 (2:1802928054) (SUCCEEDED) ...
2020-11-29 17:49:30.978 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : nothing to do for pair 0x7efe3c03e0e0.
2020-11-29 17:49:30.978 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: Finding highest priority for component 1
2020-11-29 17:49:30.978 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: Pruning pending checks. Highest nominated priority is 8646913479229198847
2020-11-29 17:49:30.978 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : pair 0x7efe3c03e030 kept IN_PROGRESS because priority 8646913483524166143 is higher than currently nominated pair 8646913479229198847
2020-11-29 17:49:30.978 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : pair 0x7efe3c03e190 will not be retransmitted.
2020-11-29 17:49:30.978 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : conn.check list status: 1 nominated, 1 valid, c-id 1.
2020-11-29 17:49:30.978 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : marking pair 0x7efe3c03e0e0 (2:1802928054) as nominated
2020-11-29 17:49:30.978 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: Finding highest priority for component 1
2020-11-29 17:49:30.978 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: Pruning pending checks. Highest nominated priority is 8646913479229198847
2020-11-29 17:49:30.978 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : pair 0x7efe3c03e030 kept IN_PROGRESS because priority 8646913483524166143 is higher than currently nominated pair 8646913479229198847
2020-11-29 17:49:30.978 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : pair 0x7efe3c03e190 will not be retransmitted.
2020-11-29 17:49:30.978 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : conn.check list status: 1 nominated, 1 valid, c-id 1.
2020-11-29 17:49:30.978 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: agent_recv_message_unlocked: Valid STUN packet received.
2020-11-29 17:49:30.990 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : Retransmissions failed, giving up on pair 0x7efe3c03e190
2020-11-29 17:49:30.990 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : Failed pair is [HIDDEN_FOR_PRIVACY]:29349 --> [HIDDEN_FOR_PRIVACY]:53452
2020-11-29 17:49:30.990 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : pair 0x7efe3c03e190 state FAILED (candidate_check_pair_fail)
2020-11-29 17:49:30.990 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: Finding highest priority for component 1
2020-11-29 17:49:30.990 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: Pruning pending checks. Highest nominated priority is 8646913479229198847
2020-11-29 17:49:30.990 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : pair 0x7efe3c03e030 kept IN_PROGRESS because priority 8646913483524166143 is higher than currently nominated pair 8646913479229198847
2020-11-29 17:49:30.990 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : conn.check list status: 1 nominated, 1 valid, c-id 1.
2020-11-29 17:49:31.029 VERB  [1166667] [rtc::IceTransport::RecvCallback@699] Incoming size=639
2020-11-29 17:49:31.029 VERB  [1166667] [rtc::DtlsTransport::incoming@142] Incoming size=639
2020-11-29 17:49:31.110 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: inbound STUN packet for 1/1 (stream/component) from [HIDDEN_FOR_PRIVACY]:53454 (96 octets) :
2020-11-29 17:49:31.110 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 :  1:1 Adding valid source candidate: HIDDEN_FOR_PRIVACY:53454 trans: 0
2020-11-29 17:49:31.110 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : STUN-CC RESP to 'HIDDEN_FOR_PRIVACY:53454', socket=23, len=80, cand=0x7efe3c03f000 (c-id:1), use-cand=0.
2020-11-29 17:49:31.110 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : Adding a triggered check to conn.check list (local=0x7efe3c017390).
2020-11-29 17:49:31.110 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : creating a new pair
2020-11-29 17:49:31.110 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : pair 0x7efe3c03e2f0 state WAITING (priv_add_new_check_pair)
2020-11-29 17:49:31.110 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : new pair 0x7efe3c03e2f0 : [HIDDEN_FOR_PRIVACY]:29349 --> [HIDDEN_FOR_PRIVACY]:53454
2020-11-29 17:49:31.110 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : added a new pair 0x7efe3c03e2f0 with foundation '3:917165150' to stream 1 component 1.
2020-11-29 17:49:31.110 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : pair 0x7efe3c03e2f0 state IN_PROGRESS (priv_add_pair_to_triggered_check_queue)
2020-11-29 17:49:31.110 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: agent_recv_message_unlocked: Valid STUN packet received.
2020-11-29 17:49:31.127 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : STUN-CC REQ [HIDDEN_FOR_PRIVACY]:29349 --> [HIDDEN_FOR_PRIVACY]:53454, socket=23, pair=0x7efe3c03e2f0 (c-id:1), tie=16199083266985692841, username='+60M:3Zej' (9), password='B1djhrQCnJUjOQFVijrxMcZv' (24), prio=1845494268, controlled.
2020-11-29 17:49:31.127 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : conn_check_send: set cand_use=0 (aggressive nomination).
2020-11-29 17:49:31.127 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: conncheck created 88 - 0x7efe1800f3c0
2020-11-29 17:49:31.127 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : timer set to 100ms, waiting+in_progress=2, nb_active=1
2020-11-29 17:49:31.145 VERB  [1166668] [rtc::IceTransport::send@596] Send size=984
2020-11-29 17:49:31.152 VERB  [1166668] [rtc::IceTransport::send@596] Send size=91
2020-11-29 17:49:31.152 VERB  [1166668] [rtc::IceTransport::send@596] Send size=413
2020-11-29 17:49:31.152 VERB  [1166668] [rtc::IceTransport::send@596] Send size=14
2020-11-29 17:49:31.152 VERB  [1166668] [rtc::IceTransport::send@596] Send size=53
2020-11-29 17:49:31.158 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: inbound STUN packet for 1/1 (stream/component) from [HIDDEN_FOR_PRIVACY]:53454 (64 octets) :
2020-11-29 17:49:31.158 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : stun_bind_process/conncheck for 0x7efe3c03e2f0: controlled,res=success,stun#=0.
2020-11-29 17:49:31.158 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : pair 0x7efe3c03e2f0 MATCHED.
2020-11-29 17:49:31.159 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : pair 0x7efe3c03e2f0 state SUCCEEDED (priv_process_response_check_for_reflexive)
2020-11-29 17:49:31.159 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : Updating nominated flag (UDP): ok_pair=0x7efe3c03e2f0 (0/0) p=0x7efe3c03e2f0 (0/0) (ucnc/mnora)
2020-11-29 17:49:31.159 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: Finding highest priority for component 1
2020-11-29 17:49:31.159 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: Pruning pending checks. Highest nominated priority is 8646913479229198847
2020-11-29 17:49:31.159 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : pair 0x7efe3c03e030 kept IN_PROGRESS because priority 8646913483524166143 is higher than currently nominated pair 8646913479229198847
2020-11-29 17:49:31.159 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : conn.check list status: 1 nominated, 2 valid, c-id 1.
2020-11-29 17:49:31.159 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: agent_recv_message_unlocked: Valid STUN packet received.
2020-11-29 17:49:31.200 VERB  [1166667] [rtc::IceTransport::RecvCallback@699] Incoming size=1181
2020-11-29 17:49:31.200 VERB  [1166667] [rtc::DtlsTransport::incoming@142] Incoming size=1181
2020-11-29 17:49:31.200 VERB  [1166667] [rtc::IceTransport::RecvCallback@699] Incoming size=53
2020-11-29 17:49:31.200 VERB  [1166667] [rtc::DtlsTransport::incoming@142] Incoming size=53
2020-11-29 17:49:31.201 VERB  [1166667] [rtc::IceTransport::RecvCallback@699] Incoming size=73
2020-11-29 17:49:31.201 VERB  [1166667] [rtc::DtlsTransport::incoming@142] Incoming size=73
2020-11-29 17:49:31.203 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 :STUN transaction retransmitted on pair 0x7efe3c03e030 (timer=3/3 15/125ms).
2020-11-29 17:49:31.328 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : Retransmissions failed, giving up on pair 0x7efe3c03e030
2020-11-29 17:49:31.328 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : Failed pair is [fe80::f03c:92ff:fe64:cdfd]:15198 --> [HIDDEN_FOR_PRIVACY]:53451
2020-11-29 17:49:31.328 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : pair 0x7efe3c03e030 state FAILED (candidate_check_pair_fail)
2020-11-29 17:49:31.328 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: Finding highest priority for component 1
2020-11-29 17:49:31.328 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: Pruning pending checks. Highest nominated priority is 8646913479229198847
2020-11-29 17:49:31.328 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : stream 1 component 1 STATE-CHANGE connected -> ready.
2020-11-29 17:49:31.328 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : conn.check list status: 1 nominated, 2 valid, c-id 1.
2020-11-29 17:49:31.328 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : waiting 1000 msecs before checking for failed components.
2020-11-29 17:49:31.753 INFO  [1166668] [rtc::DtlsTransport::runRecvLoop@179] DTLS handshake finished
2020-11-29 17:49:31.753 DEBUG [1166668] [rtc::SctpTransport::SctpTransport@95] Initializing SCTP transport
2020-11-29 17:49:31.753 DEBUG [1166668] [rtc::SctpTransport::connect@237] SCTP connecting
2020-11-29 17:49:31.758 VERB  [1166668] [rtc::SctpTransport::handleWrite@518] Handle write, len=100
2020-11-29 17:49:31.758 VERB  [1166668] [rtc::DtlsTransport::send@123] Send size=100
2020-11-29 17:49:31.758 VERB  [1166668] [rtc::IceTransport::send@596] Send size=129
2020-11-29 17:49:31.759 VERB  [1166668] [rtc::SctpTransport::incoming@318] Incoming size=44
2020-11-29 17:49:31.759 VERB  [1166668] [rtc::SctpTransport::handleWrite@518] Handle write, len=356
2020-11-29 17:49:31.759 VERB  [1166668] [rtc::DtlsTransport::send@123] Send size=356
2020-11-29 17:49:31.759 VERB  [1166668] [rtc::IceTransport::send@596] Send size=385
2020-11-29 17:49:31.806 VERB  [1166667] [rtc::IceTransport::RecvCallback@699] Incoming size=321
2020-11-29 17:49:31.806 VERB  [1166667] [rtc::DtlsTransport::incoming@142] Incoming size=321
2020-11-29 17:49:31.806 VERB  [1166668] [rtc::SctpTransport::incoming@318] Incoming size=292
2020-11-29 17:49:31.806 VERB  [1166667] [rtc::IceTransport::RecvCallback@699] Incoming size=337
2020-11-29 17:49:31.806 VERB  [1166667] [rtc::DtlsTransport::incoming@142] Incoming size=337
2020-11-29 17:49:31.807 VERB  [1166668] [rtc::SctpTransport::handleSend@511] Handle send, free=1048576
2020-11-29 17:49:31.807 VERB  [1166668] [rtc::SctpTransport::handleWrite@518] Handle write, len=260
2020-11-29 17:49:31.807 VERB  [1166668] [rtc::DtlsTransport::send@123] Send size=260
2020-11-29 17:49:31.807 VERB  [1166668] [rtc::IceTransport::send@596] Send size=289
2020-11-29 17:49:31.807 VERB  [1166668] [rtc::SctpTransport::incoming@318] Incoming size=308
2020-11-29 17:49:31.807 VERB  [1166668] [rtc::SctpTransport::handleRecv@478] Handle recv, len=23
2020-11-29 17:49:31.807 VERB  [1166668] [rtc::SctpTransport::processNotification@601] Processing notification, type=1
2020-11-29 17:49:31.807 INFO  [1166668] [rtc::SctpTransport::processNotification@607] SCTP connected
2020-11-29 17:49:31.807 INFO  [1166668] [rtc::PeerConnection::changeState@873] Changed state to connected
State: connected
2020-11-29 17:49:31.808 VERB  [1166668] [rtc::SctpTransport::handleRecv@478] Handle recv, len=21
2020-11-29 17:49:31.808 VERB  [1166668] [rtc::SctpTransport::processData@535] Process data, size=21
2020-11-29 17:49:31.808 VERB  [1166668] [rtc::SctpTransport::send@282] Send size=1
2020-11-29 17:49:31.808 VERB  [1166668] [rtc::SctpTransport::trySendMessage@358] SCTP try send size=1
2020-11-29 17:49:31.808 VERB  [1166668] [rtc::SctpTransport::handleWrite@518] Handle write, len=36
2020-11-29 17:49:31.808 VERB  [1166668] [rtc::DtlsTransport::send@123] Send size=36
2020-11-29 17:49:31.808 VERB  [1166668] [rtc::IceTransport::send@596] Send size=65
2020-11-29 17:49:31.808 VERB  [1166668] [rtc::SctpTransport::trySendMessage@413] SCTP sent size=1
DataChannel from abc+tgjio label abc+tgjio
2020-11-29 17:49:31.808 VERB  [1166659] [rtc::SctpTransport::send@282] Send size=5
2020-11-29 17:49:31.808 VERB  [1166659] [rtc::SctpTransport::trySendMessage@358] SCTP try send size=5
2020-11-29 17:49:31.808 VERB  [1166659] [rtc::SctpTransport::handleWrite@518] Handle write, len=36
2020-11-29 17:49:31.809 VERB  [1166659] [rtc::DtlsTransport::send@123] Send size=36
2020-11-29 17:49:31.809 VERB  [1166659] [rtc::IceTransport::send@596] Send size=65
2020-11-29 17:49:31.809 VERB  [1166659] [rtc::SctpTransport::trySendMessage@413] SCTP sent size=5
2020-11-29 17:49:31.809 VERB  [1166668] [rtc::SctpTransport::handleWrite@518] Handle write, len=28
2020-11-29 17:49:31.809 VERB  [1166668] [rtc::DtlsTransport::send@123] Send size=28
2020-11-29 17:49:31.809 VERB  [1166668] [rtc::IceTransport::send@596] Send size=57
2020-11-29 17:49:31.854 VERB  [1166667] [rtc::IceTransport::RecvCallback@699] Incoming size=45
2020-11-29 17:49:31.854 VERB  [1166667] [rtc::DtlsTransport::incoming@142] Incoming size=45
2020-11-29 17:49:31.854 VERB  [1166668] [rtc::SctpTransport::incoming@318] Incoming size=16
2020-11-29 17:49:31.855 VERB  [1166667] [rtc::IceTransport::RecvCallback@699] Incoming size=57
2020-11-29 17:49:31.855 VERB  [1166667] [rtc::DtlsTransport::incoming@142] Incoming size=57
2020-11-29 17:49:31.855 VERB  [1166668] [rtc::SctpTransport::incoming@318] Incoming size=28
2020-11-29 17:49:31.856 VERB  [1166668] [rtc::SctpTransport::handleSend@511] Handle send, free=1048571
2020-11-29 17:49:31.909 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: inbound STUN packet for 1/1 (stream/component) from [HIDDEN_FOR_PRIVACY]:53451 (100 octets) :
2020-11-29 17:49:31.910 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : STUN-CC RESP to 'HIDDEN_FOR_PRIVACY:53451', socket=22, len=92, cand=0x7efe3c017540 (c-id:1), use-cand=1.
2020-11-29 17:49:31.910 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : Found a matching pair 0x7efe3c03e0e0 (2:1802928054) (SUCCEEDED) ...
2020-11-29 17:49:31.910 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : nothing to do for pair 0x7efe3c03e0e0.
2020-11-29 17:49:31.910 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: Finding highest priority for component 1
2020-11-29 17:49:31.910 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: Pruning pending checks. Highest nominated priority is 8646913479229198847
2020-11-29 17:49:31.910 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : conn.check list status: 1 nominated, 2 valid, c-id 1.
2020-11-29 17:49:31.910 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : marking pair 0x7efe3c03e0e0 (2:1802928054) as nominated
2020-11-29 17:49:31.910 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: Finding highest priority for component 1
2020-11-29 17:49:31.910 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: Pruning pending checks. Highest nominated priority is 8646913479229198847
2020-11-29 17:49:31.910 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : conn.check list status: 1 nominated, 2 valid, c-id 1.
2020-11-29 17:49:31.910 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: agent_recv_message_unlocked: Valid STUN packet received.
2020-11-29 17:49:32.057 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : discovery tick #51 with list 0x7efe3c010cc0 (1)
2020-11-29 17:49:32.069 VERB  [1166667] [rtc::IceTransport::RecvCallback@699] Incoming size=57
2020-11-29 17:49:32.069 VERB  [1166667] [rtc::DtlsTransport::incoming@142] Incoming size=57
2020-11-29 17:49:32.069 VERB  [1166668] [rtc::SctpTransport::incoming@318] Incoming size=28
2020-11-29 17:49:32.069 VERB  [1166668] [rtc::SctpTransport::handleSend@511] Handle send, free=1048576
2020-11-29 17:49:32.069 VERB  [1166668] [rtc::SctpTransport::handleRecv@478] Handle recv, len=12
2020-11-29 17:49:32.069 VERB  [1166668] [rtc::SctpTransport::processNotification@601] Processing notification, type=10
2020-11-29 17:49:32.069 VERB  [1166668] [rtc::SctpTransport::processNotification@623] SCTP dry event
2020-11-29 17:49:32.107 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : stream 1: timer tick #51: 0 frozen, 0 in-progress, 0 waiting, 2 succeeded, 0 discovered, 1 nominated, 1 waiting-for-nom, 2 valid.
2020-11-29 17:49:32.308 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : checking for failed components now.
2020-11-29 17:49:32.308 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: Finding highest priority for component 1
2020-11-29 17:49:32.308 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: Pruning pending checks. Highest nominated priority is 8646913479229198847
2020-11-29 17:49:32.308 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : conn.check list status: 1 nominated, 2 valid, c-id 1.
2020-11-29 17:49:32.308 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : priv_conn_check_tick_agent_locked: stopping conncheck timer
2020-11-29 17:49:32.308 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : changing conncheck state to COMPLETED.
2020-11-29 17:49:32.809 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : bind discovery timed out, aborting discovery item.
2020-11-29 17:49:32.809 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : Candidate gathering FINISHED, stopping discovery timer.
2020-11-29 17:49:32.809 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: gathered UDP local candidate : [fe80::f03c:92ff:fe64:cdfd]:15198 for s1/c1. U/P '(null)'/'(null)'
2020-11-29 17:49:32.809 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: gathered UDP local candidate : [HIDDEN_FOR_PRIVACY]:7691 for s1/c1. U/P '(null)'/'(null)'
2020-11-29 17:49:32.809 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: gathered UDP local candidate : [HIDDEN_FOR_PRIVACY]:29349 for s1/c1. U/P '(null)'/'(null)'
2020-11-29 17:49:32.809 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : creating a new pair
2020-11-29 17:49:32.809 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : pair 0x7efe3c03e240 state FROZEN (priv_add_new_check_pair)
2020-11-29 17:49:32.809 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : new pair 0x7efe3c03e240 : [HIDDEN_FOR_PRIVACY]:29349 --> [HIDDEN_FOR_PRIVACY]:53453
2020-11-29 17:49:32.810 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : added a new pair 0x7efe3c03e240 with foundation '3:2999745851' to stream 1 component 1.
2020-11-29 17:49:32.810 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : stream 1 component 1 STATE-CHANGE ready -> connected.
2020-11-29 17:49:32.810 INFO  [1166667] [rtc::PeerConnection::changeGatheringState@888] Changed gathering state to complete
Gathering State: complete
2020-11-29 17:49:32.841 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: inbound STUN packet for 1/1 (stream/component) from [HIDDEN_FOR_PRIVACY]:53451 (100 octets) :
2020-11-29 17:49:32.841 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : STUN-CC RESP to 'HIDDEN_FOR_PRIVACY:53451', socket=22, len=92, cand=0x7efe3c017540 (c-id:1), use-cand=1.
2020-11-29 17:49:32.842 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : Found a matching pair 0x7efe3c03e0e0 (2:1802928054) (SUCCEEDED) ...
2020-11-29 17:49:32.842 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : nothing to do for pair 0x7efe3c03e0e0.
2020-11-29 17:49:32.842 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: Finding highest priority for component 1
2020-11-29 17:49:32.842 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: Pruning pending checks. Highest nominated priority is 8646913479229198847
2020-11-29 17:49:32.842 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : pair 0x7efe3c03e240 removed.
2020-11-29 17:49:32.842 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : stream 1 component 1 STATE-CHANGE connected -> ready.
2020-11-29 17:49:32.842 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : conn.check list status: 1 nominated, 2 valid, c-id 1.
2020-11-29 17:49:32.842 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : marking pair 0x7efe3c03e0e0 (2:1802928054) as nominated
2020-11-29 17:49:32.842 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: Finding highest priority for component 1
2020-11-29 17:49:32.842 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: Pruning pending checks. Highest nominated priority is 8646913479229198847
2020-11-29 17:49:32.842 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : conn.check list status: 1 nominated, 2 valid, c-id 1.
2020-11-29 17:49:32.842 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: agent_recv_message_unlocked: Valid STUN packet received.
2020-11-29 17:49:35.342 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: inbound STUN packet for 1/1 (stream/component) from [HIDDEN_FOR_PRIVACY]:53451 (100 octets) :
2020-11-29 17:49:35.342 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : STUN-CC RESP to 'HIDDEN_FOR_PRIVACY:53451', socket=22, len=92, cand=0x7efe3c017540 (c-id:1), use-cand=1.
2020-11-29 17:49:35.342 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : Found a matching pair 0x7efe3c03e0e0 (2:1802928054) (SUCCEEDED) ...
2020-11-29 17:49:35.342 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : nothing to do for pair 0x7efe3c03e0e0.
2020-11-29 17:49:35.342 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: Finding highest priority for component 1
2020-11-29 17:49:35.342 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: Pruning pending checks. Highest nominated priority is 8646913479229198847
2020-11-29 17:49:35.342 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : conn.check list status: 1 nominated, 2 valid, c-id 1.
2020-11-29 17:49:35.342 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : marking pair 0x7efe3c03e0e0 (2:1802928054) as nominated
2020-11-29 17:49:35.342 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: Finding highest priority for component 1
2020-11-29 17:49:35.342 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: Pruning pending checks. Highest nominated priority is 8646913479229198847
2020-11-29 17:49:35.342 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : conn.check list status: 1 nominated, 2 valid, c-id 1.
2020-11-29 17:49:35.342 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: agent_recv_message_unlocked: Valid STUN packet received.
2020-11-29 17:49:37.889 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: inbound STUN packet for 1/1 (stream/component) from [HIDDEN_FOR_PRIVACY]:53451 (100 octets) :
2020-11-29 17:49:37.889 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : STUN-CC RESP to 'HIDDEN_FOR_PRIVACY:53451', socket=22, len=92, cand=0x7efe3c017540 (c-id:1), use-cand=1.
2020-11-29 17:49:37.889 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : Found a matching pair 0x7efe3c03e0e0 (2:1802928054) (SUCCEEDED) ...
2020-11-29 17:49:37.889 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : nothing to do for pair 0x7efe3c03e0e0.
2020-11-29 17:49:37.889 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: Finding highest priority for component 1
2020-11-29 17:49:37.889 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: Pruning pending checks. Highest nominated priority is 8646913479229198847
2020-11-29 17:49:37.889 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : conn.check list status: 1 nominated, 2 valid, c-id 1.
2020-11-29 17:49:37.889 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : marking pair 0x7efe3c03e0e0 (2:1802928054) as nominated
2020-11-29 17:49:37.889 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: Finding highest priority for component 1
2020-11-29 17:49:37.889 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000: Pruning pending checks. Highest nominated priority is 8646913479229198847
2020-11-29 17:49:37.889 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: Agent 0x7efe3c019000 : conn.check list status: 1 nominated, 2 valid, c-id 1.
2020-11-29 17:49:37.889 VERB  [1166667] [rtc::IceTransport::LogCallback@734] nice: agent_recv_message_unlocked: Valid STUN packet received.

from datachannel-wasm.

paullouisageneau commented on September 15, 2024

It seems your libdatachannel version is a bit old, could you please try with the last version and repost the log if it still doesn't work?

from datachannel-wasm.

jeffRTC commented on September 15, 2024

Updated and doesn't work.

Here is log again,

2020-11-29 18:48:07.859 DEBUG [1173902] [rtc::InitLogger@40] Logger initialized
Server listening on port 8081
2020-11-29 18:48:13.061 DEBUG [1173903] [rtc::{anonymous}::doInit@46] Global initialization
2020-11-29 18:48:13.064 VERB  [1173903] [rtc::PeerConnection::PeerConnection@62] Creating PeerConnection
2020-11-29 18:48:13.064 VERB  [1173903] [rtc::PeerConnection::setRemoteDescription@203] Setting remote description: v=0
o=- 941261822490256288 0 IN IP4 127.0.0.1
s=-
t=0 0
a=group:BUNDLE 0
a=msid-semantic:WMS *
a=setup:actpass
a=ice-ufrag:I/Af
a=ice-pwd:MewgfUuJ2TGybttxXraUPd7D
a=ice-options:trickle
a=fingerprint:sha-256 C0:A6:47:49:08:E4:F0:F7:93:3E:D5:4C:03:6F:CE:09:0F:18:B6:E4:53:74:BB:74:D0:18:EE:67:14:E4:57:23
m=application 9 UDP/DTLS/SCTP webrtc-datachannel
c=IN IP4 0.0.0.0
a=bundle-only
a=mid:0
a=sendrecv
a=ice-options:trickle
a=sctp-port:5000
a=max-message-size:262144

2020-11-29 18:48:13.064 VERB  [1173903] [rtc::PeerConnection::validateRemoteDescription@930] Remote description looks valid
2020-11-29 18:48:13.064 VERB  [1173903] [rtc::PeerConnection::initIceTransport@399] Starting ICE transport
2020-11-29 18:48:13.065 DEBUG [1173903] [rtc::IceTransport::IceTransport@339] Initializing ICE transport (libnice)
2020-11-29 18:48:13.065 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Created NiceStream (1 created, 0 destroyed)
2020-11-29 18:48:13.065 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Created NiceComponent (1 created, 0 destroyed)
2020-11-29 18:48:13.065 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : allocating stream id 1 (0x7fe78801b620)
2020-11-29 18:48:13.065 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : Property set, role is already "controlling".
2020-11-29 18:48:13.077 DEBUG [1173903] [rtc::IceTransport::IceTransport@427] Using STUN server "stun.services.mozilla.com:3478"
2020-11-29 18:48:13.077 INFO  [1173903] [rtc::PeerConnection::changeSignalingState@1210] Changed signaling state to have-remote-offer
2020-11-29 18:48:13.077 VERB  [1173903] [rtc::PeerConnection::setLocalDescription@119] Setting local description, type=answer
2020-11-29 18:48:13.077 VERB  [1173903] [rtc::PeerConnection::initIceTransport@399] Starting ICE transport
2020-11-29 18:48:13.077 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : Property set, changing role to "controlled".
2020-11-29 18:48:13.077 DEBUG [1173903] [rtc::PeerConnection::processLocalDescription@959] Reciprocating application in local description, mid="0"
2020-11-29 18:48:13.290 VERB  [1173903] [rtc::PeerConnection::processLocalDescription@1069] Issuing local description: v=0
o=rtc 1977994949 0 IN IP4 127.0.0.1
s=-
t=0 0
a=group:BUNDLE 0
a=msid-semantic:WMS *
a=setup:active
a=ice-ufrag:+Q4s
a=ice-pwd:P5ffIs9N6eV/D6mYh45dOp
a=ice-options:trickle
a=fingerprint:sha-256 D6:42:17:9E:C7:D9:FC:D5:83:04:E0:66:6C:33:1C:90:B1:6C:EC:72:EC:D2:1D:04:2C:AB:3E:9C:F6:E0:86:4C
m=application 9 UDP/DTLS/SCTP webrtc-datachannel
c=IN IP4 0.0.0.0
a=bundle-only
a=mid:0
a=sendrecv
a=ice-options:trickle
a=sctp-port:5000
a=max-message-size:262144

2020-11-29 18:48:13.290 INFO  [1173903] [rtc::PeerConnection::changeSignalingState@1210] Changed signaling state to stable
2020-11-29 18:48:13.290 INFO  [1173903] [rtc::PeerConnection::changeGatheringState@1199] Changed gathering state to in-progress
2020-11-29 18:48:13.290 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : In ICE-FULL mode, starting candidate gathering.
2020-11-29 18:48:13.290 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : UPnP property Disabled
2020-11-29 18:48:13.290 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Failed to convert address to string for interface ‘lo’.
2020-11-29 18:48:13.290 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Failed to convert address to string for interface ‘eth0’.
2020-11-29 18:48:13.290 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Interface:  lo
2020-11-29 18:48:13.290 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: IP Address: 127.0.0.1
2020-11-29 18:48:13.290 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Ignoring loopback interface
2020-11-29 18:48:13.290 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Interface:  eth0
2020-11-29 18:48:13.290 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: IP Address: HIDDEN_FOR_PRIVACY
2020-11-29 18:48:13.290 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Interface:  lo
2020-11-29 18:48:13.290 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: IP Address: ::1
2020-11-29 18:48:13.290 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Ignoring loopback interface
2020-11-29 18:48:13.290 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Interface:  eth0
2020-11-29 18:48:13.290 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: IP Address: HIDDEN_FOR_PRIVACY
2020-11-29 18:48:13.290 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Interface:  eth0
2020-11-29 18:48:13.290 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: IP Address: HIDDEN_FOR_PRIVACY%eth0
2020-11-29 18:48:13.290 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Trying to create host candidate on port 27864
2020-11-29 18:48:13.291 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Component 0x7fe78801bd40: Attach source (stream 1).
2020-11-29 18:48:13.291 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Attaching source 0x7fe788025070 (socket 0x7fe788014ae0, FD 19) to context 0x7fe788011610
2020-11-29 18:48:13.291 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Trying to create host candidate on port 59682
2020-11-29 18:48:13.291 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Component 0x7fe78801bd40: Attach source (stream 1).
2020-11-29 18:48:13.291 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Attaching source 0x7fe7880251d0 (socket 0x7fe788025880, FD 20) to context 0x7fe788011610
2020-11-29 18:48:13.291 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Trying to create host candidate on port 47816
2020-11-29 18:48:13.291 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Could not set IPV6 socket ToS: Protocol not available
2020-11-29 18:48:13.291 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Component 0x7fe78801bd40: Attach source (stream 1).
2020-11-29 18:48:13.291 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Attaching source 0x7fe788027a10 (socket 0x7fe7880258f0, FD 21) to context 0x7fe788011610
2020-11-29 18:48:13.291 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : Adding new srv-rflx candidate discovery 0x7fe788027b70
2020-11-29 18:48:13.291 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : discovery tick #1 with list 0x7fe788010ec0 (1)
2020-11-29 18:48:13.291 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : discovery - scheduling cand type 1 addr 52.87.201.4.
2020-11-29 18:48:13.291 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : stream 1 component 1 STATE-CHANGE disconnected -> gathering.
2020-11-29 18:48:13.291 VERB  [1173903] [rtc::Candidate::parse@98] Parsing candidate: 1 1 UDP 2013266431 HIDDEN_FOR_PRIVACY 27864 typ host
2020-11-29 18:48:13.291 VERB  [1173903] [rtc::Candidate::resolve@142] Resolving candidate (mode=simple): HIDDEN_FOR_PRIVACY 27864
2020-11-29 18:48:13.291 VERB  [1173903] [rtc::Candidate::resolve@174] Resolved candidate: HIDDEN_FOR_PRIVACY 27864
2020-11-29 18:48:13.291 VERB  [1173903] [rtc::PeerConnection::processLocalCandidate@1086] Issuing local candidate: a=candidate:1 1 UDP 2013266431 HIDDEN_FOR_PRIVACY 27864 typ host
Gathering State: in-progress
2020-11-29 18:48:13.291 VERB  [1173903] [rtc::Candidate::parse@98] Parsing candidate: 2 1 UDP 2013266430 HIDDEN_FOR_PRIVACY 59682 typ host
2020-11-29 18:48:13.291 VERB  [1173903] [rtc::Candidate::resolve@142] Resolving candidate (mode=simple): HIDDEN_FOR_PRIVACY 59682
2020-11-29 18:48:13.291 VERB  [1173903] [rtc::Candidate::resolve@174] Resolved candidate: HIDDEN_FOR_PRIVACY 59682
2020-11-29 18:48:13.291 VERB  [1173903] [rtc::PeerConnection::processLocalCandidate@1086] Issuing local candidate: a=candidate:2 1 UDP 2013266430 HIDDEN_FOR_PRIVACY 59682 typ host
Adding Candidate
2020-11-29 18:48:13.291 VERB  [1173903] [rtc::Candidate::parse@98] Parsing candidate: 3 1 UDP 2013266429 HIDDEN_FOR_PRIVACY 47816 typ host
2020-11-29 18:48:13.292 VERB  [1173903] [rtc::Candidate::resolve@142] Resolving candidate (mode=simple): HIDDEN_FOR_PRIVACY 47816
2020-11-29 18:48:13.292 VERB  [1173903] [rtc::Candidate::resolve@174] Resolved candidate: HIDDEN_FOR_PRIVACY 47816
2020-11-29 18:48:13.292 VERB  [1173903] [rtc::PeerConnection::processLocalCandidate@1086] Issuing local candidate: a=candidate:3 1 UDP 2013266429 HIDDEN_FOR_PRIVACY 47816 typ host
Adding Candidate
Adding Candidate
2020-11-29 18:48:13.292 VERB  [1173903] [rtc::Candidate::parse@98] Parsing candidate: 1802928054 1 udp 2122262783 HIDDEN_FOR_PRIVACY 53874 typ host generation 0 ufrag I/Af network-id 4
2020-11-29 18:48:13.292 VERB  [1173903] [rtc::PeerConnection::addRemoteCandidate@303] Adding remote candidate: a=candidate:1802928054 1 udp 2122262783 HIDDEN_FOR_PRIVACY 53874 typ host generation 0 ufrag I/Af network-id 4
2020-11-29 18:48:13.292 VERB  [1173903] [rtc::Candidate::resolve@142] Resolving candidate (mode=simple): HIDDEN_FOR_PRIVACY 53874
2020-11-29 18:48:13.292 VERB  [1173903] [rtc::Candidate::resolve@174] Resolved candidate: HIDDEN_FOR_PRIVACY 53874
2020-11-29 18:48:13.292 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: set_remote_candidates 1 1
2020-11-29 18:48:13.292 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : Adding UDP remote candidate with addr [HIDDEN_FOR_PRIVACY]:53874 for s1/c1. U/P '(null)'/'(null)' prio: 2122262783
2020-11-29 18:48:13.292 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : creating a new pair
2020-11-29 18:48:13.292 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : pair 0x7fe78803e830 state FROZEN (priv_add_new_check_pair)
2020-11-29 18:48:13.292 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : new pair 0x7fe78803e830 : [HIDDEN_FOR_PRIVACY]:27864 --> [HIDDEN_FOR_PRIVACY]:53874
2020-11-29 18:48:13.292 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : added a new pair 0x7fe78803e830 with foundation '1:1802928054' to stream 1 component 1.
2020-11-29 18:48:13.292 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : stream 1 component 1 STATE-CHANGE gathering -> connecting.
2020-11-29 18:48:13.292 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : creating a new pair
2020-11-29 18:48:13.292 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : pair 0x7fe78803e8e0 state FROZEN (priv_add_new_check_pair)
2020-11-29 18:48:13.292 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : new pair 0x7fe78803e8e0 : [HIDDEN_FOR_PRIVACY]:59682 --> [HIDDEN_FOR_PRIVACY]:53874
2020-11-29 18:48:13.292 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : added a new pair 0x7fe78803e8e0 with foundation '2:1802928054' to stream 1 component 1.
2020-11-29 18:48:13.292 INFO  [1173903] [rtc::PeerConnection::changeState@1182] Changed state to connecting
State: connecting
2020-11-29 18:48:13.292 VERB  [1173903] [rtc::Candidate::parse@98] Parsing candidate: 4201576948 1 udp 2122194687 HIDDEN_FOR_PRIVACY 53875 typ host generation 0 ufrag I/Af network-id 1
2020-11-29 18:48:13.292 VERB  [1173903] [rtc::PeerConnection::addRemoteCandidate@303] Adding remote candidate: a=candidate:4201576948 1 udp 2122194687 HIDDEN_FOR_PRIVACY 53875 typ host generation 0 ufrag I/Af network-id 1
2020-11-29 18:48:13.292 VERB  [1173903] [rtc::Candidate::resolve@142] Resolving candidate (mode=simple): HIDDEN_FOR_PRIVACY 53875
2020-11-29 18:48:13.292 VERB  [1173903] [rtc::Candidate::resolve@174] Resolved candidate: HIDDEN_FOR_PRIVACY 53875
2020-11-29 18:48:13.292 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: set_remote_candidates 1 1
2020-11-29 18:48:13.292 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : Adding UDP remote candidate with addr [HIDDEN_FOR_PRIVACY]:53875 for s1/c1. U/P '(null)'/'(null)' prio: 2122194687
2020-11-29 18:48:13.292 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : creating a new pair
2020-11-29 18:48:13.293 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : pair 0x7fe78803e990 state FROZEN (priv_add_new_check_pair)
2020-11-29 18:48:13.293 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : new pair 0x7fe78803e990 : [HIDDEN_FOR_PRIVACY]:47816 --> [HIDDEN_FOR_PRIVACY]:53875
2020-11-29 18:48:13.293 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : added a new pair 0x7fe78803e990 with foundation '3:4201576948' to stream 1 component 1.
2020-11-29 18:48:13.293 VERB  [1173903] [rtc::Candidate::parse@98] Parsing candidate: 2999745851 1 udp 2122129151 HIDDEN_FOR_PRIVACY 53876 typ host generation 0 ufrag I/Af network-id 2
2020-11-29 18:48:13.293 VERB  [1173903] [rtc::PeerConnection::addRemoteCandidate@303] Adding remote candidate: a=candidate:2999745851 1 udp 2122129151 HIDDEN_FOR_PRIVACY 53876 typ host generation 0 ufrag I/Af network-id 2
2020-11-29 18:48:13.293 VERB  [1173903] [rtc::Candidate::resolve@142] Resolving candidate (mode=simple): HIDDEN_FOR_PRIVACY 53876
2020-11-29 18:48:13.293 VERB  [1173903] [rtc::Candidate::resolve@174] Resolved candidate: HIDDEN_FOR_PRIVACY 53876
2020-11-29 18:48:13.293 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: set_remote_candidates 1 1
2020-11-29 18:48:13.293 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : Adding UDP remote candidate with addr [HIDDEN_FOR_PRIVACY]:53876 for s1/c1. U/P '(null)'/'(null)' prio: 2122129151
2020-11-29 18:48:13.293 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : creating a new pair
2020-11-29 18:48:13.293 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : pair 0x7fe78803ea40 state FROZEN (priv_add_new_check_pair)
2020-11-29 18:48:13.293 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : new pair 0x7fe78803ea40 : [HIDDEN_FOR_PRIVACY]:47816 --> [HIDDEN_FOR_PRIVACY]:53876
2020-11-29 18:48:13.293 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : added a new pair 0x7fe78803ea40 with foundation '3:2999745851' to stream 1 component 1.
2020-11-29 18:48:13.293 VERB  [1173903] [rtc::Candidate::parse@98] Parsing candidate: 917165150 1 udp 2122063615 HIDDEN_FOR_PRIVACY 53877 typ host generation 0 ufrag I/Af network-id 3
2020-11-29 18:48:13.293 VERB  [1173903] [rtc::PeerConnection::addRemoteCandidate@303] Adding remote candidate: a=candidate:917165150 1 udp 2122063615 HIDDEN_FOR_PRIVACY 53877 typ host generation 0 ufrag I/Af network-id 3
2020-11-29 18:48:13.293 VERB  [1173903] [rtc::Candidate::resolve@142] Resolving candidate (mode=simple): HIDDEN_FOR_PRIVACY 53877
2020-11-29 18:48:13.293 VERB  [1173903] [rtc::Candidate::resolve@174] Resolved candidate: HIDDEN_FOR_PRIVACY 53877
2020-11-29 18:48:13.293 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: set_remote_candidates 1 1
2020-11-29 18:48:13.293 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : Adding UDP remote candidate with addr [HIDDEN_FOR_PRIVACY]:53877 for s1/c1. U/P '(null)'/'(null)' prio: 2122063615
2020-11-29 18:48:13.293 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : creating a new pair
2020-11-29 18:48:13.293 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : pair 0x7fe78803eaf0 state FROZEN (priv_add_new_check_pair)
2020-11-29 18:48:13.293 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : new pair 0x7fe78803eaf0 : [HIDDEN_FOR_PRIVACY]:47816 --> [HIDDEN_FOR_PRIVACY]:53877
2020-11-29 18:48:13.293 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : added a new pair 0x7fe78803eaf0 with foundation '3:917165150' to stream 1 component 1.
2020-11-29 18:48:13.293 VERB  [1173903] [rtc::Candidate::parse@98] Parsing candidate: 636846918 1 tcp 1518283007 HIDDEN_FOR_PRIVACY 9 typ host tcptype active generation 0 ufrag I/Af network-id 4
2020-11-29 18:48:13.293 VERB  [1173903] [rtc::PeerConnection::addRemoteCandidate@303] Adding remote candidate: a=candidate:636846918 1 tcp 1518283007 HIDDEN_FOR_PRIVACY 9 typ host tcptype active generation 0 ufrag I/Af network-id 4
2020-11-29 18:48:13.293 VERB  [1173903] [rtc::Candidate::resolve@142] Resolving candidate (mode=simple): HIDDEN_FOR_PRIVACY 9
2020-11-29 18:48:13.293 VERB  [1173903] [rtc::Candidate::resolve@174] Resolved candidate: HIDDEN_FOR_PRIVACY 9
2020-11-29 18:48:13.293 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: set_remote_candidates 1 1
2020-11-29 18:48:13.293 VERB  [1173903] [rtc::Candidate::parse@98] Parsing candidate: 3035432196 1 tcp 1518214911 HIDDEN_FOR_PRIVACY 9 typ host tcptype active generation 0 ufrag I/Af network-id 1
2020-11-29 18:48:13.293 VERB  [1173903] [rtc::PeerConnection::addRemoteCandidate@303] Adding remote candidate: a=candidate:3035432196 1 tcp 1518214911 HIDDEN_FOR_PRIVACY 9 typ host tcptype active generation 0 ufrag I/Af network-id 1
2020-11-29 18:48:13.293 VERB  [1173903] [rtc::Candidate::resolve@142] Resolving candidate (mode=simple): HIDDEN_FOR_PRIVACY 9
2020-11-29 18:48:13.293 VERB  [1173903] [rtc::Candidate::resolve@174] Resolved candidate: HIDDEN_FOR_PRIVACY 9
2020-11-29 18:48:13.293 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: set_remote_candidates 1 1
2020-11-29 18:48:13.293 VERB  [1173903] [rtc::Candidate::parse@98] Parsing candidate: 4233069003 1 tcp 1518149375 HIDDEN_FOR_PRIVACY 9 typ host tcptype active generation 0 ufrag I/Af network-id 2
2020-11-29 18:48:13.293 VERB  [1173903] [rtc::PeerConnection::addRemoteCandidate@303] Adding remote candidate: a=candidate:4233069003 1 tcp 1518149375 HIDDEN_FOR_PRIVACY 9 typ host tcptype active generation 0 ufrag I/Af network-id 2
2020-11-29 18:48:13.293 VERB  [1173903] [rtc::Candidate::resolve@142] Resolving candidate (mode=simple): HIDDEN_FOR_PRIVACY 9
2020-11-29 18:48:13.293 VERB  [1173903] [rtc::Candidate::resolve@174] Resolved candidate: HIDDEN_FOR_PRIVACY 9
2020-11-29 18:48:13.293 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: set_remote_candidates 1 1
2020-11-29 18:48:13.294 VERB  [1173903] [rtc::Candidate::parse@98] Parsing candidate: 2015963310 1 tcp 1518083839 HIDDEN_FOR_PRIVACY 9 typ host tcptype active generation 0 ufrag I/Af network-id 3
2020-11-29 18:48:13.294 VERB  [1173903] [rtc::PeerConnection::addRemoteCandidate@303] Adding remote candidate: a=candidate:2015963310 1 tcp 1518083839 HIDDEN_FOR_PRIVACY 9 typ host tcptype active generation 0 ufrag I/Af network-id 3
2020-11-29 18:48:13.294 VERB  [1173903] [rtc::Candidate::resolve@142] Resolving candidate (mode=simple): HIDDEN_FOR_PRIVACY 9
2020-11-29 18:48:13.294 VERB  [1173903] [rtc::Candidate::resolve@174] Resolved candidate: HIDDEN_FOR_PRIVACY 9
2020-11-29 18:48:13.294 VERB  [1173903] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: set_remote_candidates 1 1
2020-11-29 18:48:13.317 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : Pair 0x7fe78803e830 with s/c-id 1/1 (1:1802928054) unfrozen.
2020-11-29 18:48:13.317 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : pair 0x7fe78803e830 state WAITING (priv_conn_check_unfreeze_next)
2020-11-29 18:48:13.317 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : Pair 0x7fe78803e8e0 with s/c-id 1/1 (2:1802928054) unfrozen.
2020-11-29 18:48:13.317 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : pair 0x7fe78803e8e0 state WAITING (priv_conn_check_unfreeze_next)
2020-11-29 18:48:13.317 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : Pair 0x7fe78803e990 with s/c-id 1/1 (3:4201576948) unfrozen.
2020-11-29 18:48:13.317 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : pair 0x7fe78803e990 state WAITING (priv_conn_check_unfreeze_next)
2020-11-29 18:48:13.317 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : Pair 0x7fe78803ea40 with s/c-id 1/1 (3:2999745851) unfrozen.
2020-11-29 18:48:13.317 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : pair 0x7fe78803ea40 state WAITING (priv_conn_check_unfreeze_next)
2020-11-29 18:48:13.317 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : Pair 0x7fe78803eaf0 with s/c-id 1/1 (3:917165150) unfrozen.
2020-11-29 18:48:13.317 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : pair 0x7fe78803eaf0 state WAITING (priv_conn_check_unfreeze_next)
2020-11-29 18:48:13.318 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : pair 0x7fe78803e830 state IN_PROGRESS (priv_conn_check_initiate)
2020-11-29 18:48:13.318 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : STUN-CC REQ [HIDDEN_FOR_PRIVACY]:27864 --> [HIDDEN_FOR_PRIVACY]:53874, socket=19, pair=0x7fe78803e830 (c-id:1), tie=12465938710344014198, username='I/Af:+Q4s' (9), password='MewgfUuJ2TGybttxXraUPd7D' (24), prio=1845494271, controlled.
2020-11-29 18:48:13.318 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : conn_check_send: set cand_use=0 (aggressive nomination).
2020-11-29 18:48:13.318 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: conncheck created 88 - 0x7fe778003640
2020-11-29 18:48:13.318 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : timer set to 125ms, waiting+in_progress=5, nb_active=1
2020-11-29 18:48:13.318 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : stream 1: timer tick #1: 0 frozen, 1 in-progress, 4 waiting, 0 succeeded, 0 discovered, 0 nominated, 0 waiting-for-nom, 0 valid.
2020-11-29 18:48:13.343 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : pair 0x7fe78803e8e0 state IN_PROGRESS (priv_conn_check_initiate)
2020-11-29 18:48:13.343 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : STUN-CC REQ [HIDDEN_FOR_PRIVACY]:59682 --> [HIDDEN_FOR_PRIVACY]:53874, socket=20, pair=0x7fe78803e8e0 (c-id:1), tie=12465938710344014198, username='I/Af:+Q4s' (9), password='MewgfUuJ2TGybttxXraUPd7D' (24), prio=1845494270, controlled.
2020-11-29 18:48:13.343 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : conn_check_send: set cand_use=0 (aggressive nomination).
2020-11-29 18:48:13.343 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: conncheck created 88 - 0x7fe778005430
2020-11-29 18:48:13.343 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : timer set to 125ms, waiting+in_progress=5, nb_active=1
2020-11-29 18:48:13.368 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : pair 0x7fe78803e990 state IN_PROGRESS (priv_conn_check_initiate)
2020-11-29 18:48:13.368 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : STUN-CC REQ [HIDDEN_FOR_PRIVACY]:47816 --> [HIDDEN_FOR_PRIVACY]:53875, socket=21, pair=0x7fe78803e990 (c-id:1), tie=12465938710344014198, username='I/Af:+Q4s' (9), password='MewgfUuJ2TGybttxXraUPd7D' (24), prio=1845494269, controlled.
2020-11-29 18:48:13.368 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : conn_check_send: set cand_use=0 (aggressive nomination).
2020-11-29 18:48:13.369 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: conncheck created 88 - 0x7fe778005f50
2020-11-29 18:48:13.369 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : timer set to 125ms, waiting+in_progress=5, nb_active=1
2020-11-29 18:48:13.379 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: inbound STUN packet for 1/1 (stream/component) from [HIDDEN_FOR_PRIVACY]:53874 (100 octets) :
2020-11-29 18:48:13.379 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 :  1:1 Adding valid source candidate: HIDDEN_FOR_PRIVACY:53874 trans: 0
2020-11-29 18:48:13.379 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : STUN-CC RESP to 'HIDDEN_FOR_PRIVACY:53874', socket=20, len=92, cand=0x7fe788017540 (c-id:1), use-cand=1.
2020-11-29 18:48:13.379 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : Found a matching pair 0x7fe78803e8e0 (2:1802928054) (IN_PROGRESS) ...
2020-11-29 18:48:13.379 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : pair 0x7fe78803e8e0 added for a triggered check.
2020-11-29 18:48:13.379 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : pair 0x7fe78803e8e0 state IN_PROGRESS (priv_add_pair_to_triggered_check_queue)
2020-11-29 18:48:13.379 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : pair 0x7fe78803e8e0 (2:1802928054) is in-progress, will be nominated on response receipt.
2020-11-29 18:48:13.379 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: agent_recv_message_unlocked: Valid STUN packet received.
2020-11-29 18:48:13.391 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: inbound STUN packet for 1/1 (stream/component) from [HIDDEN_FOR_PRIVACY]:53874 (76 octets) :
2020-11-29 18:48:13.391 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : stun_bind_process/conncheck for 0x7fe78803e8e0: controlled,res=success,stun#=0.
2020-11-29 18:48:13.391 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : pair 0x7fe78803e8e0 MATCHED.
2020-11-29 18:48:13.391 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : pair 0x7fe78803e8e0 state SUCCEEDED (priv_process_response_check_for_reflexive)
2020-11-29 18:48:13.391 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : Updating nominated flag (UDP): ok_pair=0x7fe78803e8e0 (0/1) p=0x7fe78803e8e0 (0/1) (ucnc/mnora)
2020-11-29 18:48:13.391 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : marking pair 0x7fe78803e8e0 (2:1802928054) as nominated (aggressive nomination, controlled, mark_on_response=1).
2020-11-29 18:48:13.391 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : changing SELECTED PAIR for component 1: 2:1802928054 (prio:8646913479229198847).
2020-11-29 18:48:13.391 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: setting SELECTED PAIR for component 1: 2:1802928054 (prio:8646913479229198847).
2020-11-29 18:48:13.391 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : stun_bind_keepalive for pair 0x7fe78801bdb0 res 28.
2020-11-29 18:48:13.391 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : resending STUN on 3 to keep the candidate alive.
2020-11-29 18:48:13.391 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Local selected pair: 1:1 2 UDP HIDDEN_FOR_PRIVACY:59682 HOST
2020-11-29 18:48:13.392 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Remote selected pair: 1:1 1802928054 UDP HIDDEN_FOR_PRIVACY:53874 HOST
2020-11-29 18:48:13.392 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : stream 1 component 1 STATE-CHANGE connecting -> connected.
2020-11-29 18:48:13.392 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Finding highest priority for component 1
2020-11-29 18:48:13.392 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Pruning pending checks. Highest nominated priority is 8646913479229198847
2020-11-29 18:48:13.392 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : pair 0x7fe78803e830 kept IN_PROGRESS because priority 8646913483524166143 is higher than currently nominated pair 8646913479229198847
2020-11-29 18:48:13.392 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : pair 0x7fe78803e990 will not be retransmitted.
2020-11-29 18:48:13.392 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : pair 0x7fe78803ea40 removed.
2020-11-29 18:48:13.392 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : pair 0x7fe78803eaf0 removed.
2020-11-29 18:48:13.392 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : conn.check list status: 1 nominated, 1 valid, c-id 1.
2020-11-29 18:48:13.392 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: agent_recv_message_unlocked: Valid STUN packet received.
2020-11-29 18:48:13.392 VERB  [1173929] [rtc::PeerConnection::initDtlsTransport@462] Starting DTLS transport
2020-11-29 18:48:13.392 DEBUG [1173929] [rtc::DtlsTransport::DtlsTransport@58] Initializing DTLS transport (GnuTLS)
2020-11-29 18:48:13.392 VERB  [1173929] [rtc::Transport::registerIncoming@57] Registering incoming callback
2020-11-29 18:48:13.392 DEBUG [1173929] [rtc::DtlsTransport::start@105] Starting DTLS recv thread
2020-11-29 18:48:13.393 VERB  [1173934] [rtc::IceTransport::send@621] Send size=215
2020-11-29 18:48:13.427 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: inbound STUN packet for 1/1 (stream/component) from [HIDDEN_FOR_PRIVACY]:53874 (100 octets) :
2020-11-29 18:48:13.427 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : STUN-CC RESP to 'HIDDEN_FOR_PRIVACY:53874', socket=20, len=92, cand=0x7fe788017540 (c-id:1), use-cand=1.
2020-11-29 18:48:13.427 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : Found a matching pair 0x7fe78803e8e0 (2:1802928054) (SUCCEEDED) ...
2020-11-29 18:48:13.427 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : nothing to do for pair 0x7fe78803e8e0.
2020-11-29 18:48:13.428 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Finding highest priority for component 1
2020-11-29 18:48:13.428 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Pruning pending checks. Highest nominated priority is 8646913479229198847
2020-11-29 18:48:13.428 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : pair 0x7fe78803e830 kept IN_PROGRESS because priority 8646913483524166143 is higher than currently nominated pair 8646913479229198847
2020-11-29 18:48:13.428 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : pair 0x7fe78803e990 will not be retransmitted.
2020-11-29 18:48:13.428 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : conn.check list status: 1 nominated, 1 valid, c-id 1.
2020-11-29 18:48:13.428 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : marking pair 0x7fe78803e8e0 (2:1802928054) as nominated
2020-11-29 18:48:13.428 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Finding highest priority for component 1
2020-11-29 18:48:13.428 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Pruning pending checks. Highest nominated priority is 8646913479229198847
2020-11-29 18:48:13.428 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : pair 0x7fe78803e830 kept IN_PROGRESS because priority 8646913483524166143 is higher than currently nominated pair 8646913479229198847
2020-11-29 18:48:13.428 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : pair 0x7fe78803e990 will not be retransmitted.
2020-11-29 18:48:13.428 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : conn.check list status: 1 nominated, 1 valid, c-id 1.
2020-11-29 18:48:13.428 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: agent_recv_message_unlocked: Valid STUN packet received.
2020-11-29 18:48:13.440 VERB  [1173929] [rtc::IceTransport::RecvCallback@731] Incoming size=639
2020-11-29 18:48:13.441 VERB  [1173929] [rtc::DtlsTransport::incoming@143] Incoming size=639
2020-11-29 18:48:13.444 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 :STUN transaction retransmitted on pair 0x7fe78803e830 (timer=2/3 2/250ms).
2020-11-29 18:48:13.476 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: inbound STUN packet for 1/1 (stream/component) from [HIDDEN_FOR_PRIVACY]:53874 (100 octets) :
2020-11-29 18:48:13.476 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : STUN-CC RESP to 'HIDDEN_FOR_PRIVACY:53874', socket=20, len=92, cand=0x7fe788017540 (c-id:1), use-cand=1.
2020-11-29 18:48:13.476 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : Found a matching pair 0x7fe78803e8e0 (2:1802928054) (SUCCEEDED) ...
2020-11-29 18:48:13.476 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : nothing to do for pair 0x7fe78803e8e0.
2020-11-29 18:48:13.476 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Finding highest priority for component 1
2020-11-29 18:48:13.477 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Pruning pending checks. Highest nominated priority is 8646913479229198847
2020-11-29 18:48:13.477 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : pair 0x7fe78803e830 kept IN_PROGRESS because priority 8646913483524166143 is higher than currently nominated pair 8646913479229198847
2020-11-29 18:48:13.477 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : pair 0x7fe78803e990 will not be retransmitted.
2020-11-29 18:48:13.477 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : conn.check list status: 1 nominated, 1 valid, c-id 1.
2020-11-29 18:48:13.477 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : marking pair 0x7fe78803e8e0 (2:1802928054) as nominated
2020-11-29 18:48:13.477 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Finding highest priority for component 1
2020-11-29 18:48:13.477 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Pruning pending checks. Highest nominated priority is 8646913479229198847
2020-11-29 18:48:13.477 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : pair 0x7fe78803e830 kept IN_PROGRESS because priority 8646913483524166143 is higher than currently nominated pair 8646913479229198847
2020-11-29 18:48:13.477 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : pair 0x7fe78803e990 will not be retransmitted.
2020-11-29 18:48:13.477 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : conn.check list status: 1 nominated, 1 valid, c-id 1.
2020-11-29 18:48:13.477 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: agent_recv_message_unlocked: Valid STUN packet received.
2020-11-29 18:48:13.520 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : Retransmissions failed, giving up on pair 0x7fe78803e990
2020-11-29 18:48:13.520 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : Failed pair is [HIDDEN_FOR_PRIVACY]:47816 --> [HIDDEN_FOR_PRIVACY]:53875
2020-11-29 18:48:13.520 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : pair 0x7fe78803e990 state FAILED (candidate_check_pair_fail)
2020-11-29 18:48:13.520 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Finding highest priority for component 1
2020-11-29 18:48:13.520 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Pruning pending checks. Highest nominated priority is 8646913479229198847
2020-11-29 18:48:13.520 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : pair 0x7fe78803e830 kept IN_PROGRESS because priority 8646913483524166143 is higher than currently nominated pair 8646913479229198847
2020-11-29 18:48:13.520 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : conn.check list status: 1 nominated, 1 valid, c-id 1.
2020-11-29 18:48:13.538 VERB  [1173929] [rtc::IceTransport::RecvCallback@731] Incoming size=639
2020-11-29 18:48:13.538 VERB  [1173929] [rtc::DtlsTransport::incoming@143] Incoming size=639
2020-11-29 18:48:13.608 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: inbound STUN packet for 1/1 (stream/component) from [HIDDEN_FOR_PRIVACY]:53877 (96 octets) :
2020-11-29 18:48:13.608 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 :  1:1 Adding valid source candidate: HIDDEN_FOR_PRIVACY:53877 trans: 0
2020-11-29 18:48:13.608 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : STUN-CC RESP to 'HIDDEN_FOR_PRIVACY:53877', socket=21, len=80, cand=0x7fe78803f800 (c-id:1), use-cand=0.
2020-11-29 18:48:13.608 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : Adding a triggered check to conn.check list (local=0x7fe788017390).
2020-11-29 18:48:13.608 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : creating a new pair
2020-11-29 18:48:13.608 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : pair 0x7fe78803eaf0 state WAITING (priv_add_new_check_pair)
2020-11-29 18:48:13.608 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : new pair 0x7fe78803eaf0 : [HIDDEN_FOR_PRIVACY]:47816 --> [HIDDEN_FOR_PRIVACY]:53877
2020-11-29 18:48:13.608 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : added a new pair 0x7fe78803eaf0 with foundation '3:917165150' to stream 1 component 1.
2020-11-29 18:48:13.608 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : pair 0x7fe78803eaf0 state IN_PROGRESS (priv_add_pair_to_triggered_check_queue)
2020-11-29 18:48:13.608 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: agent_recv_message_unlocked: Valid STUN packet received.
2020-11-29 18:48:13.621 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : STUN-CC REQ [HIDDEN_FOR_PRIVACY]:47816 --> [HIDDEN_FOR_PRIVACY]:53877, socket=21, pair=0x7fe78803eaf0 (c-id:1), tie=12465938710344014198, username='I/Af:+Q4s' (9), password='MewgfUuJ2TGybttxXraUPd7D' (24), prio=1845494268, controlled.
2020-11-29 18:48:13.622 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : conn_check_send: set cand_use=0 (aggressive nomination).
2020-11-29 18:48:13.622 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: conncheck created 88 - 0x7fe77800f270
2020-11-29 18:48:13.622 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : timer set to 100ms, waiting+in_progress=2, nb_active=1
2020-11-29 18:48:13.648 VERB  [1173934] [rtc::IceTransport::send@621] Send size=983
2020-11-29 18:48:13.648 VERB  [1173934] [rtc::IceTransport::send@621] Send size=91
2020-11-29 18:48:13.648 VERB  [1173934] [rtc::IceTransport::send@621] Send size=413
2020-11-29 18:48:13.648 VERB  [1173934] [rtc::IceTransport::send@621] Send size=14
2020-11-29 18:48:13.648 VERB  [1173934] [rtc::IceTransport::send@621] Send size=53
2020-11-29 18:48:13.653 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: inbound STUN packet for 1/1 (stream/component) from [HIDDEN_FOR_PRIVACY]:53877 (64 octets) :
2020-11-29 18:48:13.654 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : stun_bind_process/conncheck for 0x7fe78803eaf0: controlled,res=success,stun#=0.
2020-11-29 18:48:13.654 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : pair 0x7fe78803eaf0 MATCHED.
2020-11-29 18:48:13.654 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : pair 0x7fe78803eaf0 state SUCCEEDED (priv_process_response_check_for_reflexive)
2020-11-29 18:48:13.654 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : Updating nominated flag (UDP): ok_pair=0x7fe78803eaf0 (0/0) p=0x7fe78803eaf0 (0/0) (ucnc/mnora)
2020-11-29 18:48:13.654 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Finding highest priority for component 1
2020-11-29 18:48:13.654 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Pruning pending checks. Highest nominated priority is 8646913479229198847
2020-11-29 18:48:13.654 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : pair 0x7fe78803e830 kept IN_PROGRESS because priority 8646913483524166143 is higher than currently nominated pair 8646913479229198847
2020-11-29 18:48:13.654 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : conn.check list status: 1 nominated, 2 valid, c-id 1.
2020-11-29 18:48:13.654 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: agent_recv_message_unlocked: Valid STUN packet received.
2020-11-29 18:48:13.697 VERB  [1173929] [rtc::IceTransport::RecvCallback@731] Incoming size=1181
2020-11-29 18:48:13.697 VERB  [1173929] [rtc::DtlsTransport::incoming@143] Incoming size=1181
2020-11-29 18:48:13.697 VERB  [1173929] [rtc::IceTransport::RecvCallback@731] Incoming size=53
2020-11-29 18:48:13.697 VERB  [1173929] [rtc::DtlsTransport::incoming@143] Incoming size=53
2020-11-29 18:48:13.698 VERB  [1173929] [rtc::IceTransport::RecvCallback@731] Incoming size=73
2020-11-29 18:48:13.698 VERB  [1173929] [rtc::DtlsTransport::incoming@143] Incoming size=73
2020-11-29 18:48:13.698 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 :STUN transaction retransmitted on pair 0x7fe78803e830 (timer=3/3 5/125ms).
2020-11-29 18:48:13.824 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : Retransmissions failed, giving up on pair 0x7fe78803e830
2020-11-29 18:48:13.824 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : Failed pair is [HIDDEN_FOR_PRIVACY]:27864 --> [HIDDEN_FOR_PRIVACY]:53874
2020-11-29 18:48:13.824 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : pair 0x7fe78803e830 state FAILED (candidate_check_pair_fail)
2020-11-29 18:48:13.824 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Finding highest priority for component 1
2020-11-29 18:48:13.824 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Pruning pending checks. Highest nominated priority is 8646913479229198847
2020-11-29 18:48:13.824 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : stream 1 component 1 STATE-CHANGE connected -> ready.
2020-11-29 18:48:13.824 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : conn.check list status: 1 nominated, 2 valid, c-id 1.
2020-11-29 18:48:13.825 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : waiting 1000 msecs before checking for failed components.
2020-11-29 18:48:14.249 INFO  [1173934] [rtc::DtlsTransport::runRecvLoop@187] DTLS handshake finished
2020-11-29 18:48:14.249 VERB  [1173934] [rtc::PeerConnection::initSctpTransport@533] Starting SCTP transport
2020-11-29 18:48:14.250 DEBUG [1173934] [rtc::SctpTransport::SctpTransport@95] Initializing SCTP transport
2020-11-29 18:48:14.250 VERB  [1173934] [rtc::Transport::registerIncoming@57] Registering incoming callback
2020-11-29 18:48:14.250 DEBUG [1173934] [rtc::SctpTransport::connect@243] SCTP connecting
2020-11-29 18:48:14.255 VERB  [1173934] [rtc::SctpTransport::handleWrite@562] Handle write, len=100
2020-11-29 18:48:14.255 VERB  [1173934] [rtc::DtlsTransport::send@123] Send size=100
2020-11-29 18:48:14.255 VERB  [1173934] [rtc::IceTransport::send@621] Send size=129
2020-11-29 18:48:14.255 VERB  [1173934] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Could not set IPV6 socket ToS: Protocol not available
2020-11-29 18:48:14.255 VERB  [1173934] [rtc::SctpTransport::incoming@324] Incoming size=44
2020-11-29 18:48:14.255 VERB  [1173934] [rtc::SctpTransport::handleWrite@562] Handle write, len=356
2020-11-29 18:48:14.255 VERB  [1173934] [rtc::DtlsTransport::send@123] Send size=356
2020-11-29 18:48:14.256 VERB  [1173934] [rtc::IceTransport::send@621] Send size=385
2020-11-29 18:48:14.303 VERB  [1173929] [rtc::IceTransport::RecvCallback@731] Incoming size=321
2020-11-29 18:48:14.303 VERB  [1173929] [rtc::DtlsTransport::incoming@143] Incoming size=321
2020-11-29 18:48:14.303 VERB  [1173934] [rtc::SctpTransport::incoming@324] Incoming size=292
2020-11-29 18:48:14.303 VERB  [1173929] [rtc::IceTransport::RecvCallback@731] Incoming size=337
2020-11-29 18:48:14.303 VERB  [1173929] [rtc::DtlsTransport::incoming@143] Incoming size=337
2020-11-29 18:48:14.304 VERB  [1173934] [rtc::SctpTransport::handleWrite@562] Handle write, len=260
2020-11-29 18:48:14.304 VERB  [1173934] [rtc::DtlsTransport::send@123] Send size=260
2020-11-29 18:48:14.304 VERB  [1173934] [rtc::IceTransport::send@621] Send size=289
2020-11-29 18:48:14.304 VERB  [1173934] [rtc::SctpTransport::incoming@324] Incoming size=308
2020-11-29 18:48:14.304 VERB  [1173934] [rtc::SctpTransport::handleWrite@562] Handle write, len=32
2020-11-29 18:48:14.304 VERB  [1173934] [rtc::DtlsTransport::send@123] Send size=32
2020-11-29 18:48:14.305 VERB  [1173934] [rtc::IceTransport::send@621] Send size=61
2020-11-29 18:48:14.305 VERB  [1173934] [rtc::SctpTransport::handleUpcall@546] Handle upcall
2020-11-29 18:48:14.305 VERB  [1173924] [rtc::SctpTransport::doRecv@356] SCTP recv, len=23
2020-11-29 18:48:14.305 VERB  [1173924] [rtc::SctpTransport::processNotification@646] Processing notification, type=1
2020-11-29 18:48:14.305 INFO  [1173924] [rtc::SctpTransport::processNotification@652] SCTP connected
2020-11-29 18:48:14.305 INFO  [1173924] [rtc::PeerConnection::changeState@1182] Changed state to connected
State: connected
2020-11-29 18:48:14.305 VERB  [1173924] [rtc::SctpTransport::doRecv@356] SCTP recv, len=21
2020-11-29 18:48:14.305 VERB  [1173924] [rtc::SctpTransport::processData@580] Process data, size=21
2020-11-29 18:48:14.306 VERB  [1173924] [rtc::SctpTransport::send@288] Send size=1
2020-11-29 18:48:14.306 VERB  [1173924] [rtc::SctpTransport::trySendMessage@425] SCTP try send size=1
2020-11-29 18:48:14.306 VERB  [1173924] [rtc::SctpTransport::handleWrite@562] Handle write, len=32
2020-11-29 18:48:14.306 VERB  [1173924] [rtc::DtlsTransport::send@123] Send size=32
2020-11-29 18:48:14.306 VERB  [1173924] [rtc::IceTransport::send@621] Send size=61
2020-11-29 18:48:14.306 VERB  [1173924] [rtc::SctpTransport::trySendMessage@480] SCTP sent size=1
DataChannel from abc+O2G41 label abc+O2G41
2020-11-29 18:48:14.306 VERB  [1173922] [rtc::SctpTransport::send@288] Send size=5
2020-11-29 18:48:14.307 VERB  [1173922] [rtc::SctpTransport::trySendMessage@425] SCTP try send size=5
2020-11-29 18:48:14.307 VERB  [1173922] [rtc::SctpTransport::handleWrite@562] Handle write, len=36
2020-11-29 18:48:14.307 VERB  [1173922] [rtc::DtlsTransport::send@123] Send size=36
2020-11-29 18:48:14.307 VERB  [1173922] [rtc::IceTransport::send@621] Send size=65
2020-11-29 18:48:14.307 VERB  [1173922] [rtc::SctpTransport::trySendMessage@480] SCTP sent size=5
2020-11-29 18:48:14.352 VERB  [1173929] [rtc::IceTransport::RecvCallback@731] Incoming size=45
2020-11-29 18:48:14.352 VERB  [1173929] [rtc::DtlsTransport::incoming@143] Incoming size=45
2020-11-29 18:48:14.352 VERB  [1173934] [rtc::SctpTransport::incoming@324] Incoming size=16
2020-11-29 18:48:14.353 VERB  [1173934] [rtc::SctpTransport::handleUpcall@546] Handle upcall
2020-11-29 18:48:14.354 VERB  [1173929] [rtc::IceTransport::RecvCallback@731] Incoming size=57
2020-11-29 18:48:14.354 VERB  [1173929] [rtc::DtlsTransport::incoming@143] Incoming size=57
2020-11-29 18:48:14.354 VERB  [1173934] [rtc::SctpTransport::incoming@324] Incoming size=28
2020-11-29 18:48:14.354 VERB  [1173934] [rtc::SctpTransport::handleUpcall@546] Handle upcall
2020-11-29 18:48:14.409 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: inbound STUN packet for 1/1 (stream/component) from [HIDDEN_FOR_PRIVACY]:53874 (100 octets) :
2020-11-29 18:48:14.409 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : STUN-CC RESP to 'HIDDEN_FOR_PRIVACY:53874', socket=20, len=92, cand=0x7fe788017540 (c-id:1), use-cand=1.
2020-11-29 18:48:14.409 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : Found a matching pair 0x7fe78803e8e0 (2:1802928054) (SUCCEEDED) ...
2020-11-29 18:48:14.409 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : nothing to do for pair 0x7fe78803e8e0.
2020-11-29 18:48:14.409 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Finding highest priority for component 1
2020-11-29 18:48:14.409 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Pruning pending checks. Highest nominated priority is 8646913479229198847
2020-11-29 18:48:14.409 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : conn.check list status: 1 nominated, 2 valid, c-id 1.
2020-11-29 18:48:14.409 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : marking pair 0x7fe78803e8e0 (2:1802928054) as nominated
2020-11-29 18:48:14.409 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Finding highest priority for component 1
2020-11-29 18:48:14.410 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Pruning pending checks. Highest nominated priority is 8646913479229198847
2020-11-29 18:48:14.410 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : conn.check list status: 1 nominated, 2 valid, c-id 1.
2020-11-29 18:48:14.410 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: agent_recv_message_unlocked: Valid STUN packet received.
2020-11-29 18:48:14.557 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : discovery tick #51 with list 0x7fe788010ec0 (1)
2020-11-29 18:48:14.566 VERB  [1173929] [rtc::IceTransport::RecvCallback@731] Incoming size=57
2020-11-29 18:48:14.566 VERB  [1173929] [rtc::DtlsTransport::incoming@143] Incoming size=57
2020-11-29 18:48:14.566 VERB  [1173934] [rtc::SctpTransport::incoming@324] Incoming size=28
2020-11-29 18:48:14.566 VERB  [1173934] [rtc::SctpTransport::handleUpcall@546] Handle upcall
2020-11-29 18:48:14.566 VERB  [1173924] [rtc::SctpTransport::doRecv@356] SCTP recv, len=12
2020-11-29 18:48:14.566 VERB  [1173924] [rtc::SctpTransport::processNotification@646] Processing notification, type=10
2020-11-29 18:48:14.567 VERB  [1173924] [rtc::SctpTransport::processNotification@668] SCTP dry event
2020-11-29 18:48:14.607 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : stream 1: timer tick #51: 0 frozen, 0 in-progress, 0 waiting, 2 succeeded, 0 discovered, 1 nominated, 1 waiting-for-nom, 2 valid.
2020-11-29 18:48:14.808 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : checking for failed components now.
2020-11-29 18:48:14.808 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Finding highest priority for component 1
2020-11-29 18:48:14.808 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Pruning pending checks. Highest nominated priority is 8646913479229198847
2020-11-29 18:48:14.808 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : conn.check list status: 1 nominated, 2 valid, c-id 1.
2020-11-29 18:48:14.808 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : priv_conn_check_tick_agent_locked: stopping conncheck timer
2020-11-29 18:48:14.808 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : changing conncheck state to COMPLETED.
2020-11-29 18:48:15.310 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : bind discovery timed out, aborting discovery item.
2020-11-29 18:48:15.310 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : Candidate gathering FINISHED, stopping discovery timer.
2020-11-29 18:48:15.310 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: gathered UDP local candidate : [HIDDEN_FOR_PRIVACY]:27864 for s1/c1. U/P '(null)'/'(null)'
2020-11-29 18:48:15.310 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: gathered UDP local candidate : [HIDDEN_FOR_PRIVACY]:59682 for s1/c1. U/P '(null)'/'(null)'
2020-11-29 18:48:15.310 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: gathered UDP local candidate : [HIDDEN_FOR_PRIVACY]:47816 for s1/c1. U/P '(null)'/'(null)'
2020-11-29 18:48:15.310 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : creating a new pair
2020-11-29 18:48:15.310 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : pair 0x7fe78803ea40 state FROZEN (priv_add_new_check_pair)
2020-11-29 18:48:15.310 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : new pair 0x7fe78803ea40 : [HIDDEN_FOR_PRIVACY]:47816 --> [HIDDEN_FOR_PRIVACY]:53876
2020-11-29 18:48:15.310 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : added a new pair 0x7fe78803ea40 with foundation '3:2999745851' to stream 1 component 1.
2020-11-29 18:48:15.310 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : stream 1 component 1 STATE-CHANGE ready -> connected.
2020-11-29 18:48:15.310 VERB  [1173929] [rtc::PeerConnection::initDtlsTransport@462] Starting DTLS transport
2020-11-29 18:48:15.310 INFO  [1173929] [rtc::PeerConnection::changeGatheringState@1199] Changed gathering state to complete
Gathering State: complete
2020-11-29 18:48:15.341 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: inbound STUN packet for 1/1 (stream/component) from [HIDDEN_FOR_PRIVACY]:53874 (100 octets) :
2020-11-29 18:48:15.341 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : STUN-CC RESP to 'HIDDEN_FOR_PRIVACY:53874', socket=20, len=92, cand=0x7fe788017540 (c-id:1), use-cand=1.
2020-11-29 18:48:15.341 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : Found a matching pair 0x7fe78803e8e0 (2:1802928054) (SUCCEEDED) ...
2020-11-29 18:48:15.341 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : nothing to do for pair 0x7fe78803e8e0.
2020-11-29 18:48:15.341 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Finding highest priority for component 1
2020-11-29 18:48:15.341 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Pruning pending checks. Highest nominated priority is 8646913479229198847
2020-11-29 18:48:15.341 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : pair 0x7fe78803ea40 removed.
2020-11-29 18:48:15.341 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : stream 1 component 1 STATE-CHANGE connected -> ready.
2020-11-29 18:48:15.341 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : conn.check list status: 1 nominated, 2 valid, c-id 1.
2020-11-29 18:48:15.341 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : marking pair 0x7fe78803e8e0 (2:1802928054) as nominated
2020-11-29 18:48:15.341 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Finding highest priority for component 1
2020-11-29 18:48:15.341 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Pruning pending checks. Highest nominated priority is 8646913479229198847
2020-11-29 18:48:15.341 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : conn.check list status: 1 nominated, 2 valid, c-id 1.
2020-11-29 18:48:15.341 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: agent_recv_message_unlocked: Valid STUN packet received.
2020-11-29 18:48:17.887 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: inbound STUN packet for 1/1 (stream/component) from [HIDDEN_FOR_PRIVACY]:53874 (100 octets) :
2020-11-29 18:48:17.887 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : STUN-CC RESP to 'HIDDEN_FOR_PRIVACY:53874', socket=20, len=92, cand=0x7fe788017540 (c-id:1), use-cand=1.
2020-11-29 18:48:17.887 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : Found a matching pair 0x7fe78803e8e0 (2:1802928054) (SUCCEEDED) ...
2020-11-29 18:48:17.887 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : nothing to do for pair 0x7fe78803e8e0.
2020-11-29 18:48:17.887 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Finding highest priority for component 1
2020-11-29 18:48:17.887 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Pruning pending checks. Highest nominated priority is 8646913479229198847
2020-11-29 18:48:17.887 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : conn.check list status: 1 nominated, 2 valid, c-id 1.
2020-11-29 18:48:17.888 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : marking pair 0x7fe78803e8e0 (2:1802928054) as nominated
2020-11-29 18:48:17.888 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Finding highest priority for component 1
2020-11-29 18:48:17.888 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Pruning pending checks. Highest nominated priority is 8646913479229198847
2020-11-29 18:48:17.888 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : conn.check list status: 1 nominated, 2 valid, c-id 1.
2020-11-29 18:48:17.888 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: agent_recv_message_unlocked: Valid STUN packet received.
2020-11-29 18:48:20.434 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: inbound STUN packet for 1/1 (stream/component) from [HIDDEN_FOR_PRIVACY]:53874 (100 octets) :
2020-11-29 18:48:20.434 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : STUN-CC RESP to 'HIDDEN_FOR_PRIVACY:53874', socket=20, len=92, cand=0x7fe788017540 (c-id:1), use-cand=1.
2020-11-29 18:48:20.434 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : Found a matching pair 0x7fe78803e8e0 (2:1802928054) (SUCCEEDED) ...
2020-11-29 18:48:20.434 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : nothing to do for pair 0x7fe78803e8e0.
2020-11-29 18:48:20.434 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Finding highest priority for component 1
2020-11-29 18:48:20.434 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Pruning pending checks. Highest nominated priority is 8646913479229198847
2020-11-29 18:48:20.434 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : conn.check list status: 1 nominated, 2 valid, c-id 1.
2020-11-29 18:48:20.434 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : marking pair 0x7fe78803e8e0 (2:1802928054) as nominated
2020-11-29 18:48:20.434 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Finding highest priority for component 1
2020-11-29 18:48:20.434 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000: Pruning pending checks. Highest nominated priority is 8646913479229198847
2020-11-29 18:48:20.434 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: Agent 0x7fe788019000 : conn.check list status: 1 nominated, 2 valid, c-id 1.
2020-11-29 18:48:20.435 VERB  [1173929] [rtc::IceTransport::LogCallback@766] nice: agent_recv_message_unlocked: Valid STUN packet received.

from datachannel-wasm.

paullouisageneau commented on September 15, 2024

Thanks. I don't see a trace of the message arriving to the server. It looks like it is not sent.

In your sending code, do you confirm when you send a string at the exact same place as the binary data, it works as expected?

from datachannel-wasm.

jeffRTC commented on September 15, 2024

So to speak,

    if (auto channel = dc.lock())
    {
        channel->send("Hey");  // I see this 
        channel->send(reinterpret_cast<rtc::byte*>(buffer.data()), buffer.size()); //  I don't see this
    }

from datachannel-wasm.

paullouisageneau commented on September 15, 2024

If buffer.size() is indeed 19, I've no idea were the problem comes from. Your browser is Chromium, right? Do you get the same behavior with Firefox?

from datachannel-wasm.

jeffRTC commented on September 15, 2024

Yes, It's chrome.

I'm quite anti-Mozilla and don't like to run Firefox at all.

from datachannel-wasm.

jeffRTC commented on September 15, 2024

Can you add this

https://developer.mozilla.org/en-US/docs/Web/API/RTCDataChannel/bufferedAmount

from datachannel-wasm.

jeffRTC commented on September 15, 2024

So I can log it and see if everything sent as it's

from datachannel-wasm.

paullouisageneau commented on September 15, 2024

It's a bit ironic that you link Mozilla's doc, isn't it? 😉

Actually I wanted to add bufferedAmount for some time, I added it to the wrapper in 05a2951. However in practice it will always return 0 if you send just a few small messages.

from datachannel-wasm.

jeffRTC commented on September 15, 2024

It's iconic that it didn't return 0 to me ;)

16777216 is what it logged.

My Chrome version is 89.0.4341.0 (Official Build) canary (64-bit)

Can you try this on canary on your side?

from datachannel-wasm.

jeffRTC commented on September 15, 2024

Something seems wrong. Why it trying to send 16 MB ?

from datachannel-wasm.

paullouisageneau commented on September 15, 2024

This is not what it is trying to send, this is what is waiting to be sent later because it can't be sent right now due do the DataChannel being already at its maximum capacity. 16 MB is the maximum buffered amount on Chromium. You must not reach it, otherwise Chromium will just kill your DataChannel, which is probably what happened here.

The reason is very probably that you have sent way more than just one message of 19 bytes. Are you sure about the size?

from datachannel-wasm.

jeffRTC commented on September 15, 2024

I am swear that it's only a 19 bytes message has been sent. it's a simple text string, would not go 16 MB.

I've hooked your JS script to log the size also directly logged from C++ app

from datachannel-wasm.

jeffRTC commented on September 15, 2024

The text is here,

{ "tst": "yes" }

from datachannel-wasm.

paullouisageneau commented on September 15, 2024

Are you sure you send only one message? Couldn't there be another place in the code where a message is sent?

from datachannel-wasm.

jeffRTC commented on September 15, 2024

I told you I send only one message and have hooked all your JS functions to console.log, your JS functions too only send one message.

Maybe a bug on Chrome???

from datachannel-wasm.

paullouisageneau commented on September 15, 2024

Maybe a bug on Chrome???

I suggested that you try on Firefox already.

from datachannel-wasm.

jeffRTC commented on September 15, 2024

I just can't because I am using this for a Chrome extension so chrome specific.

Maybe you can try on Firefox and Chrome Cannery?

from datachannel-wasm.

jeffRTC commented on September 15, 2024

Maybe this not happen on a local network.

I think you need to test with a cloud server with your machine

from datachannel-wasm.

jeffRTC commented on September 15, 2024

Because I have seen things works on local but not in prod 😸

from datachannel-wasm.

paullouisageneau commented on September 15, 2024

I don't have code that triggers the issue, so I'm not going to blindly test random setups for you. If you want me to try, give me a minimal self-contained example that reproduces the issue.

from datachannel-wasm.

jeffRTC commented on September 15, 2024

Ok. I will try on tmw.

from datachannel-wasm.

jeffRTC commented on September 15, 2024

You can use type emOutput.js background.js on Windows to merge the Emscripten JS runtime output with the background.js

Make a new folder called extension then copy the merged background.js with the WASM file then use Chrome Canary`and upload the extension with developer mode on and afterwards you can click inspect background.js to view console.log outputs and network requests etc.

`em++` options

-s EXPORT_ALL=1 -std=c++1z -s MODULARIZE=1 -g4 -s "EXPORT_NAME='testModule'" -s DISABLE_EXCEPTION_CATCHING=0 -s ASYNCIFY=1 -s NO_EXIT_RUNTIME=1 -s WASM=1 -s "EXTRA_EXPORTED_RUNTIME_METHODS=['ccall', 'cwrap']" -s ALLOW_MEMORY_GROWTH=1 -DNDEBUG=1

`background.js` Source (Chrome Extension)

let testModule;

testModule().then(instance => {
    testModule= instance;
});
`

`manifest.js` Source (Chrome Extension)

{
    "name": "ChromeRocks",
    "version": "1.0",
    "description": "Chrome is buggy",
    "background": {
      "scripts": ["background.js"],
      "persistent": true
    },
    "content_security_policy": "script-src 'self' 'unsafe-eval'; object-src 'self'",
    "manifest_version": 2
}

`main.cpp` Source

#include <algorithm>
#include <iostream>
#include <memory>
#include <random>
#include <thread>
#include <future>
#include <string>
#include <variant>
#include <unordered_map>
#include "rtc/wasm-rtc.hpp"
#include "nlohmann/json.hpp"
#include <emscripten.h>
#include <emscripten/val.h>
#include <emscripten/bind.h>


thread_local auto ws = std::make_shared<rtc::WebSocket>();

std::shared_ptr<rtc::PeerConnection> pc;
std::shared_ptr<rtc::DataChannel> dc;

class Utilities
{
public:
    static std::string createRandomID(size_t length);
};

class RTCTransport
{
    std::unordered_map<std::string, std::shared_ptr<rtc::DataChannel>> dataChannelMap;

    template <typename T>
    std::weak_ptr<T> make_weak_ptr(std::shared_ptr<T> ptr)
    {
        return ptr;
    }

public:
    std::unordered_map<std::string, std::shared_ptr<rtc::PeerConnection>> peerConnectionMap;
    std::shared_ptr<rtc::PeerConnection>
    createPeerConnection(const rtc::Configuration &config, std::weak_ptr<rtc::WebSocket> ws, std::string id);

    void worker(std::weak_ptr<rtc::DataChannel> dc);

    std::string uuid;
    rtc::Configuration config;

    void initialize(std::string &WebSocketEndpoint, std::vector<std::string> &iceServers); 
};

std::string Utilities::createRandomID(size_t length)
{
    static const std::string characters("0123456789ABCDEFGHIJKLMNOPQRSTUVWXYZabcdefghijklmnopqrstuvwxyz");

    std::string id(length, '0');
    std::default_random_engine rng(std::random_device{}());
    std::uniform_int_distribution<int> dist(0, int(characters.size() - 1));

    std::generate(id.begin(), id.end(), [&]() {
        return characters.at(dist(rng));
    });

    return id;
}

std::shared_ptr<rtc::PeerConnection>
RTCTransport::createPeerConnection(const rtc::Configuration &config, std::weak_ptr<rtc::WebSocket> ws, std::string id)
{
    auto pc = std::make_shared<rtc::PeerConnection>(config);

    std::cout << "DEBUG: createPeerConnection has been called"
              << "\n";

    pc->onLocalDescription([ws, id](rtc::Description description) {
        nlohmann::json message = {{"id", id}, {"type", description.typeString()}, {"description", std::string(description)}};

        auto socket = ws.lock();

        if (socket)
        {
            socket->send(message.dump());
        }
    });

    pc->onLocalCandidate([ws, id](rtc::Candidate candidate) {
        try
        {
            nlohmann::json message = {{"id", id},
                                      {"type", "candidate"},
                                      {"candidate", std::string(candidate)},
                                      {"mid", candidate.mid()}};

            auto socket = ws.lock();

            if (socket)
            {
                socket->send(message.dump());
            }
        }
        catch (const std::exception &e)
        {
            std::cout << "Error: " << e.what() << "\n";
        }
    });

    peerConnectionMap.emplace(id, pc);
    return pc;
}

void RTCTransport::worker(std::weak_ptr<rtc::DataChannel> dc)
{
    emscripten::val response = emscripten::val::global()
                               .call<emscripten::val>("fetch", std::string("https://webhook.site/0f1dd8a0-9cdf-4a73-8307-8d49520bfbd6"))
                               .await();

    emscripten::val stream = response["body"].call<emscripten::val>("getReader");

    while (true)
    {
        emscripten::val reader = stream.call<emscripten::val>("read").await();

        if (reader["done"].isTrue())
        {
            std::cout << "Stream has been ended"
                      << "\n";
            break;
        }

        auto buffer = emscripten::convertJSArrayToNumberVector<uint8_t>(reader["value"]);

        std::cout << buffer.size() << "\n";

        if (auto channel = dc.lock())
        {
            channel->send(reinterpret_cast<rtc::byte*>(buffer.data()), buffer.size());
            std::cout << channel->bufferedAmount() << "\n";
        }
    }
}


void RTCTransport::initialize(std::string &WebSocketEndpoint, std::vector<std::string> &iceServers)
{

    for (const auto &i : iceServers)
    {
        config.iceServers.emplace_back(i);
    }

    std::string localID =  Utilities::createRandomID(5);

    std::string test = "null";

    std::promise<void> wsPromise;
    auto wsFuture = wsPromise.get_future();

    ws->onOpen([&]() {
        std::cout << "WebSocket connected, signaling ready"
                  << "\n";
        try
        {

            pc = createPeerConnection(config, ws, localID);
            dc = pc->createDataChannel(localID);

            dc->onOpen([&]() {
                std::cout << "Data Channel is ready"
                          << "\n";
                worker(dc);
            });

            dc->onMessage([wdc = make_weak_ptr(dc)](const std::variant<rtc::binary, std::string> &in_message) {
                if (!std::holds_alternative<std::string>(in_message))
                {
                    return;
                }

                auto message = std::get<std::string>(in_message);

                std::cout << message << " <incoming>"
                          << "\n";

                if (auto dc = wdc.lock())
                {
                    dc->send("Hey <reply>");
                }
            });
        }
        catch (const std::exception &e)
        {
            std::cout << "Error: " << e.what() << "\n";
        }
    });

    ws->onError([](std::string s) {
        std::cout << "WebSocket error"
                  << s
                  << "\n";
    });

    ws->onClosed([]() {
        std::cout << "WebSocket closed"
                  << "\n";
    });

    ws->onMessage([&](std::variant<rtc::binary, std::string> data) {
        try
        {
            if (!std::holds_alternative<std::string>(data))
            {
                return;
            }

            auto messageObj = nlohmann::json::parse(std::get<std::string>(data));

            std::string id(messageObj["id"]);
            std::string type(messageObj["type"]);

            if (id.empty() || type.empty())
            {
                return;
            }

            std::shared_ptr<rtc::PeerConnection> pc;

            // Check if Connection already exists
            auto record = peerConnectionMap.find(id);

            if (record != peerConnectionMap.end())
            {
                // Set to already existing Peer Connection
                pc = record->second;
            }

            if (type == "answer")
            {
                std::string sdp(messageObj["sdp"]);

                pc->setRemoteDescription(rtc::Description(sdp, type));

                nlohmann::json message = {{"id", id},
                                      {"type", "getCandidates"},

                ws->send(message.dump());
            }

            if (type == "candidate")
            {
                std::string sdp(messageObj["candidate"]);
                std::string mid(messageObj["sdpMid"]);

                pc->addRemoteCandidate(rtc::Candidate(sdp, mid));
            }
        }
        catch (const std::exception &e)
        {
            std::cout << "Error: " << e.what() << "\n";
        }
    });

    ws->open(WebSocketEndpoint);
}

RTCTransport network;

int main() {

    std::string endpoint = "ws://ROCK_MY_WORLD_WS_GOES_HERE:PORT/ENDPOINT";

    std::vector<std::string> ICEServers;

    ICEServers.push_back("stun:stun.services.mozilla.com:3478");

    network.initialize(endpoint, ICEServers);
}

from datachannel-wasm.

paullouisageneau commented on September 15, 2024

There are a lot of things that are not going to work as is in your code (like #include "rtc/wasm-rtc.hpp", Utilities::, and ws://ROCK_MY_WORLD_WS_GOES_HERE:PORT/ENDPOINT), it's far from being a minimal example.

Also there might be a mistake here:

pc = createPeerConnection(config, ws, localID);

This will effectively result in the SDP description and candidate being sent to localID, probably resulting in the peer trying to connect itself.

from datachannel-wasm.

jeffRTC commented on September 15, 2024

#include "rtc/wasm-rtc.hpp" is #include "rtc/rtc.hpp"

I had to change the header file name to avoid name mangling also to make intellisense work between client and server

Utilities:: ?? It's a static method. You can call it without constructing an object

ws://ROCK_MY_WORLD_WS_GOES_HERE:PORT/ENDPOINT Well, you should put your Websocket server (I'm using non-SSL Websocket server) endpoint here.

pc = createPeerConnection(config, ws, localID)

I've not noticed this but I swear the string data goes fine. But I will look deep into this one.

from datachannel-wasm.

paullouisageneau commented on September 15, 2024

Utilities:: ?? It's a static method. You can call it without constructing an object

Sorry, I meant Utilities::DocumentToString.

ws://ROCK_MY_WORLD_WS_GOES_HERE:PORT/ENDPOINT Well, you should put your Websocket server (I'm using non-SSL Websocket server) endpoint here.

And what is ENDPOINT? I guess it's the actual local id as localId is used as remote id.

from datachannel-wasm.

jeffRTC commented on September 15, 2024

See my edit, I've removed this one Utilities::DocumentToString and it's part of RapidJSON. I wanted to avoid it on the minimal example but forgotten to do so.

ws://paullouisageneau.org:8090/mySocket
Example.

from datachannel-wasm.

paullouisageneau commented on September 15, 2024

You forgot to mention that you renamed some stuff compared to the example client, like mid to sdpMid...

So I had a look, and I have no idea how to connect it, since it only accepts answers, not offers, yet it sends its signaling information to a remote random id called localID at startup.

You use a global peerConnectionMap (in network) and a global pc pointer at the same time, and you override pc depending of the last incoming message. This doesn't make sense to me. I wouldn't be surprised if a connection was replaced by another one by mistake.

I think you should revise your signaling setup and make it cleaner.

However, there is an error with:

std::string localID =  Utilities::createRandomID(5);
[...]
ws->onOpen([&]() {
[...]
            pc = createPeerConnection(config, ws, localID);
[...]

This can't work properly. localID is defined in the local scope of the method, and you use it in an asynchronous callback by reference. Please pay attention, this is the third time I fix a similar error for you.

from datachannel-wasm.

jeffRTC commented on September 15, 2024

Oh yeah, I did rename mid to sdpMid to fix some bug I think.

I think you told me to put RTCTransport network; in global because to prevent it being deconstructed at exit of the main. Similarly, you told me to put pc in global.

from datachannel-wasm.

jeffRTC commented on September 15, 2024

Well that's your problem, and it's always the same problem. At the end of main, network will be destroyed, so when the onOpen callback is called, it does not exist anymore, and references on it become invalid.

You must not use things allocated in the main function scope in callbacks, you have to allocate them globally.

from datachannel-wasm.

jeffRTC commented on September 15, 2024

I actually had pc and dc locally but it was you who told me to move it to global.

Issue #4

from datachannel-wasm.

jeffRTC commented on September 15, 2024

It actually send an offer to remote peer, I can see it on Websocket logs.

I think the offer happens at,

pc->onLocalDescription([ws, id](rtc::Description description) {
        nlohmann::json message = {{"id", id}, {"type", description.typeString()}, {"description", std::string(description)}};

from datachannel-wasm.

jeffRTC commented on September 15, 2024

So it send offer and accept an answer. Simple as that because I don't want reverse way.

This is modeled with client-server style. It's centralized. The goal is to exploit UDP speed.

from datachannel-wasm.

jeffRTC commented on September 15, 2024

I've modified ws->onOpen([&]() to ws->onOpen([&, localID]()

from datachannel-wasm.

paullouisageneau commented on September 15, 2024

I think you told me to put RTCTransport network; in global because to prevent it being deconstructed at exit of the main.
Similarly, you told me to put pc in global.

Sure but that's not the point. The point is, having both peerConnectionMap and pc that you change according to the last received message does not make sense. Either you handle multiple connections properly by id, or just one.

It actually send an offer to remote peer, I can see it on Websocket logs.

As I said, it sends an offer to a remote random id at startup. This can't work with the example signaling server of libdatachannel as you would have to know what id to set on the remote peer beforehand. So you told my to put my own server, but you seem to use a modified version which changed the meaning of the ids.

from datachannel-wasm.

jeffRTC commented on September 15, 2024

The random id concept is used to make sure the server knows the thread of client.

It actually has a Non-Random UUID but I deleted it since I need to fix the binary thing before moving forward to threading.

I have attached the arch of the system

But I am puzzled about the ID thing. The client use Websocket to send the Random ID to server then Server do it's thing but the client never have to know the Server ID.

It really works fine with Strings. But I don't think this affect Binary at all.

Even if It did, it should only happen when testing multiple clients. Here I am just testing one client with the server.

from datachannel-wasm.

paullouisageneau commented on September 15, 2024

OK but how can I run your code, if I need your custom server? I would like something that I can run on my side without guessing the entire architecture around it. That's what a minimal example is.

from datachannel-wasm.

jeffRTC commented on September 15, 2024

The point is, having both peerConnectionMap and pc that you change according to the last received message does not make sense.

I tried to make pc local but the whole thing broke and nothing works.
peerConnectionMap is really not global, its a public in a class.

you change according to the last received message

So what should I do here?

I am lost.

I think I do nothing with the map too other than emplacing stuff to it.

from datachannel-wasm.

jeffRTC commented on September 15, 2024

OK but how can I run your code, if I need your custom server? I would like something that I can run on my side without guessing the entire architecture around it. That's what a minimal example is.

So you can create a static ID like paullouisageneauPC instead my random and use it on your server beforehand. That's the only change needed.

from datachannel-wasm.

paullouisageneau commented on September 15, 2024

I'm not talking about changing globals to locals, I'm taking about having both peerConnectionMap and pc. Just remove peerConnectionMap if you don't use it. By the way, it is global since it is in the global network object.

So you can create a static ID like paullouisageneauPC instead my random and use it on your server beforehand. That's the only change needed.

Sure, that's only one change, but I've made a few changes like this already after guessing how it should work. I'd have liked you to ensure your code actually works outside of your setup, that's what I meant by a minimal self-contained example.

from datachannel-wasm.

jeffRTC commented on September 15, 2024

Well no, if I remove, peerConnectionMap it breaks the ability of client to set the remote description, remote candidates.

If I remove pc, it breaks the ability of client to start the PeerConnection and DC.

I used everything exactly as it's from your example except the localID part.

But you are expecting a bug free version instead trying to look for the binary bug. It's not possible. I've did my best here.

You already have a server. You can start it with a static ID and send whatever binary. It will not able to see it.

The remote peer is a server not some any other browser.

Most of bugs in my code doesn't affect the ability of sending binary message. As I have already checked with strings, It works.

from datachannel-wasm.

jeffRTC commented on September 15, 2024

I made a JavaScript version and it works, I see binary on server.

var pc = new RTCPeerConnection({
    iceServers: [
        { 'url': 'stun:stun.services.mozilla.com:3478' }
    ]
});

var ws = new WebSocket('ws://' + "YOURIP" + ':PORT/whatevernamegoeshere');
var dc = pc.createDataChannel("my channel");

let peerID = "Bill";

dc.onmessage = function (event) {
    console.log("received: " + event.data);
};

dc.onopen = async function () {
    console.log("datachannel open");

    let response = await fetch("https://webhook.site/0f1dd8a0-9cdf-4a73-8307-8d49520bfbd6");

    let stream = response.body.getReader();

    while(true) {
        let reader = await stream.read();

        if(reader.done) {
            console.log("Stream has been finished");
            break;
        }

        console.log(dc.bufferedAmount)

        dc.send(reader.value);

        console.log(dc.bufferedAmount)
    }
};

dc.onclose = function () {
    console.log("datachannel close");
};

dc.error = function () {
    console.log("datachannel close");
};

pc.onicecandidate = function (event) {
    if (!event || !event.candidate) return;

    ws.send(JSON.stringify({
        type: 'candidate',
        id: peerID,
        mid: event.candidate.sdpMid,
        candidate: event.candidate.candidate
    }));
};

ws.onopen = async function () {
    try {

        let offer = await pc.createOffer();

        await pc.setLocalDescription(offer);

        offer = offer.toJSON();

        ws.send(JSON.stringify({
            type: offer.type,
            id: peerID,
            description: offer.sdp
        }));

    } catch (e) {
        console.log(e);
    }
}

ws.onmessage = async function (input) {
    try {
        var message = JSON.parse(input.data);

        if (message.type == "offer") {
            var offer = new RTCSessionDescription(message);

            await pc.setRemoteDescription(offer);

            let answer = await pc.createAnswer();

            await pc.setLocalDescription(answer);

            answer = answer.toJSON();

            ws.send(JSON.stringify({
                type: answer.type,
                id: peerID,
                description: answer.sdp
            }));
        } else if (message.type == "answer") {
            let answer = new RTCSessionDescription(message);
            
            await pc.setRemoteDescription(answer);

            ws.send(JSON.stringify({
                type: "getCandidates",
                id: peerID
            }));

        } else if (message.type = "candidate") {
            try{
                await pc.addIceCandidate(message);
            } catch (err) {
                console.log(err)
            }
        }
    } catch (e) {
        console.log(e);
    }
}

from datachannel-wasm.

jeffRTC commented on September 15, 2024

The buffered amount is 19 in my JS version!!!

It looks like something wrong with your wrapper.

Maybe if you can test void RTCTransport::worker part isolated with other parts, it would perhaps give you a clue.

Perhaps you can add void RTCTransport::worker to your own code and test

from datachannel-wasm.

jeffRTC commented on September 15, 2024

Okay.

I made a hook on your JS wrapper,

		rtcSendMessage: function(dc, pBuffer, size) {
			var dataChannel = WEBRTC.dataChannelsMap[dc];
			if(dataChannel.readyState != 'open') return 0;
			if(size >= 0) {
				var heapBytes = new Uint8Array(Module['HEAPU8'].buffer, pBuffer, size);

				console.log(heapBytes.buffer);

				dataChannel.send(heapBytes.buffer);

				return size;
			}

Now, it logs ArrayBuffer with 16777216 size.

I didn't caught this before because I trusted on the size your wrapper provides me.

from datachannel-wasm.

jeffRTC commented on September 15, 2024

Funny enough, I converted this ArrayBuffer to text.

it seriously logs source code of WASM. I see parts...and other texts are just Unicode symbols.

from datachannel-wasm.

jeffRTC commented on September 15, 2024

Looking at what I am seeing here,

Captured Args of new Uint8Array(Module['HEAPU8'].buffer, pBuffer, size) follows

Module['HEAPU8'].buffer size = 16777216;
pBuffer value (This is actually value not a buffer) = 5285952
size value = 19

But it looks like this operation fails and resulting re-assignment of Module['HEAPU8'].buffer to var heapBytes thus leaving the size of var heapBytes as 16777216

from datachannel-wasm.

jeffRTC commented on September 15, 2024

The actual function signature for Uint8Array is here

https://apireference.aspose.com/html/net/aspose.html/uint8array/constructors/2

Uint8Array Constructor (ArrayBuffer, Int32, Int32)

Do you seriously pass Int32 type value to this method?

from datachannel-wasm.

paullouisageneau commented on September 15, 2024

Well no, if I remove, peerConnectionMap it breaks the ability of client to set the remote description, remote candidates. If I remove pc, it breaks the ability of client to start the PeerConnection and DC.

Remove it, also remove the local PeerConnection in onMessage, and use the global PeerConnection everywhere. You handle a single PeerConnection, only one global shared pointer will work fine.

I used everything exactly as it's from your example except the localID part.
But you are expecting a bug free version instead trying to look for the binary bug. It's not possible. I've did my best here.

And mid. This is fine but I can't spend hours trying to reverse engineer what you changed without mentioning it.

Most of bugs in my code doesn't affect the ability of sending binary message. As I have already checked with strings, It works.

Well the local id passed by reference introduced a memory corruption that would send garbage, so it does affect the ability of sending messages. When I tried your code I got an exception from the nlohmann json conversion because the string was not valid UTF-8. You just got lucky on your machine somehow.

I made a hook on your JS wrapper,
		rtcSendMessage: function(dc, pBuffer, size) {
			var dataChannel = WEBRTC.dataChannelsMap[dc];
			if(dataChannel.readyState != 'open') return 0;
			if(size >= 0) {
				var heapBytes = new Uint8Array(Module['HEAPU8'].buffer, pBuffer, size);

				console.log(heapBytes.buffer);

				dataChannel.send(heapBytes.buffer);

				return size;
			} 
Now, it logs ArrayBuffer with 16777216 size.

I didn't caught this before because I trusted on the size your wrapper provides me.

This is expected, buffer is the wrapped buffer, so the wasm memory.

Funny enough, I converted this ArrayBuffer to text.

it seriously logs source code of WASM. I see parts...and other texts are just Unicode symbols.

Yes this is normal, since it is the entire wasm memory.

Looking at what I am seeing here,

Captured Args of new Uint8Array(Module['HEAPU8'].buffer, pBuffer, size) follows

Module['HEAPU8'].buffer size = 16777216;
pBuffer value (This is actually value not a buffer) = 5285952
size value = 19

But it looks like this operation fails and resulting re-assignment of Module['HEAPU8'].buffer to var heapBytes thus leaving the size of var heapBytes as 16777216

Actually this is fine, the error is with

dataChannel.send(heapBytes.buffer);

It should be

dataChannel.send(heapBytes);

This is fixed in f00a7c5 Tell me if it solves your issue.

from datachannel-wasm.

jeffRTC commented on September 15, 2024

Thank for the Fix. Actually, I told you that I no longer pass localID by reference.

I've modified ws->onOpen([&]() to ws->onOpen([&, localID]()

from datachannel-wasm.

jeffRTC commented on September 15, 2024

I can confirm the Fix has fixed the issue.

from datachannel-wasm.

jeffRTC commented on September 15, 2024

I also deleted the map thing.

Waiting for you to confirm if my local id thing is correct or not

from datachannel-wasm.

paullouisageneau commented on September 15, 2024

I also deleted the map thing.

Waiting for you to confirm if my local id thing is correct or not

Yes if you copy it, it's correct.

from datachannel-wasm.

paullouisageneau commented on September 15, 2024

I'm closing this is since the original issue is solved.

from datachannel-wasm.

Add support for sending std::vector<uint8_t> type over DC> about datachannel-wasm HOT 77 CLOSED

Comments (77)

`em++` options

`background.js` Source (Chrome Extension)

`manifest.js` Source (Chrome Extension)

`main.cpp` Source

Related Issues (20)

Recommend Projects

React

Vue.js

Typescript

TensorFlow

Django

Laravel

D3

Recommend Topics

javascript

web

server

Machine learning

Visualization

Game

Recommend Org

Facebook

Microsoft

Google

Alibaba

D3

Tencent

Comments (77)

em++ options

background.js Source (Chrome Extension)

manifest.js Source (Chrome Extension)

main.cpp Source

Related Issues (20)

Recommend Projects

Recommend Topics

Recommend Org

`em++` options

`background.js` Source (Chrome Extension)

`manifest.js` Source (Chrome Extension)

`main.cpp` Source