JVB crashes when switching to E2EE mode

Hi there,
Sorry to bother.
About a month ago we updated our jitsi installation with the latest version at that time. Recently, I am seeing this error from the JVB log as it crashed the system:

2020-08-27 21:51:51.356 SEVERE: [39] XmppCommon.handleIQRequest#251: Exception handling IQ request
java.lang.NullPointerException
        at org.jitsi.videobridge.shim.ChannelShim.<init>(ChannelShim.java:163)
        at org.jitsi.videobridge.shim.ContentShim.createRtpChannel(ContentShim.java:135)
        at org.jitsi.videobridge.shim.ContentShim.getOrCreateChannelShim(ContentShim.java:276)
        at org.jitsi.videobridge.shim.VideobridgeShim.processChannels(VideobridgeShim.java:144)
        at org.jitsi.videobridge.shim.VideobridgeShim.handleColibriConferenceIQ(VideobridgeShim.java:336)
        at org.jitsi.videobridge.Videobridge.handleColibriConferenceIQ(Videobridge.java:424)
        at org.jitsi.videobridge.xmpp.XmppCommon.handleIQRequest(XmppCommon.java:228)
        at org.jitsi.videobridge.xmpp.XmppCommon.handleIQInternal(XmppCommon.java:179)
        at org.jitsi.videobridge.xmpp.XmppCommon.handleIQ(XmppCommon.java:150)
        at org.jitsi.videobridge.xmpp.ClientConnectionImpl.handleIq(ClientConnectionImpl.java:110)
        at org.jitsi.xmpp.mucclient.IQListener.handleIq(IQListener.java:50)
        at org.jitsi.xmpp.mucclient.MucClient.handleIq(MucClient.java:566)
        at org.jitsi.xmpp.mucclient.MucClient.access$700(MucClient.java:50)
        at org.jitsi.xmpp.mucclient.MucClient$2.handleIQRequest(MucClient.java:530)
        at org.jivesoftware.smack.AbstractXMPPConnection$4.run(AbstractXMPPConnection.java:1188)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at java.lang.Thread.run(Thread.java:748)

How I got into this:

  1. systemctl restart jitsi-videobridge2

  2. open few tabs to join the meeting with video off (3~4 participants), and then open a few tabs with video on(3~4 participants), so 6~8 participants in the conference in total. Then, select one of the participant with the video on to set the E2EE key (assume the E2EE key is “123”), and click “set”.

  3. It crashes for all participants, and the SEVERE log above shows up. (if it doesn’t crash after the first participant sets the key, it will crash after the second or the third participant sets it).

Does anyone know what is going on? I know we should probably update it to the latest version of Jitsi bundle(Jitsi-Meet and JVB); however, this issue didn’t occur with the last version of Jitsi (I think it was the version released in May/June).

Any help would be really appreciated!

Thanks,
Thomas

Update: today I tried reinstall Jitsi on the server with the latest package. It broke the same way when switching to E2EE mode.

Can you please attach the complete file after enabling XMPP traffic logs? You can do this by adding the following to /etc/jitsi/videobridge/logging.properties:
org.jitsi.videobridge.xmpp.XmppCommon.level=ALL

Boris

Hi there,
Thanks for replying.
Here is the log:
it is too large so i break it into three replies

2020-08-28 23:40:53.895 INFO: [19] Videobridge.createConference#255: create_conf, id=57030d4d19e78960 gid=-1 logging=false
2020-08-28 23:40:54.021 INFO: [19] org.ice4j.ice.harvest.AbstractUdpListener.<init>: Initialized AbstractUdpListener with address 10.0.11.4:10000/udp. Receive buffer size 10485760 (asked for 10485760)
2020-08-28 23:40:54.021 INFO: [19] org.ice4j.ice.harvest.SinglePortUdpHarvester.<init>: Initialized SinglePortUdpHarvester with address 10.0.11.4:10000/udp
SCTP JNI load: Linux OS detected
SCTP lib loaded
=====>: org_jitsi_modified_sctp4j_SctpJni.c calling init
=====>: org_jitsi_modified_sctp4j_SctpJni.c about to set SCTP_DEBUG_ALL
2020-08-28 23:40:55.299 INFO: [19] AbstractHealthCheckService.run#182: Performed a successful health check in PT1.414S. Sticky failure: false
2020-08-28 23:40:58.684 FINE: [30] XmppCommon.handleIQ#147: RECV: <iq to='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' from='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTYyOQBcDlH/2mo/auZqYMCWG5S9' type='get'><healthcheck xmlns='http://jitsi.org/protocol/healthcheck'/></iq>
2020-08-28 23:40:58.686 FINE: [30] XmppCommon.handleIQ#154: SENT: <iq to='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' from='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTYyOQBcDlH/2mo/auZqYMCWG5S9' type='result'></iq>
2020-08-28 23:41:03.155 FINE: [30] XmppCommon.handleIQ#147: RECV: <iq to='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' from='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTYzOQBcDlH/2mo/auZqYMCWG5S9' type='set'><conference xmlns='http://jitsi.org/protocol/colibri' gid='46089' name='y'><content name='audio'><channel endpoint='469c08b3' initiator='true' channel-bundle-id='469c08b3' last-n='-1'><payload-type name='opus' clockrate='48000' id='111' channels='2'><rtcp-fb xmlns='urn:xmpp:jingle:apps:rtp:rtcp-fb:0' type='transport-cc'/><parameter value='10' name='minptime'/><parameter value='1' name='useinbandfec'/></payload-type><payload-type id='103' name='ISAC' clockrate='16000'/><payload-type id='104' name='ISAC' clockrate='32000'/><payload-type id='126' name='telephone-event' clockrate='8000'/><rtp-hdrext id='1' uri='urn:ietf:params:rtp-hdrext:ssrc-audio-level'/><rtp-hdrext id='5' uri='http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01'/></channel></content><content name='video'><channel endpoint='469c08b3' initiator='true' channel-bundle-id='469c08b3' last-n='-1'><payload-type id='100' name='VP8' clockrate='90000'><rtcp-fb xmlns='urn:xmpp:jingle:apps:rtp:rtcp-fb:0' type='ccm' subtype='fir'/><rtcp-fb x$2020-08-28 23:41:03.157 INFO: [30] Videobridge.createConference#255: create_conf, id=2e214850638dd328 gid=286857 logging=true
2020-08-28 23:41:03.164 INFO: [30] [confId=2e214850638dd328 epId=469c08b3 local_ufrag=4efcp1egrn4apr gid=286857 conf_name=y ufrag=4efcp1egrn4apr] Agent.gatherCandidates#662: Gathering candidates for component stream-469c08b3.RTP.
2020-08-28 23:41:03.166 INFO: [36] [confId=2e214850638dd328 gid=286857 conf_name=y] Conference.dominantSpeakerChanged#464: ds_change ds_id=2e214850638dd328
2020-08-28 23:41:03.186 INFO: [30] [confId=2e214850638dd328 epId=469c08b3 gid=286857 conf_name=y] Endpoint.lambda$setTransportInfo$11#1043: Ignoring empty DtlsFingerprint extension: <transport xmlns='urn:xmpp:jingle:transports:ice-udp:1'><fingerprint xmlns='urn:xmpp:jingle:apps:dtls:0' required='false'/></transport>
2020-08-28 23:41:03.191 FINE: [30] XmppCommon.handleIQ#154: SENT: <iq to='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' from='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTYzOQBcDlH/2mo/auZqYMCWG5S9' type='result'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' name='y'><content name='audio'><channel endpoint='469c08b3' id='f7b8a2aa44a4d728' initiator='true' channel-bundle-id='469c08b3' last-n='-1' rtp-level-relay-type='translator'><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='3545881939'/></channel></content><content name='video'><channel endpoint='469c08b3' id='36833d80ed536cb5' initiator='true' channel-bundle-id='469c08b3' last-n='-1' rtp-level-relay-type='translator'><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='611726534'/></channel></content><content name='data'><sctpconnection endpoint='469c08b3' id='4286225e386d64af' initiator='true' channel-bundle-id='469c08b3' port='5000'/></content><channel-bundle id='469c08b3'><transport xmlns='urn:xmpp:jingle:transports:ice-udp:1' pwd='67ghdpmspin82tv3e0floulqns' ufrag='4efcp1egrn4apr'><rtcp-mux/><fingerprint xmlns='urn:xmpp:jingle:apps:dtls:0' setup='actpass' hash='sha-256'>0A:EF:49:6E:1F:15:C8:90:7F:A5:F2:DE:4E:22:5C:72:7E:FB:98:9$2020-08-28 23:41:03.204 FINE: [30] XmppCommon.handleIQ#147: RECV: <iq to='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' from='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTY0MgBcDlH/2mo/auZqYMCWG5S9' type='set'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' gid='46089' name='y'><content name='audio'><channel endpoint='fa204af2' initiator='true' channel-bundle-id='fa204af2' last-n='-1'><payload-type name='opus' clockrate='48000' id='111' channels='2'><rtcp-fb xmlns='urn:xmpp:jingle:apps:rtp:rtcp-fb:0' type='transport-cc'/><parameter value='10' name='minptime'/><parameter value='1' name='useinbandfec'/></payload-type><payload-type id='103' name='ISAC' clockrate='16000'/><payload-type id='104' name='ISAC' clockrate='32000'/><payload-type id='126' name='telephone-event' clockrate='8000'/><rtp-hdrext id='1' uri='urn:ietf:params:rtp-hdrext:ssrc-audio-level'/><rtp-hdrext id='5' uri='http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01'/></channel></content><content name='video'><channel endpoint='fa204af2' initiator='true' channel-bundle-id='fa204af2' last-n='-1'><payload-type id='100' name='VP8' clockrate='90000'><rtcp-fb xmlns='urn:xmpp:jingle:apps:rtp:rtcp-fb:0' type='ccm' sub$2020-08-28 23:41:03.210 INFO: [30] [confId=2e214850638dd328 epId=fa204af2 local_ufrag=2l67k1egrn4ar8 gid=286857 conf_name=y ufrag=2l67k1egrn4ar8] Agent.gatherCandidates#662: Gathering candidates for component stream-fa204af2.RTP.
2020-08-28 23:41:03.214 INFO: [30] [confId=2e214850638dd328 epId=fa204af2 gid=286857 conf_name=y] Endpoint.lambda$setTransportInfo$11#1043: Ignoring empty DtlsFingerprint extension: <transport xmlns='urn:xmpp:jingle:transports:ice-udp:1'><fingerprint xmlns='urn:xmpp:jingle:apps:dtls:0' required='false'/></transport>
2020-08-28 23:41:03.217 FINE: [30] XmppCommon.handleIQ#154: SENT: <iq to='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' from='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTY0MgBcDlH/2mo/auZqYMCWG5S9' type='result'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' name='y'><content name='audio'><channel endpoint='fa204af2' id='4143362aa30a0b76' initiator='true' channel-bundle-id='fa204af2' last-n='-1' rtp-level-relay-type='translator'><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='3545881939'/></channel></content><content name='video'><channel endpoint='fa204af2' id='3dcb9e20bd739fce' initiator='true' channel-bundle-id='fa204af2' last-n='-1' rtp-level-relay-type='translator'><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='611726534'/></channel></content><content name='data'><sctpconnection endpoint='fa204af2' id='2711fef1082e27eb' initiator='true' channel-bundle-id='fa204af2' port='5000'/></content><channel-bundle id='fa204af2'><transport xmlns='urn:xmpp:jingle:transports:ice-udp:1' pwd='442b5lmccp93jkkf4njavjuru4' ufrag='2l67k1egrn4ar8'><rtcp-mux/><fingerprint xmlns='urn:xmpp:jingle:apps:dtls:0' setup='actpass' hash='sha-256'>0A:EF:49:6E:1F:15:C8:90:7F:A5:F2:DE:4E:22:5C:72:7E:FB:98:9$2020-08-28 23:41:03.885 INFO: [19] Videobridge.createConference#255: create_conf, id=8a73d7348c86bcda gid=-1 logging=false
2020-08-28 23:41:03.900 INFO: [19] AbstractHealthCheckService.run#182: Performed a successful health check in PT0.016S. Sticky failure: false
2020-08-28 23:41:05.249 FINE: [30] XmppCommon.handleIQ#147: RECV: <iq to='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' from='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTY1MwBcDlH/2mo/auZqYMCWG5S9' type='set'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' gid='46089' name='y'><content name='audio'><channel endpoint='6c4f0f6c' initiator='true' channel-bundle-id='6c4f0f6c' last-n='-1'><payload-type name='opus' clockrate='48000' id='111' channels='2'><rtcp-fb xmlns='urn:xmpp:jingle:apps:rtp:rtcp-fb:0' type='transport-cc'/><parameter value='10' name='minptime'/><parameter value='1' name='useinbandfec'/></payload-type><payload-type id='103' name='ISAC' clockrate='16000'/><payload-type id='104' name='ISAC' clockrate='32000'/><payload-type id='126' name='telephone-event' clockrate='8000'/><rtp-hdrext id='1' uri='urn:ietf:params:rtp-hdrext:ssrc-audio-level'/><rtp-hdrext id='5' uri='http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01'/></channel></content><content name='video'><channel endpoint='6c4f0f6c' initiator='true' channel-bundle-id='6c4f0f6c' last-n='-1'><payload-type id='100' name='VP8' clockrate='90000'><rtcp-fb xmlns='urn:xmpp:jingle:apps:rtp:rtcp-fb:0' type='ccm' sub$2020-08-28 23:41:05.253 INFO: [30] [confId=2e214850638dd328 epId=6c4f0f6c local_ufrag=8m2h1egrn4cr4 gid=286857 conf_name=y ufrag=8m2h1egrn4cr4] Agent.gatherCandidates#662: Gathering candidates for component stream-6c4f0f6c.RTP.
2020-08-28 23:41:05.258 INFO: [30] [confId=2e214850638dd328 epId=6c4f0f6c gid=286857 conf_name=y] Endpoint.lambda$setTransportInfo$11#1043: Ignoring empty DtlsFingerprint extension: <transport xmlns='urn:xmpp:jingle:transports:ice-udp:1'><fingerprint xmlns='urn:xmpp:jingle:apps:dtls:0' required='false'/></transport>
2020-08-28 23:41:05.260 FINE: [30] XmppCommon.handleIQ#154: SENT: <iq to='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' from='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTY1MwBcDlH/2mo/auZqYMCWG5S9' type='result'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' name='y'><content name='audio'><channel endpoint='6c4f0f6c' id='c67c13030995de94' initiator='true' channel-bundle-id='6c4f0f6c' last-n='-1' rtp-level-relay-type='translator'><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='3545881939'/></channel></content><content name='video'><channel endpoint='6c4f0f6c' id='bde2c5dfd7d43d74' initiator='true' channel-bundle-id='6c4f0f6c' last-n='-1' rtp-level-relay-type='translator'><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='611726534'/></channel></content><content name='data'><sctpconnection endpoint='6c4f0f6c' id='52b05eab1cc5324a' initiator='true' channel-bundle-id='6c4f0f6c' port='5000'/></content><channel-bundle id='6c4f0f6c'><transport xmlns='urn:xmpp:jingle:transports:ice-udp:1' pwd='7j4qpa8hdem9fmhql9k58s2f1' ufrag='8m2h1egrn4cr4'><rtcp-mux/><fingerprint xmlns='urn:xmpp:jingle:apps:dtls:0' setup='actpass' hash='sha-256'>0A:EF:49:6E:1F:15:C8:90:7F:A5:F2:DE:4E:22:5C:72:7E:FB:98:95:$2020-08-28 23:41:05.673 FINE: [43] XmppCommon.handleIQ#147: RECV: <iq to='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' from='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTY2MgBcDlH/2mo/auZqYMCWG5S9' type='set'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' gid='46089' name='y'><channel-bundle id='6c4f0f6c'><transport xmlns='urn:xmpp:jingle:transports:ice-udp:1' pwd='Z9X5Vukkdt+4gxPeMbJN32KT' ufrag='udmq'><rtcp-mux xmlns='urn:xmpp:jingle:transports:ice-udp:1'/><fingerprint xmlns='urn:xmpp:jingle:apps:dtls:0' hash='sha-256' required='true'>35:CD:2B:69:9A:DF:6B:02:F5:D0:1A:FD:0C:7B:95:7B:2D:F3:64:DF:11:67:78:8E:AA:72:75:49:D4:44:0A:D3</fingerprint><candidate xmlns='urn:xmpp:jingle:transports:ice-udp:1' type='host' network='1' id='bzkejvsdj7' ip='192.168.1.104' component='1' port='52008' foundation='1019731727' generation='0' priority='2122260223' protocol='udp'/><candidate xmlns='urn:xmpp:jingle:transports:ice-udp:1' type='host' network='1' id='qnlouw1dva' ip='192.168.1.104' component='1' port='52008' foundation='1019731727' generation='0' priority='2122260223' protocol='udp'/><candidate xmlns='urn:xmpp:jingle:transports:ice-udp:1' type='host' network='1' id='7mpvqeu35r' ip='10.40.125.195' compo$2020-08-28 23:41:05.680 FINE: [30] XmppCommon.handleIQ#147: RECV: <iq to='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' from='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTY2MABcDlH/2mo/auZqYMCWG5S9' type='set'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' gid='46089' name='y'><content name='audio'><channel id='c67c13030995de94'><payload-type name='opus' channels='2' id='111' clockrate='48000'><rtcp-fb xmlns='urn:xmpp:jingle:apps:rtp:rtcp-fb:0' type='transport-cc'/><parameter value='10' name='minptime'/><parameter value='1' name='useinbandfec'/></payload-type><payload-type name='ISAC' channels='1' id='103' clockrate='16000'/><payload-type name='ISAC' channels='1' id='104' clockrate='32000'/><payload-type name='telephone-event' channels='1' id='126' clockrate='8000'/><rtp-hdrext id='1' uri='urn:ietf:params:rtp-hdrext:ssrc-audio-level'/><rtp-hdrext id='5' uri='http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01'/></channel></content><content name='video'><channel id='bde2c5dfd7d43d74'><payload-type name='VP8' channels='1' id='100' clockrate='90000'><rtcp-fb xmlns='urn:xmpp:jingle:apps:rtp:rtcp-fb:0' type='transport-cc'/><rtcp-fb xmlns='urn:xmpp:jingle:apps:rtp:rtcp-fb:0' t$2020-08-28 23:41:05.682 INFO: [30] [confId=2e214850638dd328 epId=6c4f0f6c gid=286857 stats_id=Ernestina-BCM conf_name=y] DtlsTransport.setSetupAttribute#124: The remote side is acting as DTLS server, we'll act as client
2020-08-28 23:41:05.691 INFO: [43] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM componentId=1 conf_name=y ufrag=8m2h1egrn4cr4 name=stream-6c4f0f6c epId=6c4f0f6c local_ufrag=8m2h1egrn4cr4] Component.addRemoteCandidate#330: Add remote candidate for stream-6c4f0f6c.RTP: 192.168.1.104:52008/udp/host
2020-08-28 23:41:05.691 INFO: [43] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM componentId=1 conf_name=y ufrag=8m2h1egrn4cr4 name=stream-6c4f0f6c epId=6c4f0f6c local_ufrag=8m2h1egrn4cr4] Component.addRemoteCandidate#330: Add remote candidate for stream-6c4f0f6c.RTP: 192.168.1.104:52008/udp/host
2020-08-28 23:41:05.691 INFO: [43] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM componentId=1 conf_name=y ufrag=8m2h1egrn4cr4 name=stream-6c4f0f6c epId=6c4f0f6c local_ufrag=8m2h1egrn4cr4] Component.addRemoteCandidate#330: Add remote candidate for stream-6c4f0f6c.RTP: 10.40.125.195:52009/udp/host
2020-08-28 23:41:05.691 INFO: [43] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM componentId=1 conf_name=y ufrag=8m2h1egrn4cr4 name=stream-6c4f0f6c epId=6c4f0f6c local_ufrag=8m2h1egrn4cr4] Component.addRemoteCandidate#330: Add remote candidate for stream-6c4f0f6c.RTP: 192.168.56.1:52010/udp/host
2020-08-28 23:41:05.692 INFO: [43] [confId=2e214850638dd328 epId=6c4f0f6c local_ufrag=8m2h1egrn4cr4 gid=286857 stats_id=Ernestina-BCM conf_name=y] IceTransport.startConnectivityEstablishment#176: Starting the agent with remote candidates.
2020-08-28 23:41:05.692 INFO: [43] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=8m2h1egrn4cr4 epId=6c4f0f6c local_ufrag=8m2h1egrn4cr4] Agent.startConnectivityEstablishment#753: Start ICE connectivity establishment.
2020-08-28 23:41:05.692 INFO: [43] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=8m2h1egrn4cr4 epId=6c4f0f6c local_ufrag=8m2h1egrn4cr4] Agent.initCheckLists#996: Init checklist for stream stream-6c4f0f6c
2020-08-28 23:41:05.694 INFO: [43] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=8m2h1egrn4cr4 epId=6c4f0f6c local_ufrag=8m2h1egrn4cr4] Agent.setState#963: ICE state changed from Waiting to Running.
2020-08-28 23:41:05.694 INFO: [43] [confId=2e214850638dd328 epId=6c4f0f6c local_ufrag=8m2h1egrn4cr4 gid=286857 stats_id=Ernestina-BCM conf_name=y] IceTransport.iceStateChanged#321: ICE state changed old=Waiting new=Running
2020-08-28 23:41:05.695 INFO: [43] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=8m2h1egrn4cr4 epId=6c4f0f6c local_ufrag=8m2h1egrn4cr4] ConnectivityCheckClient.startChecks#142: Start connectivity checks.
2020-08-28 23:41:05.700 FINE: [43] XmppCommon.handleIQ#154: SENT: <iq to='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' from='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTY2MgBcDlH/2mo/auZqYMCWG5S9' type='result'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' name='y'><channel-bundle id='6c4f0f6c'><transport xmlns='urn:xmpp:jingle:transports:ice-udp:1' pwd='7j4qpa8hdem9fmhql9k58s2f1' ufrag='8m2h1egrn4cr4'><rtcp-mux/><fingerprint xmlns='urn:xmpp:jingle:apps:dtls:0' setup='actpass' hash='sha-256'>0A:EF:49:6E:1F:15:C8:90:7F:A5:F2:DE:4E:22:5C:72:7E:FB:98:95:60:0B:61:3E:42:29:B3:E3:C9:96:68:CF</fingerprint><candidate component='1' foundation='1' generation='0' id='cbf742b1e10c5b30309817c8' network='0' priority='2130706431' protocol='udp' type='host' ip='10.0.11.4' port='10000'/><candidate component='1' foundation='2' generation='0' id='7e4102401e10c5b305b832d46' network='0' priority='1694498815' protocol='udp' type='srflx' ip='52.235.32.130' port='10000' rel-addr='10.0.11.4' rel-port='10000'/></transport></channel-bundle><endpoint id='fa204af2' stats-id='Ernestina-BCM'/><endpoint id='6c4f0f6c' stats-id='Ernestina-BCM'/><endpoint id='469c08b3' stats-id='Ernestina-BCM'/></conference></iq>
2020-08-28 23:41:05.705 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM componentId=1 conf_name=y ufrag=8m2h1egrn4cr4 name=stream-6c4f0f6c epId=6c4f0f6c local_ufrag=8m2h1egrn4cr4] Component.addUpdateRemoteCandidates#347: Update remote candidate for stream-6c4f0f6c.RTP: 192.168.1.104:52008/udp
2020-08-28 23:41:05.705 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM componentId=1 conf_name=y ufrag=8m2h1egrn4cr4 name=stream-6c4f0f6c epId=6c4f0f6c local_ufrag=8m2h1egrn4cr4] Component.addUpdateRemoteCandidates#369: Not adding duplicate remote candidate: 192.168.1.104:52008/udp
2020-08-28 23:41:05.706 FINE: [30] XmppCommon.handleIQ#154: SENT: <iq to='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' from='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTY2MABcDlH/2mo/auZqYMCWG5S9' type='result'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' name='y'><content name='audio'><channel endpoint='6c4f0f6c' id='c67c13030995de94' initiator='true' channel-bundle-id='6c4f0f6c' last-n='-1' rtp-level-relay-type='translator'><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='3545881939'/></channel></content><content name='video'><channel endpoint='6c4f0f6c' id='bde2c5dfd7d43d74' initiator='true' channel-bundle-id='6c4f0f6c' last-n='-1' rtp-level-relay-type='translator'><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='611726534'/></channel></content><channel-bundle id='6c4f0f6c'><transport xmlns='urn:xmpp:jingle:transports:ice-udp:1' pwd='7j4qpa8hdem9fmhql9k58s2f1' ufrag='8m2h1egrn4cr4'><rtcp-mux/><fingerprint xmlns='urn:xmpp:jingle:apps:dtls:0' setup='active' hash='sha-256'>0A:EF:49:6E:1F:15:C8:90:7F:A5:F2:DE:4E:22:5C:72:7E:FB:98:95:60:0B:61:3E:42:29:B3:E3:C9:96:68:CF</fingerprint><candidate component='1' foundation='1' generation='0' id='1f7394c01e10c5b30309817c8' network='0' pr$2020-08-28 23:41:05.726 INFO: [28] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=8m2h1egrn4cr4 epId=6c4f0f6c local_ufrag=8m2h1egrn4cr4] Agent.triggerCheck#1761: Add peer CandidatePair with new reflexive address to checkList: CandidatePair (State=Frozen Priority=7962116751041232895):
        LocalCandidate=candidate:1 1 udp 2130706431 10.0.11.4 10000 typ host
        RemoteCandidate=candidate:10000 1 udp 1853824767 72.138.65.206 32998 typ prflx
2020-08-28 23:41:05.727 INFO: [47] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=8m2h1egrn4cr4 epId=6c4f0f6c local_ufrag=8m2h1egrn4cr4] ConnectivityCheckClient$PaceMaker.run#922: Pair failed: 10.0.11.4:10000/udp/host -> 192.168.1.104:52008/udp/host (stream-6c4f0f6c.RTP)
2020-08-28 23:41:05.769 INFO: [28] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=8m2h1egrn4cr4 epId=6c4f0f6c local_ufrag=8m2h1egrn4cr4] ConnectivityCheckClient.processSuccessResponse#630: Pair succeeded: 10.0.11.4:10000/udp/host -> 72.138.65.206:32998/udp/prflx (stream-6c4f0f6c.RTP).
2020-08-28 23:41:05.769 INFO: [28] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM componentId=1 conf_name=y ufrag=8m2h1egrn4cr4 name=stream-6c4f0f6c epId=6c4f0f6c local_ufrag=8m2h1egrn4cr4] ComponentSocket.addAuthorizedAddress#99: Adding allowed address: 72.138.65.206:32998/udp
2020-08-28 23:41:05.769 INFO: [28] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=8m2h1egrn4cr4 epId=6c4f0f6c local_ufrag=8m2h1egrn4cr4] ConnectivityCheckClient.processSuccessResponse#639: Pair validated: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:32998/udp/prflx (stream-6c4f0f6c.RTP).
2020-08-28 23:41:05.770 INFO: [28] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=8m2h1egrn4cr4 epId=6c4f0f6c local_ufrag=8m2h1egrn4cr4] DefaultNominator.strategyNominateFirstValid#142: Nominate (first valid): 52.235.32.130:10000/udp/srflx -> 72.138.65.206:32998/udp/prflx (stream-6c4f0f6c.RTP).
2020-08-28 23:41:05.770 INFO: [28] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=8m2h1egrn4cr4 epId=6c4f0f6c local_ufrag=8m2h1egrn4cr4] Agent.nominate#1834: verify if nominated pair answer again
2020-08-28 23:41:05.771 INFO: [28] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=8m2h1egrn4cr4 epId=6c4f0f6c local_ufrag=8m2h1egrn4cr4] ConnectivityCheckClient.processSuccessResponse#708: IsControlling: true USE-CANDIDATE:false.
2020-08-28 23:41:05.790 INFO: [28] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=8m2h1egrn4cr4 epId=6c4f0f6c local_ufrag=8m2h1egrn4cr4] ConnectivityCheckClient.processSuccessResponse#630: Pair succeeded: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:32998/udp/prflx (stream-6c4f0f6c.RTP).
2020-08-28 23:41:05.790 INFO: [28] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=8m2h1egrn4cr4 epId=6c4f0f6c local_ufrag=8m2h1egrn4cr4] ConnectivityCheckClient.processSuccessResponse#639: Pair validated: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:32998/udp/prflx (stream-6c4f0f6c.RTP).
2020-08-28 23:41:05.790 INFO: [28] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=8m2h1egrn4cr4 epId=6c4f0f6c local_ufrag=8m2h1egrn4cr4] ConnectivityCheckClient.processSuccessResponse#708: IsControlling: true USE-CANDIDATE:true.
2020-08-28 23:41:05.790 INFO: [28] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=8m2h1egrn4cr4 epId=6c4f0f6c local_ufrag=8m2h1egrn4cr4] ConnectivityCheckClient.processSuccessResponse#723: Nomination confirmed for pair: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:32998/udp/prflx (stream-6c4f0f6c.RTP).
2020-08-28 23:41:05.791 INFO: [28] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=8m2h1egrn4cr4 name=stream-6c4f0f6c epId=6c4f0f6c local_ufrag=8m2h1egrn4cr4] CheckList.handleNominationConfirmed#406: Selected pair for stream stream-6c4f0f6c.RTP: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:32998/udp/prflx (stream-6c4f0f6c.RTP)
2020-08-28 23:41:05.791 INFO: [28] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=8m2h1egrn4cr4 epId=6c4f0f6c local_ufrag=8m2h1egrn4cr4] Agent.checkListStatesUpdated#1925: CheckList of stream stream-6c4f0f6c is COMPLETED
2020-08-28 23:41:05.791 INFO: [28] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=8m2h1egrn4cr4 epId=6c4f0f6c local_ufrag=8m2h1egrn4cr4] Agent.setState#963: ICE state changed from Running to Completed.
2020-08-28 23:41:05.792 INFO: [28] [confId=2e214850638dd328 epId=6c4f0f6c local_ufrag=8m2h1egrn4cr4 gid=286857 stats_id=Ernestina-BCM conf_name=y] IceTransport.iceStateChanged#321: ICE state changed old=Running new=Completed
2020-08-28 23:41:05.792 INFO: [28] [confId=2e214850638dd328 epId=6c4f0f6c gid=286857 stats_id=Ernestina-BCM conf_name=y] Endpoint$3.connected#377: ICE connected
2020-08-28 23:41:05.795 INFO: [35] [confId=2e214850638dd328 epId=6c4f0f6c gid=286857 stats_id=Ernestina-BCM conf_name=y] DtlsTransport.startDtlsHandshake#102: Starting DTLS handshake
2020-08-28 23:41:05.795 INFO: [28] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=8m2h1egrn4cr4 epId=6c4f0f6c local_ufrag=8m2h1egrn4cr4] Agent.logCandTypes#2033: Harvester used for selected pair for stream-6c4f0f6c.RTP: srflx
2020-08-28 23:41:05.797 FINE: [30] XmppCommon.handleIQ#147: RECV: <iq to='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' from='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTY2NwBcDlH/2mo/auZqYMCWG5S9' type='set'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' gid='46089' name='y'><channel-bundle id='6c4f0f6c'><transport xmlns='urn:xmpp:jingle:transports:ice-udp:1' pwd='Z9X5Vukkdt+4gxPeMbJN32KT' ufrag='udmq'><rtcp-mux xmlns='urn:xmpp:jingle:transports:ice-udp:1'/><fingerprint xmlns='urn:xmpp:jingle:apps:dtls:0' hash='sha-256' required='true'>35:CD:2B:69:9A:DF:6B:02:F5:D0:1A:FD:0C:7B:95:7B:2D:F3:64:DF:11:67:78:8E:AA:72:75:49:D4:44:0A:D3</fingerprint><candidate xmlns='urn:xmpp:jingle:transports:ice-udp:1' type='host' network='1' id='bzkejvsdj7' ip='192.168.1.104' component='1' port='52008' foundation='1019731727' generation='0' priority='2122260223' protocol='udp'/><candidate xmlns='urn:xmpp:jingle:transports:ice-udp:1' type='host' network='1' id='qnlouw1dva' ip='192.168.1.104' component='1' port='52008' foundation='1019731727' generation='0' priority='2122260223' protocol='udp'/><candidate xmlns='urn:xmpp:jingle:transports:ice-udp:1' type='host' network='1' id='7mpvqeu35r' ip='10.40.125.195' compo$2020-08-28 23:41:05.799 FINE: [30] XmppCommon.handleIQ#154: SENT: <iq to='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' from='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTY2NwBcDlH/2mo/auZqYMCWG5S9' type='result'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' name='y'><channel-bundle id='6c4f0f6c'><transport xmlns='urn:xmpp:jingle:transports:ice-udp:1' pwd='7j4qpa8hdem9fmhql9k58s2f1' ufrag='8m2h1egrn4cr4'><rtcp-mux/><fingerprint xmlns='urn:xmpp:jingle:apps:dtls:0' setup='active' hash='sha-256'>0A:EF:49:6E:1F:15:C8:90:7F:A5:F2:DE:4E:22:5C:72:7E:FB:98:95:60:0B:61:3E:42:29:B3:E3:C9:96:68:CF</fingerprint><candidate component='1' foundation='1' generation='0' id='22ec26fa1e10c5b30309817c8' network='0' priority='2130706431' protocol='udp' type='host' ip='10.0.11.4' port='10000'/><candidate component='1' foundation='2' generation='0' id='391f8b071e10c5b305b832d46' network='0' priority='1694498815' protocol='udp' type='srflx' ip='52.235.32.130' port='10000' rel-addr='10.0.11.4' rel-port='10000'/></transport></channel-bundle><endpoint id='fa204af2' stats-id='Ernestina-BCM'/><endpoint id='6c4f0f6c' stats-id='Ernestina-BCM'/><endpoint id='469c08b3' stats-id='Ernestina-BCM'/></conference></iq>
2020-08-28 23:41:05.867 INFO: [36] PartitionedByteBufferPool.<init>#88: Initialized a new PartitionedByteBufferPool with 8 partitions.
2020-08-28 23:41:05.868 INFO: [36] PartitionedByteBufferPool.<init>#88: Initialized a new PartitionedByteBufferPool with 8 partitions.
2020-08-28 23:41:05.868 INFO: [36] PartitionedByteBufferPool.<init>#88: Initialized a new PartitionedByteBufferPool with 8 partitions.
2020-08-28 23:41:05.870 INFO: [35] [confId=2e214850638dd328 epId=6c4f0f6c gid=286857 stats_id=Ernestina-BCM conf_name=y] TlsClientImpl.notifyServerVersion#165: Negotiated DTLS version DTLS 1.2
2020-08-28 23:41:05.958 INFO: [35] [confId=2e214850638dd328 epId=6c4f0f6c gid=286857 stats_id=Ernestina-BCM conf_name=y] Endpoint.lambda$setupDtlsTransport$2#404: DTLS handshake complete
2020-08-28 23:41:05.963 INFO: [50] [confId=2e214850638dd328 epId=6c4f0f6c gid=286857 stats_id=Ernestina-BCM conf_name=y] Endpoint.lambda$acceptSctpConnection$8#902: Attempting to establish SCTP socket connection
2020-08-28 23:41:06.084 FINE: [30] XmppCommon.handleIQ#147: RECV: <iq to='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' from='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTY3MwBcDlH/2mo/auZqYMCWG5S9' type='set'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' gid='46089' name='y'><content name='audio'><channel id='4143362aa30a0b76'><payload-type name='opus' channels='2' id='111' clockrate='48000'><rtcp-fb xmlns='urn:xmpp:jingle:apps:rtp:rtcp-fb:0' type='transport-cc'/><parameter value='10' name='minptime'/><parameter value='1' name='useinbandfec'/></payload-type><payload-type name='ISAC' channels='1' id='103' clockrate='16000'/><payload-type name='ISAC' channels='1' id='104' clockrate='32000'/><payload-type name='telephone-event' channels='1' id='126' clockrate='8000'/><rtp-hdrext id='1' uri='urn:ietf:params:rtp-hdrext:ssrc-audio-level'/><rtp-hdrext id='5' uri='http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01'/></channel></content><content name='video'><channel id='3dcb9e20bd739fce'><payload-type name='VP8' channels='1' id='100' clockrate='90000'><rtcp-fb xmlns='urn:xmpp:jingle:apps:rtp:rtcp-fb:0' type='transport-cc'/><rtcp-fb xmlns='urn:xmpp:jingle:apps:rtp:rtcp-fb:0' t$2020-08-28 23:41:06.086 INFO: [30] [confId=2e214850638dd328 epId=fa204af2 gid=286857 stats_id=Ernestina-BCM conf_name=y] DtlsTransport.setSetupAttribute#124: The remote side is acting as DTLS server, we'll act as client
2020-08-28 23:41:06.086 INFO: [30] [confId=2e214850638dd328 epId=fa204af2 local_ufrag=2l67k1egrn4ar8 gid=286857 stats_id=Ernestina-BCM conf_name=y] IceTransport.startConnectivityEstablishment#182: Starting the Agent without remote candidates.
2020-08-28 23:41:06.086 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=2l67k1egrn4ar8 epId=fa204af2 local_ufrag=2l67k1egrn4ar8] Agent.startConnectivityEstablishment#753: Start ICE connectivity establishment.
2020-08-28 23:41:06.086 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=2l67k1egrn4ar8 epId=fa204af2 local_ufrag=2l67k1egrn4ar8] Agent.initCheckLists#996: Init checklist for stream stream-fa204af2
2020-08-28 23:41:06.087 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=2l67k1egrn4ar8 epId=fa204af2 local_ufrag=2l67k1egrn4ar8] Agent.setState#963: ICE state changed from Waiting to Running.
2020-08-28 23:41:06.087 INFO: [30] [confId=2e214850638dd328 epId=fa204af2 local_ufrag=2l67k1egrn4ar8 gid=286857 stats_id=Ernestina-BCM conf_name=y] IceTransport.iceStateChanged#321: ICE state changed old=Waiting new=Running
2020-08-28 23:41:06.087 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=2l67k1egrn4ar8 epId=fa204af2 local_ufrag=2l67k1egrn4ar8] Agent.startConnectivityEstablishment#775: Trigger checks for pairs that were received before running state
2020-08-28 23:41:06.087 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=2l67k1egrn4ar8 epId=fa204af2 local_ufrag=2l67k1egrn4ar8] Agent.triggerCheck#1761: Add peer CandidatePair with new reflexive address to checkList: CandidatePair (State=Frozen Priority=7962116751041232895):
        LocalCandidate=candidate:1 1 udp 2130706431 10.0.11.4 10000 typ host
        RemoteCandidate=candidate:10000 1 udp 1853824767 72.138.65.206 39412 typ prflx
2020-08-28 23:41:06.087 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=2l67k1egrn4ar8 epId=fa204af2 local_ufrag=2l67k1egrn4ar8] ConnectivityCheckClient.startChecks#142: Start connectivity checks.
2020-08-28 23:41:06.088 FINE: [30] XmppCommon.handleIQ#154: SENT: <iq to='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' from='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTY3MwBcDlH/2mo/auZqYMCWG5S9' type='result'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' name='y'><content name='audio'><channel endpoint='fa204af2' id='4143362aa30a0b76' initiator='true' channel-bundle-id='fa204af2' last-n='-1' rtp-level-relay-type='translator'><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='3545881939'/></channel></content><content name='video'><channel endpoint='fa204af2' id='3dcb9e20bd739fce' initiator='true' channel-bundle-id='fa204af2' last-n='-1' rtp-level-relay-type='translator'><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='611726534'/></channel></content><channel-bundle id='fa204af2'><transport xmlns='urn:xmpp:jingle:transports:ice-udp:1' pwd='442b5lmccp93jkkf4njavjuru4' ufrag='2l67k1egrn4ar8'><rtcp-mux/><fingerprint xmlns='urn:xmpp:jingle:apps:dtls:0' setup='active' hash='sha-256'>0A:EF:49:6E:1F:15:C8:90:7F:A5:F2:DE:4E:22:5C:72:7E:FB:98:95:60:0B:61:3E:42:29:B3:E3:C9:96:68:CF</fingerprint><candidate component='1' foundation='1' generation='0' id='ac8c44f7f9c5060039d15bda' network='0' p$2020-08-28 23:41:06.091 FINE: [30] XmppCommon.handleIQ#147: RECV: <iq to='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' from='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTY3NgBcDlH/2mo/auZqYMCWG5S9' type='set'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' gid='46089' name='y'><channel-bundle id='fa204af2'><transport xmlns='urn:xmpp:jingle:transports:ice-udp:1' pwd='QT/+/QfznnMyWh58Sq4bFMBD' ufrag='vR2X'><rtcp-mux xmlns='urn:xmpp:jingle:transports:ice-udp:1'/><fingerprint xmlns='urn:xmpp:jingle:apps:dtls:0' hash='sha-256' required='true'>83:15:6E:0A:D2:19:6B:B1:4B:3E:01:3C:76:2E:BD:EA:A3:A0:85:33:3C:6E:5D:E7:A9:58:C1:58:FA:DD:15:85</fingerprint><candidate xmlns='urn:xmpp:jingle:transports:ice-udp:1' type='host' network='1' id='q38rlul41w' ip='192.168.1.104' component='1' port='51998' foundation='1019731727' generation='0' priority='2122260223' protocol='udp'/><candidate xmlns='urn:xmpp:jingle:transports:ice-udp:1' type='host' network='1' id='9jpz5jzb13' ip='10.40.125.195' component='1' port='51999' foundation='2151505277' generation='0' priority='2122194687' protocol='udp'/><candidate xmlns='urn:xmpp:jingle:transports:ice-udp:1' type='host' network='1' id='d321acni9w' ip='192.168.56.1' compon$2020-08-28 23:41:06.091 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM componentId=1 conf_name=y ufrag=2l67k1egrn4ar8 name=stream-fa204af2 epId=fa204af2 local_ufrag=2l67k1egrn4ar8] Component.addUpdateRemoteCandidates#347: Update remote candidate for stream-fa204af2.RTP: 192.168.1.104:51998/udp
2020-08-28 23:41:06.091 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM componentId=1 conf_name=y ufrag=2l67k1egrn4ar8 name=stream-fa204af2 epId=fa204af2 local_ufrag=2l67k1egrn4ar8] Component.addUpdateRemoteCandidates#347: Update remote candidate for stream-fa204af2.RTP: 10.40.125.195:51999/udp
2020-08-28 23:41:06.092 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM componentId=1 conf_name=y ufrag=2l67k1egrn4ar8 name=stream-fa204af2 epId=fa204af2 local_ufrag=2l67k1egrn4ar8] Component.addUpdateRemoteCandidates#347: Update remote candidate for stream-fa204af2.RTP: 192.168.56.1:52000/udp
2020-08-28 23:41:06.093 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM componentId=1 conf_name=y ufrag=2l67k1egrn4ar8 name=stream-fa204af2 epId=fa204af2 local_ufrag=2l67k1egrn4ar8] Component.updateRemoteCandidates#481: new Pair added: 10.0.11.4:10000/udp/host -> 192.168.1.104:51998/udp/host (stream-fa204af2.RTP).
2020-08-28 23:41:06.093 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM componentId=1 conf_name=y ufrag=2l67k1egrn4ar8 name=stream-fa204af2 epId=fa204af2 local_ufrag=2l67k1egrn4ar8] Component.updateRemoteCandidates#481: new Pair added: 10.0.11.4:10000/udp/host -> 10.40.125.195:51999/udp/host (stream-fa204af2.RTP).
2020-08-28 23:41:06.093 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM componentId=1 conf_name=y ufrag=2l67k1egrn4ar8 name=stream-fa204af2 epId=fa204af2 local_ufrag=2l67k1egrn4ar8] Component.updateRemoteCandidates#481: new Pair added: 10.0.11.4:10000/udp/host -> 192.168.56.1:52000/udp/host (stream-fa204af2.RTP).
2020-08-28 23:41:06.093 FINE: [30] XmppCommon.handleIQ#154: SENT: <iq to='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' from='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTY3NgBcDlH/2mo/auZqYMCWG5S9' type='result'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' name='y'><channel-bundle id='fa204af2'><transport xmlns='urn:xmpp:jingle:transports:ice-udp:1' pwd='442b5lmccp93jkkf4njavjuru4' ufrag='2l67k1egrn4ar8'><rtcp-mux/><fingerprint xmlns='urn:xmpp:jingle:apps:dtls:0' setup='active' hash='sha-256'>0A:EF:49:6E:1F:15:C8:90:7F:A5:F2:DE:4E:22:5C:72:7E:FB:98:95:60:0B:61:3E:42:29:B3:E3:C9:96:68:CF</fingerprint><candidate component='1' foundation='1' generation='0' id='47ef2df77f9c5060039d15bda' network='0' priority='2130706431' protocol='udp' type='host' ip='10.0.11.4' port='10000'/><candidate component='1' foundation='2' generation='0' id='4ff5c81d7f9c5060064bc7158' network='0' priority='1694498815' protocol='udp' type='srflx' ip='52.235.32.130' port='10000' rel-addr='10.0.11.4' rel-port='10000'/></transport></channel-bundle><endpoint id='fa204af2' stats-id='Ernestina-BCM'/><endpoint id='6c4f0f6c' stats-id='Ernestina-BCM'/><endpoint id='469c08b3' stats-id='Ernestina-BCM'/></conference></iq>
2020-08-28 23:41:06.130 INFO: [47] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=2l67k1egrn4ar8 epId=fa204af2 local_ufrag=2l67k1egrn4ar8] ConnectivityCheckClient$PaceMaker.run#922: Pair failed: 10.0.11.4:10000/udp/host -> 192.168.1.104:51998/udp/host (stream-fa204af2.RTP)
2020-08-28 23:41:06.130 INFO: [49] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=2l67k1egrn4ar8 epId=fa204af2 local_ufrag=2l67k1egrn4ar8] ConnectivityCheckClient$PaceMaker.run#922: Pair failed: 10.0.11.4:10000/udp/host -> 192.168.1.104:51998/udp/host (stream-fa204af2.RTP)
2020-08-28 23:41:06.137 INFO: [28] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=2l67k1egrn4ar8 epId=fa204af2 local_ufrag=2l67k1egrn4ar8] ConnectivityCheckClient.processSuccessResponse#630: Pair succeeded: 10.0.11.4:10000/udp/host -> 72.138.65.206:39412/udp/prflx (stream-fa204af2.RTP).
2020-08-28 23:41:06.137 INFO: [28] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM componentId=1 conf_name=y ufrag=2l67k1egrn4ar8 name=stream-fa204af2 epId=fa204af2 local_ufrag=2l67k1egrn4ar8] ComponentSocket.addAuthorizedAddress#99: Adding allowed address: 72.138.65.206:39412/udp
2020-08-28 23:41:06.137 INFO: [28] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=2l67k1egrn4ar8 epId=fa204af2 local_ufrag=2l67k1egrn4ar8] ConnectivityCheckClient.processSuccessResponse#639: Pair validated: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:39412/udp/prflx (stream-fa204af2.RTP).
2020-08-28 23:41:06.137 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=2l67k1egrn4ar8 epId=fa204af2 local_ufrag=2l67k1egrn4ar8] ConnectivityCheckClient.processSuccessResponse#630: Pair succeeded: 10.0.11.4:10000/udp/host -> 72.138.65.206:39412/udp/prflx (stream-fa204af2.RTP).
2020-08-28 23:41:06.137 INFO: [28] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=2l67k1egrn4ar8 epId=fa204af2 local_ufrag=2l67k1egrn4ar8] DefaultNominator.strategyNominateFirstValid#142: Nominate (first valid): 52.235.32.130:10000/udp/srflx -> 72.138.65.206:39412/udp/prflx (stream-fa204af2.RTP).
2020-08-28 23:41:06.137 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=2l67k1egrn4ar8 epId=fa204af2 local_ufrag=2l67k1egrn4ar8] ConnectivityCheckClient.processSuccessResponse#639: Pair validated: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:39412/udp/prflx (stream-fa204af2.RTP).
2020-08-28 23:41:06.138 INFO: [28] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=2l67k1egrn4ar8 epId=fa204af2 local_ufrag=2l67k1egrn4ar8] Agent.nominate#1834: verify if nominated pair answer again
2020-08-28 23:41:06.138 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=2l67k1egrn4ar8 epId=fa204af2 local_ufrag=2l67k1egrn4ar8] DefaultNominator.strategyNominateFirstValid#142: Nominate (first valid): 52.235.32.130:10000/udp/srflx -> 72.138.65.206:39412/udp/prflx (stream-fa204af2.RTP).
2020-08-28 23:41:06.138 INFO: [28] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=2l67k1egrn4ar8 epId=fa204af2 local_ufrag=2l67k1egrn4ar8] ConnectivityCheckClient.processSuccessResponse#708: IsControlling: true USE-CANDIDATE:false.
2020-08-28 23:41:06.138 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=2l67k1egrn4ar8 epId=fa204af2 local_ufrag=2l67k1egrn4ar8] ConnectivityCheckClient.processSuccessResponse#708: IsControlling: true USE-CANDIDATE:false.
2020-08-28 23:41:06.151 INFO: [47] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=2l67k1egrn4ar8 epId=fa204af2 local_ufrag=2l67k1egrn4ar8] ConnectivityCheckClient$PaceMaker.run#922: Pair failed: 10.0.11.4:10000/udp/host -> 10.40.125.195:51999/udp/host (stream-fa204af2.RTP)
2020-08-28 23:41:06.172 INFO: [47] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=2l67k1egrn4ar8 epId=fa204af2 local_ufrag=2l67k1egrn4ar8] ConnectivityCheckClient$PaceMaker.run#922: Pair failed: 10.0.11.4:10000/udp/host -> 192.168.56.1:52000/udp/host (stream-fa204af2.RTP)
2020-08-28 23:41:06.173 INFO: [49] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=2l67k1egrn4ar8 epId=fa204af2 local_ufrag=2l67k1egrn4ar8] ConnectivityCheckClient$PaceMaker.run#922: Pair failed: 10.0.11.4:10000/udp/host -> 192.168.56.1:52000/udp/host (stream-fa204af2.RTP)
2020-08-28 23:41:06.184 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=2l67k1egrn4ar8 epId=fa204af2 local_ufrag=2l67k1egrn4ar8] ConnectivityCheckClient.processSuccessResponse#630: Pair succeeded: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:39412/udp/prflx (stream-fa204af2.RTP).
2020-08-28 23:41:06.184 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=2l67k1egrn4ar8 epId=fa204af2 local_ufrag=2l67k1egrn4ar8] ConnectivityCheckClient.processSuccessResponse#639: Pair validated: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:39412/udp/prflx (stream-fa204af2.RTP).
2020-08-28 23:41:06.184 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=2l67k1egrn4ar8 epId=fa204af2 local_ufrag=2l67k1egrn4ar8] ConnectivityCheckClient.processSuccessResponse#708: IsControlling: true USE-CANDIDATE:true.
2020-08-28 23:41:06.184 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=2l67k1egrn4ar8 epId=fa204af2 local_ufrag=2l67k1egrn4ar8] ConnectivityCheckClient.processSuccessResponse#723: Nomination confirmed for pair: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:39412/udp/prflx (stream-fa204af2.RTP).
2020-08-28 23:41:06.185 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=2l67k1egrn4ar8 name=stream-fa204af2 epId=fa204af2 local_ufrag=2l67k1egrn4ar8] CheckList.handleNominationConfirmed#406: Selected pair for stream stream-fa204af2.RTP: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:39412/udp/prflx (stream-fa204af2.RTP)
2020-08-28 23:41:06.185 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=2l67k1egrn4ar8 epId=fa204af2 local_ufrag=2l67k1egrn4ar8] Agent.checkListStatesUpdated#1925: CheckList of stream stream-fa204af2 is COMPLETED
2020-08-28 23:41:06.186 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=2l67k1egrn4ar8 epId=fa204af2 local_ufrag=2l67k1egrn4ar8] Agent.setState#963: ICE state changed from Running to Completed.
2020-08-28 23:41:06.186 INFO: [48] [confId=2e214850638dd328 epId=fa204af2 local_ufrag=2l67k1egrn4ar8 gid=286857 stats_id=Ernestina-BCM conf_name=y] IceTransport.iceStateChanged#321: ICE state changed old=Running new=Completed
2020-08-28 23:41:06.186 INFO: [48] [confId=2e214850638dd328 epId=fa204af2 gid=286857 stats_id=Ernestina-BCM conf_name=y] Endpoint$3.connected#377: ICE connected
2020-08-28 23:41:06.186 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=2l67k1egrn4ar8 epId=fa204af2 local_ufrag=2l67k1egrn4ar8] Agent.logCandTypes#2033: Harvester used for selected pair for stream-fa204af2.RTP: srflx
2020-08-28 23:41:06.186 INFO: [51] [confId=2e214850638dd328 epId=fa204af2 gid=286857 stats_id=Ernestina-BCM conf_name=y] DtlsTransport.startDtlsHandshake#102: Starting DTLS handshake
2020-08-28 23:41:06.212 INFO: [51] [confId=2e214850638dd328 epId=fa204af2 gid=286857 stats_id=Ernestina-BCM conf_name=y] TlsClientImpl.notifyServerVersion#165: Negotiated DTLS version DTLS 1.2
2020-08-28 23:41:06.242 INFO: [51] [confId=2e214850638dd328 epId=fa204af2 gid=286857 stats_id=Ernestina-BCM conf_name=y] Endpoint.lambda$setupDtlsTransport$2#404: DTLS handshake complete
2020-08-28 23:41:06.243 INFO: [52] [confId=2e214850638dd328 epId=fa204af2 gid=286857 stats_id=Ernestina-BCM conf_name=y] Endpoint.lambda$acceptSctpConnection$8#902: Attempting to establish SCTP socket connection
2020-08-28 23:41:06.494 INFO: [53] OpenSslWrapperLoader.<clinit>#46: jitsisrtp successfully loaded
2020-08-28 23:41:07.094 FINE: [30] XmppCommon.handleIQ#147: RECV: <iq to='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' from='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTY4NABcDlH/2mo/auZqYMCWG5S9' type='set'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' gid='46089' name='y'><content name='audio'><channel id='f7b8a2aa44a4d728'><payload-type name='opus' channels='2' id='111' clockrate='48000'><rtcp-fb xmlns='urn:xmpp:jingle:apps:rtp:rtcp-fb:0' type='transport-cc'/><parameter value='10' name='minptime'/><parameter value='1' name='useinbandfec'/></payload-type><payload-type name='ISAC' channels='1' id='103' clockrate='16000'/><payload-type name='ISAC' channels='1' id='104' clockrate='32000'/><payload-type name='telephone-event' channels='1' id='126' clockrate='8000'/><rtp-hdrext id='1' uri='urn:ietf:params:rtp-hdrext:ssrc-audio-level'/><rtp-hdrext id='5' uri='http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01'/></channel></content><content name='video'><channel id='36833d80ed536cb5'><payload-type name='VP8' channels='1' id='100' clockrate='90000'><rtcp-fb xmlns='urn:xmpp:jingle:apps:rtp:rtcp-fb:0' type='transport-cc'/><rtcp-fb xmlns='urn:xmpp:jingle:apps:rtp:rtcp-fb:0' t$2020-08-28 23:41:07.095 INFO: [30] [confId=2e214850638dd328 epId=469c08b3 gid=286857 stats_id=Ernestina-BCM conf_name=y] DtlsTransport.setSetupAttribute#124: The remote side is acting as DTLS server, we'll act as client
2020-08-28 23:41:07.096 INFO: [30] [confId=2e214850638dd328 epId=469c08b3 local_ufrag=4efcp1egrn4apr gid=286857 stats_id=Ernestina-BCM conf_name=y] IceTransport.startConnectivityEstablishment#182: Starting the Agent without remote candidates.
2020-08-28 23:41:07.096 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=4efcp1egrn4apr epId=469c08b3 local_ufrag=4efcp1egrn4apr] Agent.startConnectivityEstablishment#753: Start ICE connectivity establishment.
2020-08-28 23:41:07.096 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=4efcp1egrn4apr epId=469c08b3 local_ufrag=4efcp1egrn4apr] Agent.initCheckLists#996: Init checklist for stream stream-469c08b3
2020-08-28 23:41:07.097 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=4efcp1egrn4apr epId=469c08b3 local_ufrag=4efcp1egrn4apr] Agent.setState#963: ICE state changed from Waiting to Running.
2020-08-28 23:41:07.097 INFO: [30] [confId=2e214850638dd328 epId=469c08b3 local_ufrag=4efcp1egrn4apr gid=286857 stats_id=Ernestina-BCM conf_name=y] IceTransport.iceStateChanged#321: ICE state changed old=Waiting new=Running
2020-08-28 23:41:07.097 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=4efcp1egrn4apr epId=469c08b3 local_ufrag=4efcp1egrn4apr] Agent.startConnectivityEstablishment#775: Trigger checks for pairs that were received before running state
2020-08-28 23:41:07.097 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=4efcp1egrn4apr epId=469c08b3 local_ufrag=4efcp1egrn4apr] Agent.triggerCheck#1761: Add peer CandidatePair with new reflexive address to checkList: CandidatePair (State=Frozen Priority=7962116751041232895):
        LocalCandidate=candidate:1 1 udp 2130706431 10.0.11.4 10000 typ host
        RemoteCandidate=candidate:10000 1 udp 1853824767 72.138.65.206 43730 typ prflx
2020-08-28 23:41:07.097 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=4efcp1egrn4apr epId=469c08b3 local_ufrag=4efcp1egrn4apr] ConnectivityCheckClient.startChecks#142: Start connectivity checks.
2020-08-28 23:41:07.098 FINE: [30] XmppCommon.handleIQ#154: SENT: <iq to='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' from='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTY4NABcDlH/2mo/auZqYMCWG5S9' type='result'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' name='y'><content name='audio'><channel endpoint='469c08b3' id='f7b8a2aa44a4d728' initiator='true' channel-bundle-id='469c08b3' last-n='-1' rtp-level-relay-type='translator'><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='3545881939'/></channel></content><content name='video'><channel endpoint='469c08b3' id='36833d80ed536cb5' initiator='true' channel-bundle-id='469c08b3' last-n='-1' rtp-level-relay-type='translator'><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='611726534'/></channel></content><channel-bundle id='469c08b3'><transport xmlns='urn:xmpp:jingle:transports:ice-udp:1' pwd='67ghdpmspin82tv3e0floulqns' ufrag='4efcp1egrn4apr'><rtcp-mux/><fingerprint xmlns='urn:xmpp:jingle:apps:dtls:0' setup='active' hash='sha-256'>0A:EF:49:6E:1F:15:C8:90:7F:A5:F2:DE:4E:22:5C:72:7E:FB:98:95:60:0B:61:3E:42:29:B3:E3:C9:96:68:CF</fingerprint><candidate component='1' foundation='1' generation='0' id='493486e3667b20210400dff23' network='0' $2020-08-28 23:41:07.103 FINE: [30] XmppCommon.handleIQ#147: RECV: <iq to='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' from='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTY4OABcDlH/2mo/auZqYMCWG5S9' type='set'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' gid='46089' name='y'><channel-bundle id='469c08b3'><transport xmlns='urn:xmpp:jingle:transports:ice-udp:1' pwd='OjtAR47wCF7JdY6au6fAWSaX' ufrag='BfYU'><rtcp-mux xmlns='urn:xmpp:jingle:transports:ice-udp:1'/><fingerprint xmlns='urn:xmpp:jingle:apps:dtls:0' hash='sha-256' required='true'>F7:CA:A9:93:9B:06:5A:E8:17:37:66:67:30:CE:A2:DE:4C:D3:86:43:5A:05:3A:4D:A8:DE:F3:F1:72:F9:34:AB</fingerprint><candidate xmlns='urn:xmpp:jingle:transports:ice-udp:1' type='host' network='1' id='i2720sgxny' ip='192.168.1.104' component='1' port='52003' foundation='1019731727' generation='0' priority='2122260223' protocol='udp'/><candidate xmlns='urn:xmpp:jingle:transports:ice-udp:1' type='host' network='1' id='1xbk07z7ch' ip='10.40.125.195' component='1' port='52004' foundation='2151505277' generation='0' priority='2122194687' protocol='udp'/><candidate xmlns='urn:xmpp:jingle:transports:ice-udp:1' type='host' network='1' id='j1cjegaz0a' ip='192.168.56.1' compon$2020-08-28 23:41:07.104 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM componentId=1 conf_name=y ufrag=4efcp1egrn4apr name=stream-469c08b3 epId=469c08b3 local_ufrag=4efcp1egrn4apr] Component.addUpdateRemoteCandidates#347: Update remote candidate for stream-469c08b3.RTP: 192.168.1.104:52003/udp
2020-08-28 23:41:07.104 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM componentId=1 conf_name=y ufrag=4efcp1egrn4apr name=stream-469c08b3 epId=469c08b3 local_ufrag=4efcp1egrn4apr] Component.addUpdateRemoteCandidates#347: Update remote candidate for stream-469c08b3.RTP: 10.40.125.195:52004/udp
2020-08-28 23:41:07.104 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM componentId=1 conf_name=y ufrag=4efcp1egrn4apr name=stream-469c08b3 epId=469c08b3 local_ufrag=4efcp1egrn4apr] Component.addUpdateRemoteCandidates#347: Update remote candidate for stream-469c08b3.RTP: 192.168.56.1:52005/udp
2020-08-28 23:41:07.105 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM componentId=1 conf_name=y ufrag=4efcp1egrn4apr name=stream-469c08b3 epId=469c08b3 local_ufrag=4efcp1egrn4apr] Component.updateRemoteCandidates#481: new Pair added: 10.0.11.4:10000/udp/host -> 192.168.1.104:52003/udp/host (stream-469c08b3.RTP).
2020-08-28 23:41:07.105 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM componentId=1 conf_name=y ufrag=4efcp1egrn4apr name=stream-469c08b3 epId=469c08b3 local_ufrag=4efcp1egrn4apr] Component.updateRemoteCandidates#481: new Pair added: 10.0.11.4:10000/udp/host -> 10.40.125.195:52004/udp/host (stream-469c08b3.RTP).
2020-08-28 23:41:07.105 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM componentId=1 conf_name=y ufrag=4efcp1egrn4apr name=stream-469c08b3 epId=469c08b3 local_ufrag=4efcp1egrn4apr] Component.updateRemoteCandidates#481: new Pair added: 10.0.11.4:10000/udp/host -> 192.168.56.1:52005/udp/host (stream-469c08b3.RTP).
2020-08-28 23:41:07.105 FINE: [30] XmppCommon.handleIQ#154: SENT: <iq to='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' from='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTY4OABcDlH/2mo/auZqYMCWG5S9' type='result'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' name='y'><channel-bundle id='469c08b3'><transport xmlns='urn:xmpp:jingle:transports:ice-udp:1' pwd='67ghdpmspin82tv3e0floulqns' ufrag='4efcp1egrn4apr'><rtcp-mux/><fingerprint xmlns='urn:xmpp:jingle:apps:dtls:0' setup='active' hash='sha-256'>0A:EF:49:6E:1F:15:C8:90:7F:A5:F2:DE:4E:22:5C:72:7E:FB:98:95:60:0B:61:3E:42:29:B3:E3:C9:96:68:CF</fingerprint><candidate component='1' foundation='1' generation='0' id='75841a7c667b20210400dff23' network='0' priority='2130706431' protocol='udp' type='host' ip='10.0.11.4' port='10000'/><candidate component='1' foundation='2' generation='0' id='223a2225667b202106af914a1' network='0' priority='1694498815' protocol='udp' type='srflx' ip='52.235.32.130' port='10000' rel-addr='10.0.11.4' rel-port='10000'/></transport></channel-bundle><endpoint id='fa204af2' stats-id='Ernestina-BCM'/><endpoint id='6c4f0f6c' stats-id='Ernestina-BCM'/><endpoint id='469c08b3' stats-id='Ernestina-BCM'/></conference></iq>
2020-08-28 23:41:07.135 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=4efcp1egrn4apr epId=469c08b3 local_ufrag=4efcp1egrn4apr] ConnectivityCheckClient.processSuccessResponse#630: Pair succeeded: 10.0.11.4:10000/udp/host -> 72.138.65.206:43730/udp/prflx (stream-469c08b3.RTP).
2020-08-28 23:41:07.135 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM componentId=1 conf_name=y ufrag=4efcp1egrn4apr name=stream-469c08b3 epId=469c08b3 local_ufrag=4efcp1egrn4apr] ComponentSocket.addAuthorizedAddress#99: Adding allowed address: 72.138.65.206:43730/udp
2020-08-28 23:41:07.135 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=4efcp1egrn4apr epId=469c08b3 local_ufrag=4efcp1egrn4apr] ConnectivityCheckClient.processSuccessResponse#639: Pair validated: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:43730/udp/prflx (stream-469c08b3.RTP).
2020-08-28 23:41:07.135 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=4efcp1egrn4apr epId=469c08b3 local_ufrag=4efcp1egrn4apr] DefaultNominator.strategyNominateFirstValid#142: Nominate (first valid): 52.235.32.130:10000/udp/srflx -> 72.138.65.206:43730/udp/prflx (stream-469c08b3.RTP).
2020-08-28 23:41:07.135 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=4efcp1egrn4apr epId=469c08b3 local_ufrag=4efcp1egrn4apr] Agent.nominate#1834: verify if nominated pair answer again
2020-08-28 23:41:07.135 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=4efcp1egrn4apr epId=469c08b3 local_ufrag=4efcp1egrn4apr] ConnectivityCheckClient.processSuccessResponse#708: IsControlling: true USE-CANDIDATE:false.
2020-08-28 23:41:07.136 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=4efcp1egrn4apr epId=469c08b3 local_ufrag=4efcp1egrn4apr] ConnectivityCheckClient.processSuccessResponse#630: Pair succeeded: 10.0.11.4:10000/udp/host -> 72.138.65.206:43730/udp/prflx (stream-469c08b3.RTP).
2020-08-28 23:41:07.136 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=4efcp1egrn4apr epId=469c08b3 local_ufrag=4efcp1egrn4apr] ConnectivityCheckClient.processSuccessResponse#639: Pair validated: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:43730/udp/prflx (stream-469c08b3.RTP).
2020-08-28 23:41:07.137 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=4efcp1egrn4apr epId=469c08b3 local_ufrag=4efcp1egrn4apr] ConnectivityCheckClient.processSuccessResponse#708: IsControlling: true USE-CANDIDATE:false.
2020-08-28 23:41:07.140 INFO: [49] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=4efcp1egrn4apr epId=469c08b3 local_ufrag=4efcp1egrn4apr] ConnectivityCheckClient$PaceMaker.run#922: Pair failed: 10.0.11.4:10000/udp/host -> 192.168.1.104:52003/udp/host (stream-469c08b3.RTP)
2020-08-28 23:41:07.156 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=4efcp1egrn4apr epId=469c08b3 local_ufrag=4efcp1egrn4apr] ConnectivityCheckClient.processSuccessResponse#630: Pair succeeded: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:43730/udp/prflx (stream-469c08b3.RTP).
2020-08-28 23:41:07.157 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=4efcp1egrn4apr epId=469c08b3 local_ufrag=4efcp1egrn4apr] ConnectivityCheckClient.processSuccessResponse#639: Pair validated: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:43730/udp/prflx (stream-469c08b3.RTP).
2020-08-28 23:41:07.157 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=4efcp1egrn4apr epId=469c08b3 local_ufrag=4efcp1egrn4apr] ConnectivityCheckClient.processSuccessResponse#708: IsControlling: true USE-CANDIDATE:true.
2020-08-28 23:41:07.157 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=4efcp1egrn4apr epId=469c08b3 local_ufrag=4efcp1egrn4apr] ConnectivityCheckClient.processSuccessResponse#723: Nomination confirmed for pair: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:43730/udp/prflx (stream-469c08b3.RTP).
2020-08-28 23:41:07.157 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=4efcp1egrn4apr name=stream-469c08b3 epId=469c08b3 local_ufrag=4efcp1egrn4apr] CheckList.handleNominationConfirmed#406: Selected pair for stream stream-469c08b3.RTP: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:43730/udp/prflx (stream-469c08b3.RTP)
2020-08-28 23:41:07.157 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=4efcp1egrn4apr epId=469c08b3 local_ufrag=4efcp1egrn4apr] Agent.checkListStatesUpdated#1925: CheckList of stream stream-469c08b3 is COMPLETED
2020-08-28 23:41:07.157 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=4efcp1egrn4apr epId=469c08b3 local_ufrag=4efcp1egrn4apr] Agent.setState#963: ICE state changed from Running to Completed.
2020-08-28 23:41:07.158 INFO: [48] [confId=2e214850638dd328 epId=469c08b3 local_ufrag=4efcp1egrn4apr gid=286857 stats_id=Ernestina-BCM conf_name=y] IceTransport.iceStateChanged#321: ICE state changed old=Running new=Completed
2020-08-28 23:41:07.158 INFO: [48] [confId=2e214850638dd328 epId=469c08b3 gid=286857 stats_id=Ernestina-BCM conf_name=y] Endpoint$3.connected#377: ICE connected
2020-08-28 23:41:07.158 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=4efcp1egrn4apr epId=469c08b3 local_ufrag=4efcp1egrn4apr] Agent.logCandTypes#2033: Harvester used for selected pair for stream-469c08b3.RTP: srflx
2020-08-28 23:41:07.158 INFO: [57] [confId=2e214850638dd328 epId=469c08b3 gid=286857 stats_id=Ernestina-BCM conf_name=y] DtlsTransport.startDtlsHandshake#102: Starting DTLS handshake
2020-08-28 23:41:07.175 INFO: [57] [confId=2e214850638dd328 epId=469c08b3 gid=286857 stats_id=Ernestina-BCM conf_name=y] TlsClientImpl.notifyServerVersion#165: Negotiated DTLS version DTLS 1.2
2020-08-28 23:41:07.199 INFO: [57] [confId=2e214850638dd328 epId=469c08b3 gid=286857 stats_id=Ernestina-BCM conf_name=y] Endpoint.lambda$setupDtlsTransport$2#404: DTLS handshake complete
2020-08-28 23:41:07.201 INFO: [58] [confId=2e214850638dd328 epId=469c08b3 gid=286857 stats_id=Ernestina-BCM conf_name=y] Endpoint.lambda$acceptSctpConnection$8#902: Attempting to establish SCTP socket connection
2020-08-28 23:41:08.110 FINE: [30] XmppCommon.handleIQ#147: RECV: <iq to='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' from='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTY5NgBcDlH/2mo/auZqYMCWG5S9' type='set'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' gid='46089' name='y'><content name='audio'><channel endpoint='49ec848c' initiator='true' channel-bundle-id='49ec848c' last-n='-1'><payload-type name='opus' clockrate='48000' id='111' channels='2'><rtcp-fb xmlns='urn:xmpp:jingle:apps:rtp:rtcp-fb:0' type='transport-cc'/><parameter value='10' name='minptime'/><parameter value='1' name='useinbandfec'/></payload-type><payload-type id='103' name='ISAC' clockrate='16000'/><payload-type id='104' name='ISAC' clockrate='32000'/><payload-type id='126' name='telephone-event' clockrate='8000'/><rtp-hdrext id='1' uri='urn:ietf:params:rtp-hdrext:ssrc-audio-level'/><rtp-hdrext id='5' uri='http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01'/></channel></content><content name='video'><channel endpoint='49ec848c' initiator='true' channel-bundle-id='49ec848c' last-n='-1'><payload-type id='100' name='VP8' clockrate='90000'><rtcp-fb xmlns='urn:xmpp:jingle:apps:rtp:rtcp-fb:0' type='ccm' sub$2020-08-28 23:41:08.115 INFO: [30] [confId=2e214850638dd328 epId=49ec848c local_ufrag=anbtl1egrn4fki gid=286857 conf_name=y ufrag=anbtl1egrn4fki] Agent.gatherCandidates#662: Gathering candidates for component stream-49ec848c.RTP.
2020-08-28 23:41:08.118 INFO: [30] [confId=2e214850638dd328 epId=49ec848c gid=286857 conf_name=y] Endpoint.lambda$setTransportInfo$11#1043: Ignoring empty DtlsFingerprint extension: <transport xmlns='urn:xmpp:jingle:transports:ice-udp:1'><fingerprint xmlns='urn:xmpp:jingle:apps:dtls:0' required='false'/></transport>
2020-08-28 23:41:08.120 FINE: [30] XmppCommon.handleIQ#154: SENT: <iq to='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' from='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTY5NgBcDlH/2mo/auZqYMCWG5S9' type='result'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' name='y'><content name='audio'><channel endpoint='49ec848c' id='7bdfef7108b762a2' initiator='true' channel-bundle-id='49ec848c' last-n='-1' rtp-level-relay-type='translator'><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='3545881939'/></channel></content><content name='video'><channel endpoint='49ec848c' id='a1428ef0df9e438e' initiator='true' channel-bundle-id='49ec848c' last-n='-1' rtp-level-relay-type='translator'><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='611726534'/></channel></content><content name='data'><sctpconnection endpoint='49ec848c' id='1263c173e4bbfa22' initiator='true' channel-bundle-id='49ec848c' port='5000'/></content><channel-bundle id='49ec848c'><transport xmlns='urn:xmpp:jingle:transports:ice-udp:1' pwd='2qlgh5460qh6ssnh1eh7hf0lck' ufrag='anbtl1egrn4fki'><rtcp-mux/><fingerprint xmlns='urn:xmpp:jingle:apps:dtls:0' setup='actpass' hash='sha-256'>0A:EF:49:6E:1F:15:C8:90:7F:A5:F2:DE:4E:22:5C:72:7E:FB:98:9$2020-08-28 23:41:08.712 FINE: [30] XmppCommon.handleIQ#147: RECV: <iq to='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' from='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTcwMQBcDlH/2mo/auZqYMCWG5S9' type='get'><healthcheck xmlns='http://jitsi.org/protocol/healthcheck'/></iq>
2020-08-28 23:41:08.712 FINE: [30] XmppCommon.handleIQ#154: SENT: <iq to='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' from='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTcwMQBcDlH/2mo/auZqYMCWG5S9' type='result'></iq>
2020-08-28 23:41:08.796 INFO: [44] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=8m2h1egrn4cr4 epId=6c4f0f6c local_ufrag=8m2h1egrn4cr4] Agent.setState#963: ICE state changed from Completed to Terminated.
2020-08-28 23:41:08.796 INFO: [44] [confId=2e214850638dd328 epId=6c4f0f6c local_ufrag=8m2h1egrn4cr4 gid=286857 stats_id=Ernestina-BCM conf_name=y] IceTransport.iceStateChanged#321: ICE state changed old=Completed new=Terminated
2020-08-28 23:41:09.186 INFO: [44] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=2l67k1egrn4ar8 epId=fa204af2 local_ufrag=2l67k1egrn4ar8] Agent.setState#963: ICE state changed from Completed to Terminated.
2020-08-28 23:41:09.187 INFO: [44] [confId=2e214850638dd328 epId=fa204af2 local_ufrag=2l67k1egrn4ar8 gid=286857 stats_id=Ernestina-BCM conf_name=y] IceTransport.iceStateChanged#321: ICE state changed old=Completed new=Terminated
Got sctp association state update: 1
sctp is now up.  was ready? false
2020-08-28 23:41:09.368 INFO: [50] [confId=2e214850638dd328 epId=6c4f0f6c gid=286857 stats_id=Ernestina-BCM conf_name=y] Endpoint$4.onReady#844: SCTP connection is ready, creating the Data channel stack
2020-08-28 23:41:09.372 INFO: [50] [confId=2e214850638dd328 epId=6c4f0f6c gid=286857 stats_id=Ernestina-BCM conf_name=y] Endpoint$4.onReady#871: Will wait for the remote side to open the data channel.
2020-08-28 23:41:09.374 INFO: [65] [confId=2e214850638dd328 epId=6c4f0f6c gid=286857 stats_id=Ernestina-BCM conf_name=y] DataChannelStack.onIncomingDataChannelPacket#62: Received data channel open message
2020-08-28 23:41:09.376 INFO: [65] [confId=2e214850638dd328 epId=6c4f0f6c gid=286857 stats_id=Ernestina-BCM conf_name=y] Endpoint$4.lambda$onReady$1#852: Remote side opened a data channel.
Got sctp association state update: 1
sctp is now up.  was ready? false
2020-08-28 23:41:09.748 INFO: [52] [confId=2e214850638dd328 epId=fa204af2 gid=286857 stats_id=Ernestina-BCM conf_name=y] Endpoint$4.onReady#844: SCTP connection is ready, creating the Data channel stack
2020-08-28 23:41:09.748 INFO: [52] [confId=2e214850638dd328 epId=fa204af2 gid=286857 stats_id=Ernestina-BCM conf_name=y] Endpoint$4.onReady#871: Will wait for the remote side to open the data channel.
2020-08-28 23:41:09.748 INFO: [71] [confId=2e214850638dd328 epId=fa204af2 gid=286857 stats_id=Ernestina-BCM conf_name=y] DataChannelStack.onIncomingDataChannelPacket#62: Received data channel open message
2020-08-28 23:41:09.749 INFO: [71] [confId=2e214850638dd328 epId=fa204af2 gid=286857 stats_id=Ernestina-BCM conf_name=y] Endpoint$4.lambda$onReady$1#852: Remote side opened a data channel.
2020-08-28 23:41:10.158 INFO: [44] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=4efcp1egrn4apr epId=469c08b3 local_ufrag=4efcp1egrn4apr] Agent.setState#963: ICE state changed from Completed to Terminated.
2020-08-28 23:41:10.159 INFO: [44] [confId=2e214850638dd328 epId=469c08b3 local_ufrag=4efcp1egrn4apr gid=286857 stats_id=Ernestina-BCM conf_name=y] IceTransport.iceStateChanged#321: ICE state changed old=Completed new=Terminated
Got sctp association state update: 1
sctp is now up.  was ready? false
2020-08-28 23:41:10.705 INFO: [58] [confId=2e214850638dd328 epId=469c08b3 gid=286857 stats_id=Ernestina-BCM conf_name=y] Endpoint$4.onReady#844: SCTP connection is ready, creating the Data channel stack
2020-08-28 23:41:10.706 INFO: [58] [confId=2e214850638dd328 epId=469c08b3 gid=286857 stats_id=Ernestina-BCM conf_name=y] Endpoint$4.onReady#871: Will wait for the remote side to open the data channel.
2020-08-28 23:41:10.706 INFO: [64] [confId=2e214850638dd328 epId=469c08b3 gid=286857 stats_id=Ernestina-BCM conf_name=y] DataChannelStack.onIncomingDataChannelPacket#62: Received data channel open message
2020-08-28 23:41:10.706 INFO: [64] [confId=2e214850638dd328 epId=469c08b3 gid=286857 stats_id=Ernestina-BCM conf_name=y] Endpoint$4.lambda$onReady$1#852: Remote side opened a data channel.
2020-08-28 23:41:11.081 FINE: [30] XmppCommon.handleIQ#147: RECV: <iq to='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' from='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTcxMABcDlH/2mo/auZqYMCWG5S9' type='set'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' gid='46089' name='y'><content name='audio'><channel id='7bdfef7108b762a2'><payload-type name='opus' channels='2' id='111' clockrate='48000'><rtcp-fb xmlns='urn:xmpp:jingle:apps:rtp:rtcp-fb:0' type='transport-cc'/><parameter value='10' name='minptime'/><parameter value='1' name='useinbandfec'/></payload-type><payload-type name='ISAC' channels='1' id='103' clockrate='16000'/><payload-type name='ISAC' channels='1' id='104' clockrate='32000'/><payload-type name='telephone-event' channels='1' id='126' clockrate='8000'/><rtp-hdrext id='1' uri='urn:ietf:params:rtp-hdrext:ssrc-audio-level'/><rtp-hdrext id='5' uri='http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01'/></channel></content><content name='video'><channel id='a1428ef0df9e438e'><payload-type name='VP8' channels='1' id='100' clockrate='90000'><rtcp-fb xmlns='urn:xmpp:jingle:apps:rtp:rtcp-fb:0' type='transport-cc'/><rtcp-fb xmlns='urn:xmpp:jingle:apps:rtp:rtcp-fb:0' t$2020-08-28 23:41:11.082 FINE: [43] XmppCommon.handleIQ#147: RECV: <iq to='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' from='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTcxNQBcDlH/2mo/auZqYMCWG5S9' type='set'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' gid='46089' name='y'><channel-bundle id='49ec848c'><transport xmlns='urn:xmpp:jingle:transports:ice-udp:1' pwd='azIKr7xIbJzALMJllvIcXhAV' ufrag='qmVy'><rtcp-mux xmlns='urn:xmpp:jingle:transports:ice-udp:1'/><fingerprint xmlns='urn:xmpp:jingle:apps:dtls:0' hash='sha-256' required='true'>B7:A8:62:96:88:97:A5:A6:2F:FA:67:21:F5:92:F0:77:2B:E7:58:C1:46:11:01:23:61:4E:D2:8A:CA:68:EE:8F</fingerprint><candidate xmlns='urn:xmpp:jingle:transports:ice-udp:1' type='host' network='1' id='ter7jzrtog' ip='192.168.1.104' component='1' port='55876' foundation='1019731727' generation='0' priority='2122260223' protocol='udp'/><candidate xmlns='urn:xmpp:jingle:transports:ice-udp:1' type='host' network='1' id='9bbf2g2u8b' ip='192.168.1.104' component='1' port='55876' foundation='1019731727' generation='0' priority='2122260223' protocol='udp'/><candidate xmlns='urn:xmpp:jingle:transports:ice-udp:1' type='host' network='1' id='8tq18soqzs' ip='10.40.125.195' compo$2020-08-28 23:41:11.083 INFO: [43] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM componentId=1 conf_name=y ufrag=anbtl1egrn4fki name=stream-49ec848c epId=49ec848c local_ufrag=anbtl1egrn4fki] Component.addRemoteCandidate#330: Add remote candidate for stream-49ec848c.RTP: 192.168.1.104:55876/udp/host
2020-08-28 23:41:11.083 INFO: [43] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM componentId=1 conf_name=y ufrag=anbtl1egrn4fki name=stream-49ec848c epId=49ec848c local_ufrag=anbtl1egrn4fki] Component.addRemoteCandidate#330: Add remote candidate for stream-49ec848c.RTP: 192.168.1.104:55876/udp/host
2020-08-28 23:41:11.083 INFO: [30] [confId=2e214850638dd328 epId=49ec848c gid=286857 stats_id=Ernestina-BCM conf_name=y] DtlsTransport.setSetupAttribute#124: The remote side is acting as DTLS server, we'll act as client
2020-08-28 23:41:11.083 INFO: [43] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM componentId=1 conf_name=y ufrag=anbtl1egrn4fki name=stream-49ec848c epId=49ec848c local_ufrag=anbtl1egrn4fki] Component.addRemoteCandidate#330: Add remote candidate for stream-49ec848c.RTP: 10.40.125.195:55877/udp/host
2020-08-28 23:41:11.083 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM componentId=1 conf_name=y ufrag=anbtl1egrn4fki name=stream-49ec848c epId=49ec848c local_ufrag=anbtl1egrn4fki] Component.addRemoteCandidate#330: Add remote candidate for stream-49ec848c.RTP: 192.168.1.104:55876/udp/host
2020-08-28 23:41:11.084 INFO: [43] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM componentId=1 conf_name=y ufrag=anbtl1egrn4fki name=stream-49ec848c epId=49ec848c local_ufrag=anbtl1egrn4fki] Component.addRemoteCandidate#330: Add remote candidate for stream-49ec848c.RTP: 192.168.56.1:55878/udp/host
2020-08-28 23:41:11.084 INFO: [43] [confId=2e214850638dd328 epId=49ec848c local_ufrag=anbtl1egrn4fki gid=286857 stats_id=Ernestina-BCM conf_name=y] IceTransport.startConnectivityEstablishment#176: Starting the agent with remote candidates.
2020-08-28 23:41:11.084 INFO: [43] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=anbtl1egrn4fki epId=49ec848c local_ufrag=anbtl1egrn4fki] Agent.startConnectivityEstablishment#753: Start ICE connectivity establishment.
2020-08-28 23:41:11.085 INFO: [30] [confId=2e214850638dd328 epId=49ec848c local_ufrag=anbtl1egrn4fki gid=286857 stats_id=Ernestina-BCM conf_name=y] IceTransport.startConnectivityEstablishment#176: Starting the agent with remote candidates.
2020-08-28 23:41:11.085 INFO: [43] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=anbtl1egrn4fki epId=49ec848c local_ufrag=anbtl1egrn4fki] Agent.initCheckLists#996: Init checklist for stream stream-49ec848c
2020-08-28 23:41:11.085 INFO: [43] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=anbtl1egrn4fki epId=49ec848c local_ufrag=anbtl1egrn4fki] Agent.setState#963: ICE state changed from Waiting to Running.
2020-08-28 23:41:11.086 INFO: [43] [confId=2e214850638dd328 epId=49ec848c local_ufrag=anbtl1egrn4fki gid=286857 stats_id=Ernestina-BCM conf_name=y] IceTransport.iceStateChanged#321: ICE state changed old=Waiting new=Running
2020-08-28 23:41:11.086 INFO: [43] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=anbtl1egrn4fki epId=49ec848c local_ufrag=anbtl1egrn4fki] Agent.startConnectivityEstablishment#775: Trigger checks for pairs that were received before running state
2020-08-28 23:41:11.086 INFO: [43] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=anbtl1egrn4fki epId=49ec848c local_ufrag=anbtl1egrn4fki] Agent.triggerCheck#1761: Add peer CandidatePair with new reflexive address to checkList: CandidatePair (State=Frozen Priority=7962116751041232895):
        LocalCandidate=candidate:1 1 udp 2130706431 10.0.11.4 10000 typ host
        RemoteCandidate=candidate:10000 1 udp 1853824767 72.138.65.206 11494 typ prflx
2020-08-28 23:41:11.087 INFO: [43] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=anbtl1egrn4fki epId=49ec848c local_ufrag=anbtl1egrn4fki] ConnectivityCheckClient.startChecks#142: Start connectivity checks.
2020-08-28 23:41:11.087 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=anbtl1egrn4fki epId=49ec848c local_ufrag=anbtl1egrn4fki] Agent.startConnectivityEstablishment#753: Start ICE connectivity establishment.
2020-08-28 23:41:11.087 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=anbtl1egrn4fki epId=49ec848c local_ufrag=anbtl1egrn4fki] Agent.initCheckLists#996: Init checklist for stream stream-49ec848c
2020-08-28 23:41:11.088 FINE: [43] XmppCommon.handleIQ#154: SENT: <iq to='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' from='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTcxNQBcDlH/2mo/auZqYMCWG5S9' type='result'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' name='y'><channel-bundle id='49ec848c'><transport xmlns='urn:xmpp:jingle:transports:ice-udp:1' pwd='2qlgh5460qh6ssnh1eh7hf0lck' ufrag='anbtl1egrn4fki'><rtcp-mux/><fingerprint xmlns='urn:xmpp:jingle:apps:dtls:0' setup='active' hash='sha-256'>0A:EF:49:6E:1F:15:C8:90:7F:A5:F2:DE:4E:22:5C:72:7E:FB:98:95:60:0B:61:3E:42:29:B3:E3:C9:96:68:CF</fingerprint><candidate component='1' foundation='1' generation='0' id='508ef7d540da9dce0a2ea9cd' network='0' priority='2130706431' protocol='udp' type='host' ip='10.0.11.4' port='10000'/><candidate component='1' foundation='2' generation='0' id='426393ec40da9dce03519bf4b' network='0' priority='1694498815' protocol='udp' type='srflx' ip='52.235.32.130' port='10000' rel-addr='10.0.11.4' rel-port='10000'/></transport></channel-bundle><endpoint id='fa204af2' stats-id='Ernestina-BCM'/><endpoint id='6c4f0f6c' stats-id='Ernestina-BCM'/><endpoint id='49ec848c' stats-id='Ernestina-BCM'/><endpoint id='469c08b3' stat$2020-08-28 23:41:11.088 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=anbtl1egrn4fki epId=49ec848c local_ufrag=anbtl1egrn4fki] ConnectivityCheckClient.startChecks#142: Start connectivity checks.
2020-08-28 23:41:11.089 FINE: [30] XmppCommon.handleIQ#154: SENT: <iq to='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' from='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTcxMABcDlH/2mo/auZqYMCWG5S9' type='result'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' name='y'><content name='audio'><channel endpoint='49ec848c' id='7bdfef7108b762a2' initiator='true' channel-bundle-id='49ec848c' last-n='-1' rtp-level-relay-type='translator'><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='3545881939'/></channel></content><content name='video'><channel endpoint='49ec848c' id='a1428ef0df9e438e' initiator='true' channel-bundle-id='49ec848c' last-n='-1' rtp-level-relay-type='translator'><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='611726534'/></channel></content><channel-bundle id='49ec848c'><transport xmlns='urn:xmpp:jingle:transports:ice-udp:1' pwd='2qlgh5460qh6ssnh1eh7hf0lck' ufrag='anbtl1egrn4fki'><rtcp-mux/><fingerprint xmlns='urn:xmpp:jingle:apps:dtls:0' setup='active' hash='sha-256'>0A:EF:49:6E:1F:15:C8:90:7F:A5:F2:DE:4E:22:5C:72:7E:FB:98:95:60:0B:61:3E:42:29:B3:E3:C9:96:68:CF</fingerprint><candidate component='1' foundation='1' generation='0' id='797c573640da9dce0a2ea9cd' network='0' p$2020-08-28 23:41:11.110 INFO: [49] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=anbtl1egrn4fki epId=49ec848c local_ufrag=anbtl1egrn4fki] ConnectivityCheckClient$PaceMaker.run#922: Pair failed: 10.0.11.4:10000/udp/host -> 192.168.1.104:55876/udp/host (stream-49ec848c.RTP)
2020-08-28 23:41:11.126 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=anbtl1egrn4fki epId=49ec848c local_ufrag=anbtl1egrn4fki] ConnectivityCheckClient.processSuccessResponse#630: Pair succeeded: 10.0.11.4:10000/udp/host -> 72.138.65.206:11494/udp/prflx (stream-49ec848c.RTP).
2020-08-28 23:41:11.126 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM componentId=1 conf_name=y ufrag=anbtl1egrn4fki name=stream-49ec848c epId=49ec848c local_ufrag=anbtl1egrn4fki] ComponentSocket.addAuthorizedAddress#99: Adding allowed address: 72.138.65.206:11494/udp
2020-08-28 23:41:11.126 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=anbtl1egrn4fki epId=49ec848c local_ufrag=anbtl1egrn4fki] ConnectivityCheckClient.processSuccessResponse#639: Pair validated: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:11494/udp/prflx (stream-49ec848c.RTP).
2020-08-28 23:41:11.126 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=anbtl1egrn4fki epId=49ec848c local_ufrag=anbtl1egrn4fki] DefaultNominator.strategyNominateFirstValid#142: Nominate (first valid): 52.235.32.130:10000/udp/srflx -> 72.138.65.206:11494/udp/prflx (stream-49ec848c.RTP).
2020-08-28 23:41:11.127 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=anbtl1egrn4fki epId=49ec848c local_ufrag=anbtl1egrn4fki] Agent.nominate#1834: verify if nominated pair answer again
2020-08-28 23:41:11.127 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=anbtl1egrn4fki epId=49ec848c local_ufrag=anbtl1egrn4fki] ConnectivityCheckClient.processSuccessResponse#708: IsControlling: true USE-CANDIDATE:false.
2020-08-28 23:41:11.130 INFO: [56] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=anbtl1egrn4fki epId=49ec848c local_ufrag=anbtl1egrn4fki] ConnectivityCheckClient$PaceMaker.run#922: Pair failed: 10.0.11.4:10000/udp/host -> 10.40.125.195:55877/udp/host (stream-49ec848c.RTP)
2020-08-28 23:41:11.147 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=anbtl1egrn4fki epId=49ec848c local_ufrag=anbtl1egrn4fki] ConnectivityCheckClient.processSuccessResponse#630: Pair succeeded: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:11494/udp/prflx (stream-49ec848c.RTP).
2020-08-28 23:41:11.147 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=anbtl1egrn4fki epId=49ec848c local_ufrag=anbtl1egrn4fki] ConnectivityCheckClient.processSuccessResponse#639: Pair validated: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:11494/udp/prflx (stream-49ec848c.RTP).
2020-08-28 23:41:11.147 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=anbtl1egrn4fki epId=49ec848c local_ufrag=anbtl1egrn4fki] ConnectivityCheckClient.processSuccessResponse#708: IsControlling: true USE-CANDIDATE:true.
2020-08-28 23:41:11.147 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=anbtl1egrn4fki epId=49ec848c local_ufrag=anbtl1egrn4fki] ConnectivityCheckClient.processSuccessResponse#723: Nomination confirmed for pair: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:11494/udp/prflx (stream-49ec848c.RTP).
2020-08-28 23:41:11.147 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=anbtl1egrn4fki name=stream-49ec848c epId=49ec848c local_ufrag=anbtl1egrn4fki] CheckList.handleNominationConfirmed#406: Selected pair for stream stream-49ec848c.RTP: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:11494/udp/prflx (stream-49ec848c.RTP)
2020-08-28 23:41:11.148 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=anbtl1egrn4fki epId=49ec848c local_ufrag=anbtl1egrn4fki] Agent.checkListStatesUpdated#1925: CheckList of stream stream-49ec848c is COMPLETED
2020-08-28 23:41:11.148 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=anbtl1egrn4fki epId=49ec848c local_ufrag=anbtl1egrn4fki] Agent.setState#963: ICE state changed from Running to Completed.
2020-08-28 23:41:11.148 INFO: [48] [confId=2e214850638dd328 epId=49ec848c local_ufrag=anbtl1egrn4fki gid=286857 stats_id=Ernestina-BCM conf_name=y] IceTransport.iceStateChanged#321: ICE state changed old=Running new=Completed
2020-08-28 23:41:11.148 INFO: [48] [confId=2e214850638dd328 epId=49ec848c gid=286857 stats_id=Ernestina-BCM conf_name=y] Endpoint$3.connected#377: ICE connected
2020-08-28 23:41:11.148 INFO: [64] [confId=2e214850638dd328 epId=49ec848c gid=286857 stats_id=Ernestina-BCM conf_name=y] DtlsTransport.startDtlsHandshake#102: Starting DTLS handshake
2020-08-28 23:41:11.148 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=anbtl1egrn4fki epId=49ec848c local_ufrag=anbtl1egrn4fki] Agent.logCandTypes#2033: Harvester used for selected pair for stream-49ec848c.RTP: srflx
2020-08-28 23:41:11.166 INFO: [64] [confId=2e214850638dd328 epId=49ec848c gid=286857 stats_id=Ernestina-BCM conf_name=y] TlsClientImpl.notifyServerVersion#165: Negotiated DTLS version DTLS 1.2
2020-08-28 23:41:11.190 INFO: [64] [confId=2e214850638dd328 epId=49ec848c gid=286857 stats_id=Ernestina-BCM conf_name=y] Endpoint.lambda$setupDtlsTransport$2#404: DTLS handshake complete
2020-08-28 23:41:11.190 INFO: [58] [confId=2e214850638dd328 epId=49ec848c gid=286857 stats_id=Ernestina-BCM conf_name=y] Endpoint.lambda$acceptSctpConnection$8#902: Attempting to establish SCTP socket connection
Got sctp association state update: 1
sctp is now up.  was ready? false
2020-08-28 23:41:11.291 INFO: [58] [confId=2e214850638dd328 epId=49ec848c gid=286857 stats_id=Ernestina-BCM conf_name=y] Endpoint$4.onReady#844: SCTP connection is ready, creating the Data channel stack
2020-08-28 23:41:11.291 INFO: [58] [confId=2e214850638dd328 epId=49ec848c gid=286857 stats_id=Ernestina-BCM conf_name=y] Endpoint$4.onReady#871: Will wait for the remote side to open the data channel.
2020-08-28 23:41:11.291 INFO: [50] [confId=2e214850638dd328 epId=49ec848c gid=286857 stats_id=Ernestina-BCM conf_name=y] DataChannelStack.onIncomingDataChannelPacket#62: Received data channel open message
2020-08-28 23:41:11.292 INFO: [50] [confId=2e214850638dd328 epId=49ec848c gid=286857 stats_id=Ernestina-BCM conf_name=y] Endpoint$4.lambda$onReady$1#852: Remote side opened a data channel.
2020-08-28 23:41:12.916 FINE: [30] XmppCommon.handleIQ#147: RECV: <iq to='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' from='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTcyMwBcDlH/2mo/auZqYMCWG5S9' type='set'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' gid='46089' name='y'><content name='audio'><channel endpoint='c0811a93' initiator='true' channel-bundle-id='c0811a93' last-n='-1'><payload-type name='opus' clockrate='48000' id='111' channels='2'><rtcp-fb xmlns='urn:xmpp:jingle:apps:rtp:rtcp-fb:0' type='transport-cc'/><parameter value='10' name='minptime'/><parameter value='1' name='useinbandfec'/></payload-type><payload-type id='103' name='ISAC' clockrate='16000'/><payload-type id='104' name='ISAC' clockrate='32000'/><payload-type id='126' name='telephone-event' clockrate='8000'/><rtp-hdrext id='1' uri='urn:ietf:params:rtp-hdrext:ssrc-audio-level'/><rtp-hdrext id='5' uri='http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01'/></channel></content><content name='video'><channel endpoint='c0811a93' initiator='true' channel-bundle-id='c0811a93' last-n='-1'><payload-type id='100' name='VP8' clockrate='90000'><rtcp-fb xmlns='urn:xmpp:jingle:apps:rtp:rtcp-fb:0' type='ccm' sub$2020-08-28 23:41:12.919 INFO: [30] [confId=2e214850638dd328 epId=c0811a93 local_ufrag=5tjm81egrn4kam gid=286857 conf_name=y ufrag=5tjm81egrn4kam] Agent.gatherCandidates#662: Gathering candidates for component stream-c0811a93.RTP.
2020-08-28 23:41:12.921 INFO: [30] [confId=2e214850638dd328 epId=c0811a93 gid=286857 conf_name=y] Endpoint.lambda$setTransportInfo$11#1043: Ignoring empty DtlsFingerprint extension: <transport xmlns='urn:xmpp:jingle:transports:ice-udp:1'><fingerprint xmlns='urn:xmpp:jingle:apps:dtls:0' required='false'/></transport>
2020-08-28 23:41:12.922 FINE: [30] XmppCommon.handleIQ#154: SENT: <iq to='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' from='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTcyMwBcDlH/2mo/auZqYMCWG5S9' type='result'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' name='y'><content name='audio'><channel endpoint='c0811a93' id='e0bccb74bb55ccbd' initiator='true' channel-bundle-id='c0811a93' last-n='-1' rtp-level-relay-type='translator'><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='3545881939'/></channel></content><content name='video'><channel endpoint='c0811a93' id='fe483ea6cc8cd5f5' initiator='true' channel-bundle-id='c0811a93' last-n='-1' rtp-level-relay-type='translator'><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='611726534'/></channel></content><content name='data'><sctpconnection endpoint='c0811a93' id='70b51926a291dfaa' initiator='true' channel-bundle-id='c0811a93' port='5000'/></content><channel-bundle id='c0811a93'><transport xmlns='urn:xmpp:jingle:transports:ice-udp:1' pwd='9str1e318abhitbbrf4nususi' ufrag='5tjm81egrn4kam'><rtcp-mux/><fingerprint xmlns='urn:xmpp:jingle:apps:dtls:0' setup='actpass' hash='sha-256'>0A:EF:49:6E:1F:15:C8:90:7F:A5:F2:DE:4E:22:5C:72:7E:FB:98:95$2020-08-28 23:41:13.796 FINE: [30] XmppCommon.handleIQ#147: RECV: <iq to='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' from='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTczMgBcDlH/2mo/auZqYMCWG5S9' type='set'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' gid='46089' name='y'><content name='audio'><channel id='e0bccb74bb55ccbd'><payload-type name='opus' channels='2' id='111' clockrate='48000'><rtcp-fb xmlns='urn:xmpp:jingle:apps:rtp:rtcp-fb:0' type='transport-cc'/><parameter value='10' name='minptime'/><parameter value='1' name='useinbandfec'/></payload-type><payload-type name='ISAC' channels='1' id='103' clockrate='16000'/><payload-type name='ISAC' channels='1' id='104' clockrate='32000'/><payload-type name='telephone-event' channels='1' id='126' clockrate='8000'/><rtp-hdrext id='1' uri='urn:ietf:params:rtp-hdrext:ssrc-audio-level'/><rtp-hdrext id='5' uri='http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01'/><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='2437823026'><parameter xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' value='XUVVi8Ob4K7xNsaQ-1' name='cname'/><parameter xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' value='0a46e379-4733-4944-9c1b-2649282d7fc9-1 eee60d4c-$2020-08-28 23:41:13.799 FINE: [43] XmppCommon.handleIQ#147: RECV: <iq to='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' from='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTczOABcDlH/2mo/auZqYMCWG5S9' type='set'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' gid='46089' name='y'><channel-bundle id='c0811a93'><transport xmlns='urn:xmpp:jingle:transports:ice-udp:1' pwd='uRNgTGi6e1AnxgmYVUCjVqIx' ufrag='0RuT'><rtcp-mux xmlns='urn:xmpp:jingle:transports:ice-udp:1'/><fingerprint xmlns='urn:xmpp:jingle:apps:dtls:0' hash='sha-256' required='true'>6F:7E:BF:E5:73:BE:A4:FD:1E:AC:EB:54:12:FC:C1:88:9D:C2:07:42:1E:14:C7:FE:6D:A0:1E:21:C2:B9:46:0A</fingerprint><candidate xmlns='urn:xmpp:jingle:transports:ice-udp:1' type='host' network='1' id='85bsovcn84' ip='192.168.1.105' component='1' port='57626' foundation='2222700650' generation='0' priority='2122260223' protocol='udp'/></transport></channel-bundle></conference></iq>
2020-08-28 23:41:13.799 INFO: [43] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM componentId=1 conf_name=y ufrag=5tjm81egrn4kam name=stream-c0811a93 epId=c0811a93 local_ufrag=5tjm81egrn4kam] Component.addRemoteCandidate#330: Add remote candidate for stream-c0811a93.RTP: 192.168.1.105:57626/udp/host
2020-08-28 23:41:13.799 INFO: [43] [confId=2e214850638dd328 epId=c0811a93 local_ufrag=5tjm81egrn4kam gid=286857 stats_id=Nickolas-EqM conf_name=y] IceTransport.startConnectivityEstablishment#176: Starting the agent with remote candidates.
2020-08-28 23:41:13.800 INFO: [43] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=5tjm81egrn4kam epId=c0811a93 local_ufrag=5tjm81egrn4kam] Agent.startConnectivityEstablishment#753: Start ICE connectivity establishment.
2020-08-28 23:41:13.800 INFO: [43] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=5tjm81egrn4kam epId=c0811a93 local_ufrag=5tjm81egrn4kam] Agent.initCheckLists#996: Init checklist for stream stream-c0811a93
2020-08-28 23:41:13.800 INFO: [43] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=5tjm81egrn4kam epId=c0811a93 local_ufrag=5tjm81egrn4kam] Agent.setState#963: ICE state changed from Waiting to Running.
2020-08-28 23:41:13.801 INFO: [43] [confId=2e214850638dd328 epId=c0811a93 local_ufrag=5tjm81egrn4kam gid=286857 stats_id=Nickolas-EqM conf_name=y] IceTransport.iceStateChanged#321: ICE state changed old=Waiting new=Running
2020-08-28 23:41:13.801 INFO: [43] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=5tjm81egrn4kam epId=c0811a93 local_ufrag=5tjm81egrn4kam] Agent.startConnectivityEstablishment#775: Trigger checks for pairs that were received before running state
2020-08-28 23:41:13.801 INFO: [43] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=5tjm81egrn4kam epId=c0811a93 local_ufrag=5tjm81egrn4kam] Agent.triggerCheck#1761: Add peer CandidatePair with new reflexive address to checkList: CandidatePair (State=Frozen Priority=7962116751041232895):
        LocalCandidate=candidate:1 1 udp 2130706431 10.0.11.4 10000 typ host
        RemoteCandidate=candidate:10000 1 udp 1853824767 72.138.65.206 13589 typ prflx
2020-08-28 23:41:13.801 INFO: [43] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=5tjm81egrn4kam epId=c0811a93 local_ufrag=5tjm81egrn4kam] ConnectivityCheckClient.startChecks#142: Start connectivity checks.
2020-08-28 23:41:13.801 FINE: [43] XmppCommon.handleIQ#154: SENT: <iq to='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' from='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTczOABcDlH/2mo/auZqYMCWG5S9' type='result'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' name='y'><channel-bundle id='c0811a93'><transport xmlns='urn:xmpp:jingle:transports:ice-udp:1' pwd='9str1e318abhitbbrf4nususi' ufrag='5tjm81egrn4kam'><rtcp-mux/><fingerprint xmlns='urn:xmpp:jingle:apps:dtls:0' setup='actpass' hash='sha-256'>0A:EF:49:6E:1F:15:C8:90:7F:A5:F2:DE:4E:22:5C:72:7E:FB:98:95:60:0B:61:3E:42:29:B3:E3:C9:96:68:CF</fingerprint><candidate component='1' foundation='1' generation='0' id='350aa9a777e145d205fb7d673' network='0' priority='2130706431' protocol='udp' type='host' ip='10.0.11.4' port='10000'/><candidate component='1' foundation='2' generation='0' id='43affe4477e145d20ffffffff8aa2ebf1' network='0' priority='1694498815' protocol='udp' type='srflx' ip='52.235.32.130' port='10000' rel-addr='10.0.11.4' rel-port='10000'/></transport></channel-bundle><endpoint id='fa204af2' stats-id='Ernestina-BCM'/><endpoint id='c0811a93' stats-id='Nickolas-EqM'/><endpoint id='6c4f0f6c' stats-id='Ernestina-BCM'/><endpoint id='49ec84$2020-08-28 23:41:13.827 INFO: [30] [confId=2e214850638dd328 epId=c0811a93 gid=286857 stats_id=Nickolas-EqM conf_name=y] DtlsTransport.setSetupAttribute#124: The remote side is acting as DTLS server, we'll act as client
2020-08-28 23:41:13.832 FINE: [30] XmppCommon.handleIQ#154: SENT: <iq to='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' from='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTczMgBcDlH/2mo/auZqYMCWG5S9' type='result'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' name='y'><content name='audio'><channel endpoint='c0811a93' id='e0bccb74bb55ccbd' initiator='true' channel-bundle-id='c0811a93' last-n='-1' rtp-level-relay-type='translator'><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='3545881939'/><ssrc>2437823026</ssrc></channel></content><content name='video'><channel endpoint='c0811a93' id='fe483ea6cc8cd5f5' initiator='true' channel-bundle-id='c0811a93' last-n='-1' rtp-level-relay-type='translator'><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='611726534'/><ssrc-group xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' semantics='FID'><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='1463863792'/><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='1441310154'/></ssrc-group><ssrc-group xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' semantics='FID'><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='1045073985'/><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='2084522332'/></ssrc-group><ssrc-$2020-08-28 23:41:13.840 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=5tjm81egrn4kam epId=c0811a93 local_ufrag=5tjm81egrn4kam] ConnectivityCheckClient.processSuccessResponse#630: Pair succeeded: 10.0.11.4:10000/udp/host -> 72.138.65.206:13589/udp/prflx (stream-c0811a93.RTP).
2020-08-28 23:41:13.840 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM componentId=1 conf_name=y ufrag=5tjm81egrn4kam name=stream-c0811a93 epId=c0811a93 local_ufrag=5tjm81egrn4kam] ComponentSocket.addAuthorizedAddress#99: Adding allowed address: 72.138.65.206:13589/udp
2020-08-28 23:41:13.840 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=5tjm81egrn4kam epId=c0811a93 local_ufrag=5tjm81egrn4kam] ConnectivityCheckClient.processSuccessResponse#639: Pair validated: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:13589/udp/prflx (stream-c0811a93.RTP).
2020-08-28 23:41:13.840 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=5tjm81egrn4kam epId=c0811a93 local_ufrag=5tjm81egrn4kam] DefaultNominator.strategyNominateFirstValid#142: Nominate (first valid): 52.235.32.130:10000/udp/srflx -> 72.138.65.206:13589/udp/prflx (stream-c0811a93.RTP).
2020-08-28 23:41:13.840 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=5tjm81egrn4kam epId=c0811a93 local_ufrag=5tjm81egrn4kam] Agent.nominate#1834: verify if nominated pair answer again
2020-08-28 23:41:13.841 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=5tjm81egrn4kam epId=c0811a93 local_ufrag=5tjm81egrn4kam] ConnectivityCheckClient.processSuccessResponse#708: IsControlling: true USE-CANDIDATE:false.
2020-08-28 23:41:13.862 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=5tjm81egrn4kam epId=c0811a93 local_ufrag=5tjm81egrn4kam] ConnectivityCheckClient.processSuccessResponse#630: Pair succeeded: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:13589/udp/prflx (stream-c0811a93.RTP).
2020-08-28 23:41:13.863 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=5tjm81egrn4kam epId=c0811a93 local_ufrag=5tjm81egrn4kam] ConnectivityCheckClient.processSuccessResponse#639: Pair validated: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:13589/udp/prflx (stream-c0811a93.RTP).
2020-08-28 23:41:13.863 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=5tjm81egrn4kam epId=c0811a93 local_ufrag=5tjm81egrn4kam] ConnectivityCheckClient.processSuccessResponse#708: IsControlling: true USE-CANDIDATE:true.
2020-08-28 23:41:13.863 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=5tjm81egrn4kam epId=c0811a93 local_ufrag=5tjm81egrn4kam] ConnectivityCheckClient.processSuccessResponse#723: Nomination confirmed for pair: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:13589/udp/prflx (stream-c0811a93.RTP).
2020-08-28 23:41:13.863 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=5tjm81egrn4kam name=stream-c0811a93 epId=c0811a93 local_ufrag=5tjm81egrn4kam] CheckList.handleNominationConfirmed#406: Selected pair for stream stream-c0811a93.RTP: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:13589/udp/prflx (stream-c0811a93.RTP)
2020-08-28 23:41:13.863 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=5tjm81egrn4kam epId=c0811a93 local_ufrag=5tjm81egrn4kam] Agent.checkListStatesUpdated#1925: CheckList of stream stream-c0811a93 is COMPLETED
2020-08-28 23:41:13.863 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=5tjm81egrn4kam epId=c0811a93 local_ufrag=5tjm81egrn4kam] Agent.setState#963: ICE state changed from Running to Completed.
2020-08-28 23:41:13.863 INFO: [48] [confId=2e214850638dd328 epId=c0811a93 local_ufrag=5tjm81egrn4kam gid=286857 stats_id=Nickolas-EqM conf_name=y] IceTransport.iceStateChanged#321: ICE state changed old=Running new=Completed
2020-08-28 23:41:13.863 INFO: [48] [confId=2e214850638dd328 epId=c0811a93 gid=286857 stats_id=Nickolas-EqM conf_name=y] Endpoint$3.connected#377: ICE connected
2020-08-28 23:41:13.863 INFO: [50] [confId=2e214850638dd328 epId=c0811a93 gid=286857 stats_id=Nickolas-EqM conf_name=y] DtlsTransport.startDtlsHandshake#102: Starting DTLS handshake
2020-08-28 23:41:13.864 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=5tjm81egrn4kam epId=c0811a93 local_ufrag=5tjm81egrn4kam] Agent.logCandTypes#2033: Harvester used for selected pair for stream-c0811a93.RTP: srflx
2020-08-28 23:41:13.882 INFO: [50] [confId=2e214850638dd328 epId=c0811a93 gid=286857 stats_id=Nickolas-EqM conf_name=y] TlsClientImpl.notifyServerVersion#165: Negotiated DTLS version DTLS 1.2
2020-08-28 23:41:13.885 INFO: [19] Videobridge.createConference#255: create_conf, id=7a247ca0b012e77 gid=-1 logging=false
2020-08-28 23:41:13.895 INFO: [19] AbstractHealthCheckService.run#182: Performed a successful health check in PT0.011S. Sticky failure: false
2020-08-28 23:41:13.908 INFO: [50] [confId=2e214850638dd328 epId=c0811a93 gid=286857 stats_id=Nickolas-EqM conf_name=y] Endpoint.lambda$setupDtlsTransport$2#404: DTLS handshake complete
2020-08-28 23:41:13.909 INFO: [58] [confId=2e214850638dd328 epId=c0811a93 gid=286857 stats_id=Nickolas-EqM conf_name=y] Endpoint.lambda$acceptSctpConnection$8#902: Attempting to establish SCTP socket connection
Got sctp association state update: 1
sctp is now up.  was ready? false
2020-08-28 23:41:13.950 INFO: [50] [confId=2e214850638dd328 gid=286857 conf_name=y] Conference.dominantSpeakerChanged#464: ds_change ds_id=2e214850638dd328
2020-08-28 23:41:14.009 INFO: [58] [confId=2e214850638dd328 epId=c0811a93 gid=286857 stats_id=Nickolas-EqM conf_name=y] Endpoint$4.onReady#844: SCTP connection is ready, creating the Data channel stack
2020-08-28 23:41:14.010 INFO: [58] [confId=2e214850638dd328 epId=c0811a93 gid=286857 stats_id=Nickolas-EqM conf_name=y] Endpoint$4.onReady#871: Will wait for the remote side to open the data channel.
2020-08-28 23:41:14.010 SEVERE: [52] [confId=2e214850638dd328 epId=c0811a93 gid=286857 stats_id=Nickolas-EqM conf_name=y] DataChannelStack.onIncomingDataChannelPacket#81: Could not find data channel for sid 1
2020-08-28 23:41:14.010 SEVERE: [52] [confId=2e214850638dd328 epId=c0811a93 gid=286857 stats_id=Nickolas-EqM conf_name=y] DataChannelStack.onIncomingDataChannelPacket#81: Could not find data channel for sid 1
2020-08-28 23:41:14.010 SEVERE: [52] [confId=2e214850638dd328 epId=c0811a93 gid=286857 stats_id=Nickolas-EqM conf_name=y] DataChannelStack.onIncomingDataChannelPacket#81: Could not find data channel for sid 1
2020-08-28 23:41:14.010 SEVERE: [52] [confId=2e214850638dd328 epId=c0811a93 gid=286857 stats_id=Nickolas-EqM conf_name=y] DataChannelStack.onIncomingDataChannelPacket#81: Could not find data channel for sid 1
2020-08-28 23:41:14.010 INFO: [52] [confId=2e214850638dd328 epId=c0811a93 gid=286857 stats_id=Nickolas-EqM conf_name=y] DataChannelStack.onIncomingDataChannelPacket#62: Received data channel open message
2020-08-28 23:41:14.011 INFO: [52] [confId=2e214850638dd328 epId=c0811a93 gid=286857 stats_id=Nickolas-EqM conf_name=y] Endpoint$4.lambda$onReady$1#852: Remote side opened a data channel.
2020-08-28 23:41:14.148 INFO: [44] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=anbtl1egrn4fki epId=49ec848c local_ufrag=anbtl1egrn4fki] Agent.setState#963: ICE state changed from Completed to Terminated.
2020-08-28 23:41:14.149 INFO: [44] [confId=2e214850638dd328 epId=49ec848c local_ufrag=anbtl1egrn4fki gid=286857 stats_id=Ernestina-BCM conf_name=y] IceTransport.iceStateChanged#321: ICE state changed old=Completed new=Terminated
2020-08-28 23:41:16.864 INFO: [44] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=5tjm81egrn4kam epId=c0811a93 local_ufrag=5tjm81egrn4kam] Agent.setState#963: ICE state changed from Completed to Terminated.
2020-08-28 23:41:16.864 INFO: [44] [confId=2e214850638dd328 epId=c0811a93 local_ufrag=5tjm81egrn4kam gid=286857 stats_id=Nickolas-EqM conf_name=y] IceTransport.iceStateChanged#321: ICE state changed old=Completed new=Terminated
2020-08-28 23:41:18.679 FINE: [30] XmppCommon.handleIQ#147: RECV: <iq to='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' from='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTc0OQBcDlH/2mo/auZqYMCWG5S9' type='get'><healthcheck xmlns='http://jitsi.org/protocol/healthcheck'/></iq>
2020-08-28 23:41:18.679 FINE: [30] XmppCommon.handleIQ#154: SENT: <iq to='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' from='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTc0OQBcDlH/2mo/auZqYMCWG5S9' type='result'></iq>
2020-08-28 23:41:19.863 FINE: [30] XmppCommon.handleIQ#147: RECV: <iq to='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' from='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTc1NgBcDlH/2mo/auZqYMCWG5S9' type='set'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' gid='46089' name='y'><content name='audio'><channel endpoint='b4d10dc5' initiator='true' channel-bundle-id='b4d10dc5' last-n='-1'><payload-type name='opus' clockrate='48000' id='111' channels='2'><rtcp-fb xmlns='urn:xmpp:jingle:apps:rtp:rtcp-fb:0' type='transport-cc'/><parameter value='10' name='minptime'/><parameter value='1' name='useinbandfec'/></payload-type><payload-type id='103' name='ISAC' clockrate='16000'/><payload-type id='104' name='ISAC' clockrate='32000'/><payload-type id='126' name='telephone-event' clockrate='8000'/><rtp-hdrext id='1' uri='urn:ietf:params:rtp-hdrext:ssrc-audio-level'/><rtp-hdrext id='5' uri='http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01'/></channel></content><content name='video'><channel endpoint='b4d10dc5' initiator='true' channel-bundle-id='b4d10dc5' last-n='-1'><payload-type id='100' name='VP8' clockrate='90000'><rtcp-fb xmlns='urn:xmpp:jingle:apps:rtp:rtcp-fb:0' type='ccm' sub$2020-08-28 23:41:19.867 INFO: [30] [confId=2e214850638dd328 epId=b4d10dc5 local_ufrag=6bm1h1egrn4r3q gid=286857 conf_name=y ufrag=6bm1h1egrn4r3q] Agent.gatherCandidates#662: Gathering candidates for component stream-b4d10dc5.RTP.
2020-08-28 23:41:19.869 INFO: [30] [confId=2e214850638dd328 epId=b4d10dc5 gid=286857 conf_name=y] Endpoint.lambda$setTransportInfo$11#1043: Ignoring empty DtlsFingerprint extension: <transport xmlns='urn:xmpp:jingle:transports:ice-udp:1'><fingerprint xmlns='urn:xmpp:jingle:apps:dtls:0' required='false'/></transport>
2020-08-28 23:41:19.870 FINE: [30] XmppCommon.handleIQ#154: SENT: <iq to='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' from='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTc1NgBcDlH/2mo/auZqYMCWG5S9' type='result'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' name='y'><content name='audio'><channel endpoint='b4d10dc5' id='4ac8f26f28af96ad' initiator='true' channel-bundle-id='b4d10dc5' last-n='-1' rtp-level-relay-type='translator'><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='3545881939'/></channel></content><content name='video'><channel endpoint='b4d10dc5' id='bcc67d48d997628' initiator='true' channel-bundle-id='b4d10dc5' last-n='-1' rtp-level-relay-type='translator'><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='611726534'/></channel></content><content name='data'><sctpconnection endpoint='b4d10dc5' id='37af913b8001ad7' initiator='true' channel-bundle-id='b4d10dc5' port='5000'/></content><channel-bundle id='b4d10dc5'><transport xmlns='urn:xmpp:jingle:transports:ice-udp:1' pwd='4i8gdjun1tdr1d3gb4culc5u0k' ufrag='6bm1h1egrn4r3q'><rtcp-mux/><fingerprint xmlns='urn:xmpp:jingle:apps:dtls:0' setup='actpass' hash='sha-256'>0A:EF:49:6E:1F:15:C8:90:7F:A5:F2:DE:4E:22:5C:72:7E:FB:98:95:$2020-08-28 23:41:21.198 FINE: [30] XmppCommon.handleIQ#147: RECV: <iq to='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' from='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTc2NQBcDlH/2mo/auZqYMCWG5S9' type='set'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' gid='46089' name='y'><content name='audio'><channel id='4ac8f26f28af96ad'><payload-type name='opus' channels='2' id='111' clockrate='48000'><rtcp-fb xmlns='urn:xmpp:jingle:apps:rtp:rtcp-fb:0' type='transport-cc'/><parameter value='10' name='minptime'/><parameter value='1' name='useinbandfec'/></payload-type><payload-type name='ISAC' channels='1' id='103' clockrate='16000'/><payload-type name='ISAC' channels='1' id='104' clockrate='32000'/><payload-type name='telephone-event' channels='1' id='126' clockrate='8000'/><rtp-hdrext id='1' uri='urn:ietf:params:rtp-hdrext:ssrc-audio-level'/><rtp-hdrext id='5' uri='http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01'/><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='628426354'><parameter xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' value='Ruu0L6AYmnbKBQq-1' name='cname'/><parameter xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' value='4cd3671c-1d8f-4075-90df-7e232343ff2d-1 047f41ff-a2$2020-08-28 23:41:21.205 INFO: [30] [confId=2e214850638dd328 epId=b4d10dc5 gid=286857 stats_id=Nickolas-EqM conf_name=y] DtlsTransport.setSetupAttribute#124: The remote side is acting as DTLS server, we'll act as client
2020-08-28 23:41:21.205 INFO: [30] [confId=2e214850638dd328 epId=b4d10dc5 local_ufrag=6bm1h1egrn4r3q gid=286857 stats_id=Nickolas-EqM conf_name=y] IceTransport.startConnectivityEstablishment#182: Starting the Agent without remote candidates.
2020-08-28 23:41:21.205 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=6bm1h1egrn4r3q epId=b4d10dc5 local_ufrag=6bm1h1egrn4r3q] Agent.startConnectivityEstablishment#753: Start ICE connectivity establishment.
2020-08-28 23:41:21.205 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=6bm1h1egrn4r3q epId=b4d10dc5 local_ufrag=6bm1h1egrn4r3q] Agent.initCheckLists#996: Init checklist for stream stream-b4d10dc5
2020-08-28 23:41:21.205 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=6bm1h1egrn4r3q epId=b4d10dc5 local_ufrag=6bm1h1egrn4r3q] Agent.setState#963: ICE state changed from Waiting to Running.
2020-08-28 23:41:21.205 INFO: [30] [confId=2e214850638dd328 epId=b4d10dc5 local_ufrag=6bm1h1egrn4r3q gid=286857 stats_id=Nickolas-EqM conf_name=y] IceTransport.iceStateChanged#321: ICE state changed old=Waiting new=Running
2020-08-28 23:41:21.206 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=6bm1h1egrn4r3q epId=b4d10dc5 local_ufrag=6bm1h1egrn4r3q] Agent.startConnectivityEstablishment#775: Trigger checks for pairs that were received before running state
2020-08-28 23:41:21.206 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=6bm1h1egrn4r3q epId=b4d10dc5 local_ufrag=6bm1h1egrn4r3q] Agent.triggerCheck#1761: Add peer CandidatePair with new reflexive address to checkList: CandidatePair (State=Frozen Priority=7962116751041232895):
        LocalCandidate=candidate:1 1 udp 2130706431 10.0.11.4 10000 typ host
        RemoteCandidate=candidate:10000 1 udp 1853824767 72.138.65.206 10921 typ prflx
2020-08-28 23:41:21.206 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=6bm1h1egrn4r3q epId=b4d10dc5 local_ufrag=6bm1h1egrn4r3q] ConnectivityCheckClient.startChecks#142: Start connectivity checks.
2020-08-28 23:41:21.207 FINE: [30] XmppCommon.handleIQ#154: SENT: <iq to='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' from='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTc2NQBcDlH/2mo/auZqYMCWG5S9' type='result'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' name='y'><content name='audio'><channel endpoint='b4d10dc5' id='4ac8f26f28af96ad' initiator='true' channel-bundle-id='b4d10dc5' last-n='-1' rtp-level-relay-type='translator'><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='3545881939'/><ssrc>628426354</ssrc></channel></content><content name='video'><channel endpoint='b4d10dc5' id='bcc67d48d997628' initiator='true' channel-bundle-id='b4d10dc5' last-n='-1' rtp-level-relay-type='translator'><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='611726534'/><ssrc-group xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' semantics='FID'><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='4050934387'/><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='836812533'/></ssrc-group><ssrc-group xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' semantics='FID'><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='2973363420'/><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='978625210'/></ssrc-group><ssrc-grou$2020-08-28 23:41:21.210 FINE: [30] XmppCommon.handleIQ#147: RECV: <iq to='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' from='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTc3MgBcDlH/2mo/auZqYMCWG5S9' type='set'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' gid='46089' name='y'><channel-bundle id='b4d10dc5'><transport xmlns='urn:xmpp:jingle:transports:ice-udp:1' pwd='stzAXIAhS3iG409im42/szZO' ufrag='/xoA'><rtcp-mux xmlns='urn:xmpp:jingle:transports:ice-udp:1'/><fingerprint xmlns='urn:xmpp:jingle:apps:dtls:0' hash='sha-256' required='true'>9C:A8:2A:16:AE:D0:FB:71:A2:9C:CD:DA:76:63:35:5A:FD:13:0B:84:43:3C:16:10:EE:13:7B:95:26:BC:02:C3</fingerprint><candidate xmlns='urn:xmpp:jingle:transports:ice-udp:1' type='host' network='1' id='r3kes8or3m' ip='192.168.1.105' component='1' port='57642' foundation='2222700650' generation='0' priority='2122260223' protocol='udp'/></transport></channel-bundle></conference></iq>
2020-08-28 23:41:21.210 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM componentId=1 conf_name=y ufrag=6bm1h1egrn4r3q name=stream-b4d10dc5 epId=b4d10dc5 local_ufrag=6bm1h1egrn4r3q] Component.addUpdateRemoteCandidates#347: Update remote candidate for stream-b4d10dc5.RTP: 192.168.1.105:57642/udp
2020-08-28 23:41:21.210 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM componentId=1 conf_name=y ufrag=6bm1h1egrn4r3q name=stream-b4d10dc5 epId=b4d10dc5 local_ufrag=6bm1h1egrn4r3q] Component.updateRemoteCandidates#481: new Pair added: 10.0.11.4:10000/udp/host -> 192.168.1.105:57642/udp/host (stream-b4d10dc5.RTP).
2020-08-28 23:41:21.211 FINE: [30] XmppCommon.handleIQ#154: SENT: <iq to='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' from='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTc3MgBcDlH/2mo/auZqYMCWG5S9' type='result'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' name='y'><channel-bundle id='b4d10dc5'><transport xmlns='urn:xmpp:jingle:transports:ice-udp:1' pwd='4i8gdjun1tdr1d3gb4culc5u0k' ufrag='6bm1h1egrn4r3q'><rtcp-mux/><fingerprint xmlns='urn:xmpp:jingle:apps:dtls:0' setup='active' hash='sha-256'>0A:EF:49:6E:1F:15:C8:90:7F:A5:F2:DE:4E:22:5C:72:7E:FB:98:95:60:0B:61:3E:42:29:B3:E3:C9:96:68:CF</fingerprint><candidate component='1' foundation='1' generation='0' id='6ab1b5426e0e609401a279217' network='0' priority='2130706431' protocol='udp' type='host' ip='10.0.11.4' port='10000'/><candidate component='1' foundation='2' generation='0' id='6e48a8c46e0e609404512a795' network='0' priority='1694498815' protocol='udp' type='srflx' ip='52.235.32.130' port='10000' rel-addr='10.0.11.4' rel-port='10000'/></transport></channel-bundle><endpoint id='b4d10dc5' stats-id='Nickolas-EqM'/><endpoint id='fa204af2' stats-id='Ernestina-BCM'/><endpoint id='c0811a93' stats-id='Nickolas-EqM'/><endpoint id='6c4f0f6c' stats$2020-08-28 23:41:21.244 FINE: [30] XmppCommon.handleIQ#147: RECV: <iq to='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' from='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTc3NwBcDlH/2mo/auZqYMCWG5S9' type='set'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' gid='46089' name='y'><content name='audio'><channel endpoint='bc7cfb53' initiator='true' channel-bundle-id='bc7cfb53' last-n='-1'><payload-type name='opus' clockrate='48000' id='111' channels='2'><rtcp-fb xmlns='urn:xmpp:jingle:apps:rtp:rtcp-fb:0' type='transport-cc'/><parameter value='10' name='minptime'/><parameter value='1' name='useinbandfec'/></payload-type><payload-type id='103' name='ISAC' clockrate='16000'/><payload-type id='104' name='ISAC' clockrate='32000'/><payload-type id='126' name='telephone-event' clockrate='8000'/><rtp-hdrext id='1' uri='urn:ietf:params:rtp-hdrext:ssrc-audio-level'/><rtp-hdrext id='5' uri='http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01'/></channel></content><content name='video'><channel endpoint='bc7cfb53' initiator='true' channel-bundle-id='bc7cfb53' last-n='-1'><payload-type id='100' name='VP8' clockrate='90000'><rtcp-fb xmlns='urn:xmpp:jingle:apps:rtp:rtcp-fb:0' type='ccm' sub$2020-08-28 23:41:21.246 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=6bm1h1egrn4r3q epId=b4d10dc5 local_ufrag=6bm1h1egrn4r3q] ConnectivityCheckClient.processSuccessResponse#630: Pair succeeded: 10.0.11.4:10000/udp/host -> 72.138.65.206:10921/udp/prflx (stream-b4d10dc5.RTP).
2020-08-28 23:41:21.246 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM componentId=1 conf_name=y ufrag=6bm1h1egrn4r3q name=stream-b4d10dc5 epId=b4d10dc5 local_ufrag=6bm1h1egrn4r3q] ComponentSocket.addAuthorizedAddress#99: Adding allowed address: 72.138.65.206:10921/udp
2020-08-28 23:41:21.247 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=6bm1h1egrn4r3q epId=b4d10dc5 local_ufrag=6bm1h1egrn4r3q] ConnectivityCheckClient.processSuccessResponse#639: Pair validated: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:10921/udp/prflx (stream-b4d10dc5.RTP).
2020-08-28 23:41:21.247 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=6bm1h1egrn4r3q epId=b4d10dc5 local_ufrag=6bm1h1egrn4r3q] DefaultNominator.strategyNominateFirstValid#142: Nominate (first valid): 52.235.32.130:10000/udp/srflx -> 72.138.65.206:10921/udp/prflx (stream-b4d10dc5.RTP).
2020-08-28 23:41:21.247 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=6bm1h1egrn4r3q epId=b4d10dc5 local_ufrag=6bm1h1egrn4r3q] Agent.nominate#1834: verify if nominated pair answer again
2020-08-28 23:41:21.247 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=6bm1h1egrn4r3q epId=b4d10dc5 local_ufrag=6bm1h1egrn4r3q] ConnectivityCheckClient.processSuccessResponse#708: IsControlling: true USE-CANDIDATE:false.
2020-08-28 23:41:21.247 INFO: [28] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=6bm1h1egrn4r3q epId=b4d10dc5 local_ufrag=6bm1h1egrn4r3q] ConnectivityCheckClient.processSuccessResponse#630: Pair succeeded: 10.0.11.4:10000/udp/host -> 72.138.65.206:10921/udp/prflx (stream-b4d10dc5.RTP).
2020-08-28 23:41:21.247 INFO: [28] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=6bm1h1egrn4r3q epId=b4d10dc5 local_ufrag=6bm1h1egrn4r3q] ConnectivityCheckClient.processSuccessResponse#639: Pair validated: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:10921/udp/prflx (stream-b4d10dc5.RTP).
2020-08-28 23:41:21.248 INFO: [28] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=6bm1h1egrn4r3q epId=b4d10dc5 local_ufrag=6bm1h1egrn4r3q] ConnectivityCheckClient.processSuccessResponse#708: IsControlling: true USE-CANDIDATE:false.
2020-08-28 23:41:21.251 INFO: [49] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=6bm1h1egrn4r3q epId=b4d10dc5 local_ufrag=6bm1h1egrn4r3q] ConnectivityCheckClient$PaceMaker.run#922: Pair failed: 10.0.11.4:10000/udp/host -> 192.168.1.105:57642/udp/host (stream-b4d10dc5.RTP)
2020-08-28 23:41:21.253 INFO: [30] [confId=2e214850638dd328 epId=bc7cfb53 local_ufrag=97tpi1egrn4sev gid=286857 conf_name=y ufrag=97tpi1egrn4sev] Agent.gatherCandidates#662: Gathering candidates for component stream-bc7cfb53.RTP.
2020-08-28 23:41:21.256 INFO: [30] [confId=2e214850638dd328 epId=bc7cfb53 gid=286857 conf_name=y] Endpoint.lambda$setTransportInfo$11#1043: Ignoring empty DtlsFingerprint extension: <transport xmlns='urn:xmpp:jingle:transports:ice-udp:1'><fingerprint xmlns='urn:xmpp:jingle:apps:dtls:0' required='false'/></transport>
2020-08-28 23:41:21.257 FINE: [30] XmppCommon.handleIQ#154: SENT: <iq to='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' from='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTc3NwBcDlH/2mo/auZqYMCWG5S9' type='result'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' name='y'><content name='audio'><channel endpoint='bc7cfb53' id='fb7568cfe80f0194' initiator='true' channel-bundle-id='bc7cfb53' last-n='-1' rtp-level-relay-type='translator'><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='3545881939'/></channel></content><content name='video'><channel endpoint='bc7cfb53' id='7e629873849b8a88' initiator='true' channel-bundle-id='bc7cfb53' last-n='-1' rtp-level-relay-type='translator'><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='611726534'/></channel></content><content name='data'><sctpconnection endpoint='bc7cfb53' id='2a274a9fcc64b9c9' initiator='true' channel-bundle-id='bc7cfb53' port='5000'/></content><channel-bundle id='bc7cfb53'><transport xmlns='urn:xmpp:jingle:transports:ice-udp:1' pwd='g98j6r5oacj89lii10vc0lqi0' ufrag='97tpi1egrn4sev'><rtcp-mux/><fingerprint xmlns='urn:xmpp:jingle:apps:dtls:0' setup='actpass' hash='sha-256'>0A:EF:49:6E:1F:15:C8:90:7F:A5:F2:DE:4E:22:5C:72:7E:FB:98:95$2020-08-28 23:41:21.267 INFO: [28] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=6bm1h1egrn4r3q epId=b4d10dc5 local_ufrag=6bm1h1egrn4r3q] ConnectivityCheckClient.processSuccessResponse#630: Pair succeeded: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:10921/udp/prflx (stream-b4d10dc5.RTP).
2020-08-28 23:41:21.267 INFO: [28] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=6bm1h1egrn4r3q epId=b4d10dc5 local_ufrag=6bm1h1egrn4r3q] ConnectivityCheckClient.processSuccessResponse#639: Pair validated: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:10921/udp/prflx (stream-b4d10dc5.RTP).
2020-08-28 23:41:21.267 INFO: [28] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=6bm1h1egrn4r3q epId=b4d10dc5 local_ufrag=6bm1h1egrn4r3q] ConnectivityCheckClient.processSuccessResponse#708: IsControlling: true USE-CANDIDATE:true.
2020-08-28 23:41:21.267 INFO: [28] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=6bm1h1egrn4r3q epId=b4d10dc5 local_ufrag=6bm1h1egrn4r3q] ConnectivityCheckClient.processSuccessResponse#723: Nomination confirmed for pair: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:10921/udp/prflx (stream-b4d10dc5.RTP).
2020-08-28 23:41:21.268 INFO: [28] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=6bm1h1egrn4r3q name=stream-b4d10dc5 epId=b4d10dc5 local_ufrag=6bm1h1egrn4r3q] CheckList.handleNominationConfirmed#406: Selected pair for stream stream-b4d10dc5.RTP: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:10921/udp/prflx (stream-b4d10dc5.RTP)
2020-08-28 23:41:21.268 INFO: [28] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=6bm1h1egrn4r3q epId=b4d10dc5 local_ufrag=6bm1h1egrn4r3q] Agent.checkListStatesUpdated#1925: CheckList of stream stream-b4d10dc5 is COMPLETED
2020-08-28 23:41:21.268 INFO: [28] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=6bm1h1egrn4r3q epId=b4d10dc5 local_ufrag=6bm1h1egrn4r3q] Agent.setState#963: ICE state changed from Running to Completed.
2020-08-28 23:41:21.268 INFO: [28] [confId=2e214850638dd328 epId=b4d10dc5 local_ufrag=6bm1h1egrn4r3q gid=286857 stats_id=Nickolas-EqM conf_name=y] IceTransport.iceStateChanged#321: ICE state changed old=Running new=Completed
2020-08-28 23:41:21.268 INFO: [28] [confId=2e214850638dd328 epId=b4d10dc5 gid=286857 stats_id=Nickolas-EqM conf_name=y] Endpoint$3.connected#377: ICE connected
2020-08-28 23:41:21.268 INFO: [28] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=6bm1h1egrn4r3q epId=b4d10dc5 local_ufrag=6bm1h1egrn4r3q] Agent.logCandTypes#2033: Harvester used for selected pair for stream-b4d10dc5.RTP: srflx
2020-08-28 23:41:21.269 INFO: [65] [confId=2e214850638dd328 epId=b4d10dc5 gid=286857 stats_id=Nickolas-EqM conf_name=y] DtlsTransport.startDtlsHandshake#102: Starting DTLS handshake
2020-08-28 23:41:21.287 INFO: [65] [confId=2e214850638dd328 epId=b4d10dc5 gid=286857 stats_id=Nickolas-EqM conf_name=y] TlsClientImpl.notifyServerVersion#165: Negotiated DTLS version DTLS 1.2
2020-08-28 23:41:21.311 INFO: [65] [confId=2e214850638dd328 epId=b4d10dc5 gid=286857 stats_id=Nickolas-EqM conf_name=y] Endpoint.lambda$setupDtlsTransport$2#404: DTLS handshake complete
2020-08-28 23:41:21.311 INFO: [64] [confId=2e214850638dd328 epId=b4d10dc5 gid=286857 stats_id=Nickolas-EqM conf_name=y] Endpoint.lambda$acceptSctpConnection$8#902: Attempting to establish SCTP socket connection
Got sctp association state update: 1
sctp is now up.  was ready? false
2020-08-28 23:41:21.412 INFO: [64] [confId=2e214850638dd328 epId=b4d10dc5 gid=286857 stats_id=Nickolas-EqM conf_name=y] Endpoint$4.onReady#844: SCTP connection is ready, creating the Data channel stack
2020-08-28 23:41:21.412 INFO: [64] [confId=2e214850638dd328 epId=b4d10dc5 gid=286857 stats_id=Nickolas-EqM conf_name=y] Endpoint$4.onReady#871: Will wait for the remote side to open the data channel.
2020-08-28 23:41:21.412 INFO: [58] [confId=2e214850638dd328 epId=b4d10dc5 gid=286857 stats_id=Nickolas-EqM conf_name=y] DataChannelStack.onIncomingDataChannelPacket#62: Received data channel open message
2020-08-28 23:41:21.412 INFO: [58] [confId=2e214850638dd328 epId=b4d10dc5 gid=286857 stats_id=Nickolas-EqM conf_name=y] Endpoint$4.lambda$onReady$1#852: Remote side opened a data channel.
2020-08-28 23:41:22.870 FINE: [30] XmppCommon.handleIQ#147: RECV: <iq to='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' from='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTc4NwBcDlH/2mo/auZqYMCWG5S9' type='set'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' gid='46089' name='y'><content name='audio'><channel endpoint='ac71d18a' initiator='true' channel-bundle-id='ac71d18a' last-n='-1'><payload-type name='opus' clockrate='48000' id='111' channels='2'><rtcp-fb xmlns='urn:xmpp:jingle:apps:rtp:rtcp-fb:0' type='transport-cc'/><parameter value='10' name='minptime'/><parameter value='1' name='useinbandfec'/></payload-type><payload-type id='103' name='ISAC' clockrate='16000'/><payload-type id='104' name='ISAC' clockrate='32000'/><payload-type id='126' name='telephone-event' clockrate='8000'/><rtp-hdrext id='1' uri='urn:ietf:params:rtp-hdrext:ssrc-audio-level'/><rtp-hdrext id='5' uri='http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01'/></channel></content><content name='video'><channel endpoint='ac71d18a' initiator='true' channel-bundle-id='ac71d18a' last-n='-1'><payload-type id='100' name='VP8' clockrate='90000'><rtcp-fb xmlns='urn:xmpp:jingle:apps:rtp:rtcp-fb:0' type='ccm' sub$2020-08-28 23:41:22.893 INFO: [30] [confId=2e214850638dd328 epId=ac71d18a local_ufrag=9a2r31egrn4u2c gid=286857 conf_name=y ufrag=9a2r31egrn4u2c] Agent.gatherCandidates#662: Gathering candidates for component stream-ac71d18a.RTP.
2020-08-28 23:41:22.895 INFO: [30] [confId=2e214850638dd328 epId=ac71d18a gid=286857 conf_name=y] Endpoint.lambda$setTransportInfo$11#1043: Ignoring empty DtlsFingerprint extension: <transport xmlns='urn:xmpp:jingle:transports:ice-udp:1'><fingerprint xmlns='urn:xmpp:jingle:apps:dtls:0' required='false'/></transport>
2020-08-28 23:41:22.897 FINE: [30] XmppCommon.handleIQ#154: SENT: <iq to='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' from='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTc4NwBcDlH/2mo/auZqYMCWG5S9' type='result'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' name='y'><content name='audio'><channel endpoint='ac71d18a' id='28696e16fc89ccba' initiator='true' channel-bundle-id='ac71d18a' last-n='-1' rtp-level-relay-type='translator'><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='3545881939'/></channel></content><content name='video'><channel endpoint='ac71d18a' id='1c429f4b2c1db391' initiator='true' channel-bundle-id='ac71d18a' last-n='-1' rtp-level-relay-type='translator'><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='611726534'/></channel></content><content name='data'><sctpconnection endpoint='ac71d18a' id='c0532c31ec110750' initiator='true' channel-bundle-id='ac71d18a' port='5000'/></content><channel-bundle id='ac71d18a'><transport xmlns='urn:xmpp:jingle:transports:ice-udp:1' pwd='1i2v4736kv9bvfdfhqndbgpkah' ufrag='9a2r31egrn4u2c'><rtcp-mux/><fingerprint xmlns='urn:xmpp:jingle:apps:dtls:0' setup='actpass' hash='sha-256'>0A:EF:49:6E:1F:15:C8:90:7F:A5:F2:DE:4E:22:5C:72:7E:FB:98:9$2020-08-28 23:41:22.918 FINE: [30] XmppCommon.handleIQ#147: RECV: <iq to='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' from='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTc5MABcDlH/2mo/auZqYMCWG5S9' type='set'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' gid='46089' name='y'><content name='audio'><channel id='fb7568cfe80f0194'><payload-type name='opus' channels='2' id='111' clockrate='48000'><rtcp-fb xmlns='urn:xmpp:jingle:apps:rtp:rtcp-fb:0' type='transport-cc'/><parameter value='10' name='minptime'/><parameter value='1' name='useinbandfec'/></payload-type><payload-type name='ISAC' channels='1' id='103' clockrate='16000'/><payload-type name='ISAC' channels='1' id='104' clockrate='32000'/><payload-type name='telephone-event' channels='1' id='126' clockrate='8000'/><rtp-hdrext id='1' uri='urn:ietf:params:rtp-hdrext:ssrc-audio-level'/><rtp-hdrext id='5' uri='http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01'/><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='3166728122'><parameter xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' value='JWXji4LmYvLa3y9-1' name='cname'/><parameter xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' value='00d548ea-711f-48a9-9b78-7860d4773afe-1 667774c1-e$2020-08-28 23:41:22.925 INFO: [30] [confId=2e214850638dd328 epId=bc7cfb53 gid=286857 stats_id=Nickolas-EqM conf_name=y] DtlsTransport.setSetupAttribute#124: The remote side is acting as DTLS server, we'll act as client
2020-08-28 23:41:22.926 INFO: [30] [confId=2e214850638dd328 epId=bc7cfb53 local_ufrag=97tpi1egrn4sev gid=286857 stats_id=Nickolas-EqM conf_name=y] IceTransport.startConnectivityEstablishment#182: Starting the Agent without remote candidates.
2020-08-28 23:41:22.926 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=97tpi1egrn4sev epId=bc7cfb53 local_ufrag=97tpi1egrn4sev] Agent.startConnectivityEstablishment#753: Start ICE connectivity establishment.
2020-08-28 23:41:22.926 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=97tpi1egrn4sev epId=bc7cfb53 local_ufrag=97tpi1egrn4sev] Agent.initCheckLists#996: Init checklist for stream stream-bc7cfb53
2020-08-28 23:41:22.926 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=97tpi1egrn4sev epId=bc7cfb53 local_ufrag=97tpi1egrn4sev] Agent.setState#963: ICE state changed from Waiting to Running.
2020-08-28 23:41:22.926 INFO: [30] [confId=2e214850638dd328 epId=bc7cfb53 local_ufrag=97tpi1egrn4sev gid=286857 stats_id=Nickolas-EqM conf_name=y] IceTransport.iceStateChanged#321: ICE state changed old=Waiting new=Running
2020-08-28 23:41:22.927 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=97tpi1egrn4sev epId=bc7cfb53 local_ufrag=97tpi1egrn4sev] Agent.startConnectivityEstablishment#775: Trigger checks for pairs that were received before running state
2020-08-28 23:41:22.927 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=97tpi1egrn4sev epId=bc7cfb53 local_ufrag=97tpi1egrn4sev] Agent.triggerCheck#1761: Add peer CandidatePair with new reflexive address to checkList: CandidatePair (State=Frozen Priority=7962116751041232895):
        LocalCandidate=candidate:1 1 udp 2130706431 10.0.11.4 10000 typ host
        RemoteCandidate=candidate:10000 1 udp 1853824767 72.138.65.206 12947 typ prflx
2020-08-28 23:41:22.927 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=97tpi1egrn4sev epId=bc7cfb53 local_ufrag=97tpi1egrn4sev] ConnectivityCheckClient.startChecks#142: Start connectivity checks.
2020-08-28 23:41:22.927 FINE: [30] XmppCommon.handleIQ#154: SENT: <iq to='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' from='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTc5MABcDlH/2mo/auZqYMCWG5S9' type='result'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' name='y'><content name='audio'><channel endpoint='bc7cfb53' id='fb7568cfe80f0194' initiator='true' channel-bundle-id='bc7cfb53' last-n='-1' rtp-level-relay-type='translator'><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='3545881939'/><ssrc>3166728122</ssrc></channel></content><content name='video'><channel endpoint='bc7cfb53' id='7e629873849b8a88' initiator='true' channel-bundle-id='bc7cfb53' last-n='-1' rtp-level-relay-type='translator'><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='611726534'/><ssrc-group xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' semantics='FID'><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='1541703832'/><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='1181046082'/></ssrc-group><ssrc-group xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' semantics='FID'><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='2507512468'/><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='2497512195'/></ssrc-group><ssrc-$2020-08-28 23:41:22.932 FINE: [30] XmppCommon.handleIQ#147: RECV: <iq to='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' from='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTc5OABcDlH/2mo/auZqYMCWG5S9' type='set'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' gid='46089' name='y'><channel-bundle id='bc7cfb53'><transport xmlns='urn:xmpp:jingle:transports:ice-udp:1' pwd='etdmusEugXVL+UL3D7Sw3ZI7' ufrag='EOma'><rtcp-mux xmlns='urn:xmpp:jingle:transports:ice-udp:1'/><fingerprint xmlns='urn:xmpp:jingle:apps:dtls:0' hash='sha-256' required='true'>48:70:D6:5E:0E:08:22:53:7B:9E:8F:AD:06:FF:3A:4B:23:69:C6:14:F7:AE:5A:9A:AF:63:EE:84:51:DE:F8:28</fingerprint><candidate xmlns='urn:xmpp:jingle:transports:ice-udp:1' type='host' network='1' id='skvr8ksvx6' ip='192.168.1.105' component='1' port='57646' foundation='2222700650' generation='0' priority='2122260223' protocol='udp'/></transport></channel-bundle></conference></iq>
2020-08-28 23:41:22.932 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM componentId=1 conf_name=y ufrag=97tpi1egrn4sev name=stream-bc7cfb53 epId=bc7cfb53 local_ufrag=97tpi1egrn4sev] Component.addUpdateRemoteCandidates#347: Update remote candidate for stream-bc7cfb53.RTP: 192.168.1.105:57646/udp
2020-08-28 23:41:22.932 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM componentId=1 conf_name=y ufrag=97tpi1egrn4sev name=stream-bc7cfb53 epId=bc7cfb53 local_ufrag=97tpi1egrn4sev] Component.updateRemoteCandidates#481: new Pair added: 10.0.11.4:10000/udp/host -> 192.168.1.105:57646/udp/host (stream-bc7cfb53.RTP).
2020-08-28 23:41:22.933 FINE: [30] XmppCommon.handleIQ#154: SENT: <iq to='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' from='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTc5OABcDlH/2mo/auZqYMCWG5S9' type='result'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' name='y'><channel-bundle id='bc7cfb53'><transport xmlns='urn:xmpp:jingle:transports:ice-udp:1' pwd='g98j6r5oacj89lii10vc0lqi0' ufrag='97tpi1egrn4sev'><rtcp-mux/><fingerprint xmlns='urn:xmpp:jingle:apps:dtls:0' setup='active' hash='sha-256'>0A:EF:49:6E:1F:15:C8:90:7F:A5:F2:DE:4E:22:5C:72:7E:FB:98:95:60:0B:61:3E:42:29:B3:E3:C9:96:68:CF</fingerprint><candidate component='1' foundation='1' generation='0' id='35f3bc1a46b2f18d0ffffffff82daed18' network='0' priority='2130706431' protocol='udp' type='host' ip='10.0.11.4' port='10000'/><candidate component='1' foundation='2' generation='0' id='2464dd7f46b2f18d0ffffffffadc60296' network='0' priority='1694498815' protocol='udp' type='srflx' ip='52.235.32.130' port='10000' rel-addr='10.0.11.4' rel-port='10000'/></transport></channel-bundle><endpoint id='b4d10dc5' stats-id='Nickolas-EqM'/><endpoint id='ac71d18a' stats-id='Nickolas-EqM'/><endpoint id='fa204af2' stats-id='Ernestina-BCM'/><endpoint id='$2020-08-28 23:41:22.948 INFO: [56] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=97tpi1egrn4sev epId=bc7cfb53 local_ufrag=97tpi1egrn4sev] ConnectivityCheckClient$PaceMaker.run#922: Pair failed: 10.0.11.4:10000/udp/host -> 192.168.1.105:57646/udp/host (stream-bc7cfb53.RTP)
2020-08-28 23:41:22.966 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=97tpi1egrn4sev epId=bc7cfb53 local_ufrag=97tpi1egrn4sev] ConnectivityCheckClient.processSuccessResponse#630: Pair succeeded: 10.0.11.4:10000/udp/host -> 72.138.65.206:12947/udp/prflx (stream-bc7cfb53.RTP).
2020-08-28 23:41:22.966 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM componentId=1 conf_name=y ufrag=97tpi1egrn4sev name=stream-bc7cfb53 epId=bc7cfb53 local_ufrag=97tpi1egrn4sev] ComponentSocket.addAuthorizedAddress#99: Adding allowed address: 72.138.65.206:12947/udp
2020-08-28 23:41:22.967 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=97tpi1egrn4sev epId=bc7cfb53 local_ufrag=97tpi1egrn4sev] ConnectivityCheckClient.processSuccessResponse#639: Pair validated: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:12947/udp/prflx (stream-bc7cfb53.RTP).
2020-08-28 23:41:22.967 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=97tpi1egrn4sev epId=bc7cfb53 local_ufrag=97tpi1egrn4sev] DefaultNominator.strategyNominateFirstValid#142: Nominate (first valid): 52.235.32.130:10000/udp/srflx -> 72.138.65.206:12947/udp/prflx (stream-bc7cfb53.RTP).
2020-08-28 23:41:22.967 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=97tpi1egrn4sev epId=bc7cfb53 local_ufrag=97tpi1egrn4sev] Agent.nominate#1834: verify if nominated pair answer again
2020-08-28 23:41:22.967 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=97tpi1egrn4sev epId=bc7cfb53 local_ufrag=97tpi1egrn4sev] ConnectivityCheckClient.processSuccessResponse#708: IsControlling: true USE-CANDIDATE:false.
2020-08-28 23:41:22.987 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=97tpi1egrn4sev epId=bc7cfb53 local_ufrag=97tpi1egrn4sev] ConnectivityCheckClient.processSuccessResponse#630: Pair succeeded: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:12947/udp/prflx (stream-bc7cfb53.RTP).
2020-08-28 23:41:22.987 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=97tpi1egrn4sev epId=bc7cfb53 local_ufrag=97tpi1egrn4sev] ConnectivityCheckClient.processSuccessResponse#639: Pair validated: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:12947/udp/prflx (stream-bc7cfb53.RTP).
2020-08-28 23:41:22.988 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=97tpi1egrn4sev epId=bc7cfb53 local_ufrag=97tpi1egrn4sev] ConnectivityCheckClient.processSuccessResponse#708: IsControlling: true USE-CANDIDATE:true.
2020-08-28 23:41:22.988 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=97tpi1egrn4sev epId=bc7cfb53 local_ufrag=97tpi1egrn4sev] ConnectivityCheckClient.processSuccessResponse#723: Nomination confirmed for pair: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:12947/udp/prflx (stream-bc7cfb53.RTP).
2020-08-28 23:41:22.988 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=97tpi1egrn4sev name=stream-bc7cfb53 epId=bc7cfb53 local_ufrag=97tpi1egrn4sev] CheckList.handleNominationConfirmed#406: Selected pair for stream stream-bc7cfb53.RTP: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:12947/udp/prflx (stream-bc7cfb53.RTP)
2020-08-28 23:41:22.988 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=97tpi1egrn4sev epId=bc7cfb53 local_ufrag=97tpi1egrn4sev] Agent.checkListStatesUpdated#1925: CheckList of stream stream-bc7cfb53 is COMPLETED
2020-08-28 23:41:22.988 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=97tpi1egrn4sev epId=bc7cfb53 local_ufrag=97tpi1egrn4sev] Agent.setState#963: ICE state changed from Running to Completed.
2020-08-28 23:41:22.988 INFO: [48] [confId=2e214850638dd328 epId=bc7cfb53 local_ufrag=97tpi1egrn4sev gid=286857 stats_id=Nickolas-EqM conf_name=y] IceTransport.iceStateChanged#321: ICE state changed old=Running new=Completed
2020-08-28 23:41:22.988 INFO: [48] [confId=2e214850638dd328 epId=bc7cfb53 gid=286857 stats_id=Nickolas-EqM conf_name=y] Endpoint$3.connected#377: ICE connected
2020-08-28 23:41:22.990 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=97tpi1egrn4sev epId=bc7cfb53 local_ufrag=97tpi1egrn4sev] Agent.logCandTypes#2033: Harvester used for selected pair for stream-bc7cfb53.RTP: srflx
2020-08-28 23:41:22.991 INFO: [79] [confId=2e214850638dd328 epId=bc7cfb53 gid=286857 stats_id=Nickolas-EqM conf_name=y] DtlsTransport.startDtlsHandshake#102: Starting DTLS handshake
2020-08-28 23:41:23.010 INFO: [79] [confId=2e214850638dd328 epId=bc7cfb53 gid=286857 stats_id=Nickolas-EqM conf_name=y] TlsClientImpl.notifyServerVersion#165: Negotiated DTLS version DTLS 1.2
2020-08-28 23:41:23.042 INFO: [79] [confId=2e214850638dd328 epId=bc7cfb53 gid=286857 stats_id=Nickolas-EqM conf_name=y] Endpoint.lambda$setupDtlsTransport$2#404: DTLS handshake complete
2020-08-28 23:41:23.042 INFO: [64] [confId=2e214850638dd328 epId=bc7cfb53 gid=286857 stats_id=Nickolas-EqM conf_name=y] Endpoint.lambda$acceptSctpConnection$8#902: Attempting to establish SCTP socket connection
2020-08-28 23:41:23.885 INFO: [19] Videobridge.createConference#255: create_conf, id=5c60e5219e708cd8 gid=-1 logging=false
2020-08-28 23:41:23.892 INFO: [19] AbstractHealthCheckService.run#182: Performed a successful health check in PT0.008S. Sticky failure: false
2020-08-28 23:41:24.268 INFO: [44] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=6bm1h1egrn4r3q epId=b4d10dc5 local_ufrag=6bm1h1egrn4r3q] Agent.setState#963: ICE state changed from Completed to Terminated.
2020-08-28 23:41:24.269 INFO: [44] [confId=2e214850638dd328 epId=b4d10dc5 local_ufrag=6bm1h1egrn4r3q gid=286857 stats_id=Nickolas-EqM conf_name=y] IceTransport.iceStateChanged#321: ICE state changed old=Completed new=Terminated
2020-08-28 23:41:25.622 FINE: [30] XmppCommon.handleIQ#147: RECV: <iq to='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' from='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTgxOABcDlH/2mo/auZqYMCWG5S9' type='set'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' gid='46089' name='y'><content name='audio'><channel id='28696e16fc89ccba'><payload-type name='opus' channels='2' id='111' clockrate='48000'><rtcp-fb xmlns='urn:xmpp:jingle:apps:rtp:rtcp-fb:0' type='transport-cc'/><parameter value='10' name='minptime'/><parameter value='1' name='useinbandfec'/></payload-type><payload-type name='ISAC' channels='1' id='103' clockrate='16000'/><payload-type name='ISAC' channels='1' id='104' clockrate='32000'/><payload-type name='telephone-event' channels='1' id='126' clockrate='8000'/><rtp-hdrext id='1' uri='urn:ietf:params:rtp-hdrext:ssrc-audio-level'/><rtp-hdrext id='5' uri='http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01'/><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='1567100855'><parameter xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' value='ABZQNtmuBN8RAmEQ-1' name='cname'/><parameter xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' value='5e8625b8-cc9d-4fcc-8590-e5906e06a721-1 5bc92d03-$2020-08-28 23:41:25.631 INFO: [30] [confId=2e214850638dd328 epId=ac71d18a gid=286857 stats_id=Nickolas-EqM conf_name=y] DtlsTransport.setSetupAttribute#124: The remote side is acting as DTLS server, we'll act as client
2020-08-28 23:41:25.631 INFO: [30] [confId=2e214850638dd328 epId=ac71d18a local_ufrag=9a2r31egrn4u2c gid=286857 stats_id=Nickolas-EqM conf_name=y] IceTransport.startConnectivityEstablishment#182: Starting the Agent without remote candidates.
2020-08-28 23:41:25.631 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=9a2r31egrn4u2c epId=ac71d18a local_ufrag=9a2r31egrn4u2c] Agent.startConnectivityEstablishment#753: Start ICE connectivity establishment.
2020-08-28 23:41:25.631 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=9a2r31egrn4u2c epId=ac71d18a local_ufrag=9a2r31egrn4u2c] Agent.initCheckLists#996: Init checklist for stream stream-ac71d18a
2020-08-28 23:41:25.631 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=9a2r31egrn4u2c epId=ac71d18a local_ufrag=9a2r31egrn4u2c] Agent.setState#963: ICE state changed from Waiting to Running.
2020-08-28 23:41:25.632 INFO: [30] [confId=2e214850638dd328 epId=ac71d18a local_ufrag=9a2r31egrn4u2c gid=286857 stats_id=Nickolas-EqM conf_name=y] IceTransport.iceStateChanged#321: ICE state changed old=Waiting new=Running
2020-08-28 23:41:25.632 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=9a2r31egrn4u2c epId=ac71d18a local_ufrag=9a2r31egrn4u2c] Agent.startConnectivityEstablishment#775: Trigger checks for pairs that were received before running state
2020-08-28 23:41:25.632 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=9a2r31egrn4u2c epId=ac71d18a local_ufrag=9a2r31egrn4u2c] Agent.triggerCheck#1761: Add peer CandidatePair with new reflexive address to checkList: CandidatePair (State=Frozen Priority=7962116751041232895):
        LocalCandidate=candidate:1 1 udp 2130706431 10.0.11.4 10000 typ host
        RemoteCandidate=candidate:10000 1 udp 1853824767 72.138.65.206 1595 typ prflx
2020-08-28 23:41:25.632 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=9a2r31egrn4u2c epId=ac71d18a local_ufrag=9a2r31egrn4u2c] ConnectivityCheckClient.startChecks#142: Start connectivity checks.
2020-08-28 23:41:25.633 FINE: [30] XmppCommon.handleIQ#154: SENT: <iq to='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' from='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTgxOABcDlH/2mo/auZqYMCWG5S9' type='result'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' name='y'><content name='audio'><channel endpoint='ac71d18a' id='28696e16fc89ccba' initiator='true' channel-bundle-id='ac71d18a' last-n='-1' rtp-level-relay-type='translator'><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='3545881939'/><ssrc>1567100855</ssrc></channel></content><content name='video'><channel endpoint='ac71d18a' id='1c429f4b2c1db391' initiator='true' channel-bundle-id='ac71d18a' last-n='-1' rtp-level-relay-type='translator'><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='611726534'/><ssrc-group xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' semantics='FID'><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='3273817967'/><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='1839673561'/></ssrc-group><ssrc-group xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' semantics='FID'><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='1702428928'/><source xmlns='urn:xmpp:jingle:apps:rtp:ssma:0' ssrc='1712957885'/></ssrc-group><ssrc-$2020-08-28 23:41:25.649 FINE: [30] XmppCommon.handleIQ#147: RECV: <iq to='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' from='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTgyOABcDlH/2mo/auZqYMCWG5S9' type='set'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' gid='46089' name='y'><channel-bundle id='ac71d18a'><transport xmlns='urn:xmpp:jingle:transports:ice-udp:1' pwd='EUgDxs40o0fUK6qGscGMia5k' ufrag='BFiL'><rtcp-mux xmlns='urn:xmpp:jingle:transports:ice-udp:1'/><fingerprint xmlns='urn:xmpp:jingle:apps:dtls:0' hash='sha-256' required='true'>D7:C5:8A:DC:C9:9A:A2:7C:8C:B0:74:80:28:49:34:E3:69:68:B2:66:E7:56:BC:E5:59:2A:B0:3B:B5:64:38:BB</fingerprint><candidate xmlns='urn:xmpp:jingle:transports:ice-udp:1' type='host' network='1' id='xci1qbzzrr' ip='192.168.1.105' component='1' port='57652' foundation='2222700650' generation='0' priority='2122260223' protocol='udp'/></transport></channel-bundle></conference></iq>
2020-08-28 23:41:25.650 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM componentId=1 conf_name=y ufrag=9a2r31egrn4u2c name=stream-ac71d18a epId=ac71d18a local_ufrag=9a2r31egrn4u2c] Component.addUpdateRemoteCandidates#347: Update remote candidate for stream-ac71d18a.RTP: 192.168.1.105:57652/udp
2020-08-28 23:41:25.650 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM componentId=1 conf_name=y ufrag=9a2r31egrn4u2c name=stream-ac71d18a epId=ac71d18a local_ufrag=9a2r31egrn4u2c] Component.updateRemoteCandidates#481: new Pair added: 10.0.11.4:10000/udp/host -> 192.168.1.105:57652/udp/host (stream-ac71d18a.RTP).
2020-08-28 23:41:25.650 FINE: [30] XmppCommon.handleIQ#154: SENT: <iq to='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' from='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTgyOABcDlH/2mo/auZqYMCWG5S9' type='result'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' name='y'><channel-bundle id='ac71d18a'><transport xmlns='urn:xmpp:jingle:transports:ice-udp:1' pwd='1i2v4736kv9bvfdfhqndbgpkah' ufrag='9a2r31egrn4u2c'><rtcp-mux/><fingerprint xmlns='urn:xmpp:jingle:apps:dtls:0' setup='active' hash='sha-256'>0A:EF:49:6E:1F:15:C8:90:7F:A5:F2:DE:4E:22:5C:72:7E:FB:98:95:60:0B:61:3E:42:29:B3:E3:C9:96:68:CF</fingerprint><candidate component='1' foundation='1' generation='0' id='1fb939fe4ce6852031e7a883' network='0' priority='2130706431' protocol='udp' type='host' ip='10.0.11.4' port='10000'/><candidate component='1' foundation='2' generation='0' id='447681d4ce685205cd2be01' network='0' priority='1694498815' protocol='udp' type='srflx' ip='52.235.32.130' port='10000' rel-addr='10.0.11.4' rel-port='10000'/></transport></channel-bundle><endpoint id='b4d10dc5' stats-id='Nickolas-EqM'/><endpoint id='ac71d18a' stats-id='Nickolas-EqM'/><endpoint id='fa204af2' stats-id='Ernestina-BCM'/><endpoint id='c0811a93' stats-id$2020-08-28 23:41:25.654 INFO: [56] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=9a2r31egrn4u2c epId=ac71d18a local_ufrag=9a2r31egrn4u2c] ConnectivityCheckClient$PaceMaker.run#922: Pair failed: 10.0.11.4:10000/udp/host -> 192.168.1.105:57652/udp/host (stream-ac71d18a.RTP)
2020-08-28 23:41:25.671 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=9a2r31egrn4u2c epId=ac71d18a local_ufrag=9a2r31egrn4u2c] ConnectivityCheckClient.processSuccessResponse#630: Pair succeeded: 10.0.11.4:10000/udp/host -> 72.138.65.206:1595/udp/prflx (stream-ac71d18a.RTP).
2020-08-28 23:41:25.672 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM componentId=1 conf_name=y ufrag=9a2r31egrn4u2c name=stream-ac71d18a epId=ac71d18a local_ufrag=9a2r31egrn4u2c] ComponentSocket.addAuthorizedAddress#99: Adding allowed address: 72.138.65.206:1595/udp
2020-08-28 23:41:25.672 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=9a2r31egrn4u2c epId=ac71d18a local_ufrag=9a2r31egrn4u2c] ConnectivityCheckClient.processSuccessResponse#639: Pair validated: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:1595/udp/prflx (stream-ac71d18a.RTP).
2020-08-28 23:41:25.672 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=9a2r31egrn4u2c epId=ac71d18a local_ufrag=9a2r31egrn4u2c] DefaultNominator.strategyNominateFirstValid#142: Nominate (first valid): 52.235.32.130:10000/udp/srflx -> 72.138.65.206:1595/udp/prflx (stream-ac71d18a.RTP).
2020-08-28 23:41:25.672 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=9a2r31egrn4u2c epId=ac71d18a local_ufrag=9a2r31egrn4u2c] Agent.nominate#1834: verify if nominated pair answer again
2020-08-28 23:41:25.672 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=9a2r31egrn4u2c epId=ac71d18a local_ufrag=9a2r31egrn4u2c] ConnectivityCheckClient.processSuccessResponse#708: IsControlling: true USE-CANDIDATE:false.
2020-08-28 23:41:25.694 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=9a2r31egrn4u2c epId=ac71d18a local_ufrag=9a2r31egrn4u2c] ConnectivityCheckClient.processSuccessResponse#630: Pair succeeded: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:1595/udp/prflx (stream-ac71d18a.RTP).
2020-08-28 23:41:25.694 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=9a2r31egrn4u2c epId=ac71d18a local_ufrag=9a2r31egrn4u2c] ConnectivityCheckClient.processSuccessResponse#639: Pair validated: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:1595/udp/prflx (stream-ac71d18a.RTP).
2020-08-28 23:41:25.694 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=9a2r31egrn4u2c epId=ac71d18a local_ufrag=9a2r31egrn4u2c] ConnectivityCheckClient.processSuccessResponse#708: IsControlling: true USE-CANDIDATE:true.
2020-08-28 23:41:25.694 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=9a2r31egrn4u2c epId=ac71d18a local_ufrag=9a2r31egrn4u2c] ConnectivityCheckClient.processSuccessResponse#723: Nomination confirmed for pair: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:1595/udp/prflx (stream-ac71d18a.RTP).
2020-08-28 23:41:25.694 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=9a2r31egrn4u2c name=stream-ac71d18a epId=ac71d18a local_ufrag=9a2r31egrn4u2c] CheckList.handleNominationConfirmed#406: Selected pair for stream stream-ac71d18a.RTP: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:1595/udp/prflx (stream-ac71d18a.RTP)
2020-08-28 23:41:25.694 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=9a2r31egrn4u2c epId=ac71d18a local_ufrag=9a2r31egrn4u2c] Agent.checkListStatesUpdated#1925: CheckList of stream stream-ac71d18a is COMPLETED
2020-08-28 23:41:25.694 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=9a2r31egrn4u2c epId=ac71d18a local_ufrag=9a2r31egrn4u2c] Agent.setState#963: ICE state changed from Running to Completed.
2020-08-28 23:41:25.694 INFO: [48] [confId=2e214850638dd328 epId=ac71d18a local_ufrag=9a2r31egrn4u2c gid=286857 stats_id=Nickolas-EqM conf_name=y] IceTransport.iceStateChanged#321: ICE state changed old=Running new=Completed
2020-08-28 23:41:25.694 INFO: [48] [confId=2e214850638dd328 epId=ac71d18a gid=286857 stats_id=Nickolas-EqM conf_name=y] Endpoint$3.connected#377: ICE connected
2020-08-28 23:41:25.695 INFO: [57] [confId=2e214850638dd328 epId=ac71d18a gid=286857 stats_id=Nickolas-EqM conf_name=y] DtlsTransport.startDtlsHandshake#102: Starting DTLS handshake
2020-08-28 23:41:25.695 INFO: [48] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=9a2r31egrn4u2c epId=ac71d18a local_ufrag=9a2r31egrn4u2c] Agent.logCandTypes#2033: Harvester used for selected pair for stream-ac71d18a.RTP: srflx
2020-08-28 23:41:25.715 INFO: [57] [confId=2e214850638dd328 epId=ac71d18a gid=286857 stats_id=Nickolas-EqM conf_name=y] TlsClientImpl.notifyServerVersion#165: Negotiated DTLS version DTLS 1.2
2020-08-28 23:41:25.741 INFO: [57] [confId=2e214850638dd328 epId=ac71d18a gid=286857 stats_id=Nickolas-EqM conf_name=y] Endpoint.lambda$setupDtlsTransport$2#404: DTLS handshake complete
2020-08-28 23:41:25.741 INFO: [70] [confId=2e214850638dd328 epId=ac71d18a gid=286857 stats_id=Nickolas-EqM conf_name=y] Endpoint.lambda$acceptSctpConnection$8#902: Attempting to establish SCTP socket connection
Got sctp association state update: 1
sctp is now up.  was ready? false
2020-08-28 23:41:25.842 INFO: [70] [confId=2e214850638dd328 epId=ac71d18a gid=286857 stats_id=Nickolas-EqM conf_name=y] Endpoint$4.onReady#844: SCTP connection is ready, creating the Data channel stack
2020-08-28 23:41:25.843 INFO: [70] [confId=2e214850638dd328 epId=ac71d18a gid=286857 stats_id=Nickolas-EqM conf_name=y] Endpoint$4.onReady#871: Will wait for the remote side to open the data channel.
2020-08-28 23:41:25.843 INFO: [84] [confId=2e214850638dd328 epId=ac71d18a gid=286857 stats_id=Nickolas-EqM conf_name=y] DataChannelStack.onIncomingDataChannelPacket#62: Received data channel open message
2020-08-28 23:41:25.843 INFO: [84] [confId=2e214850638dd328 epId=ac71d18a gid=286857 stats_id=Nickolas-EqM conf_name=y] Endpoint$4.lambda$onReady$1#852: Remote side opened a data channel.
2020-08-28 23:41:25.988 INFO: [44] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=97tpi1egrn4sev epId=bc7cfb53 local_ufrag=97tpi1egrn4sev] Agent.setState#963: ICE state changed from Completed to Terminated.
2020-08-28 23:41:25.989 INFO: [44] [confId=2e214850638dd328 epId=bc7cfb53 local_ufrag=97tpi1egrn4sev gid=286857 stats_id=Nickolas-EqM conf_name=y] IceTransport.iceStateChanged#321: ICE state changed old=Completed new=Terminated
Got sctp association state update: 1
sctp is now up.  was ready? false
2020-08-28 23:41:26.449 INFO: [64] [confId=2e214850638dd328 epId=bc7cfb53 gid=286857 stats_id=Nickolas-EqM conf_name=y] Endpoint$4.onReady#844: SCTP connection is ready, creating the Data channel stack
2020-08-28 23:41:26.449 INFO: [64] [confId=2e214850638dd328 epId=bc7cfb53 gid=286857 stats_id=Nickolas-EqM conf_name=y] Endpoint$4.onReady#871: Will wait for the remote side to open the data channel.
2020-08-28 23:41:26.449 INFO: [86] [confId=2e214850638dd328 epId=bc7cfb53 gid=286857 stats_id=Nickolas-EqM conf_name=y] DataChannelStack.onIncomingDataChannelPacket#62: Received data channel open message
2020-08-28 23:41:26.449 INFO: [86] [confId=2e214850638dd328 epId=bc7cfb53 gid=286857 stats_id=Nickolas-EqM conf_name=y] Endpoint$4.lambda$onReady$1#852: Remote side opened a data channel.
2020-08-28 23:41:28.679 FINE: [30] XmppCommon.handleIQ#147: RECV: <iq to='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' from='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTg0MQBcDlH/2mo/auZqYMCWG5S9' type='get'><healthcheck xmlns='http://jitsi.org/protocol/healthcheck'/></iq>
2020-08-28 23:41:28.680 FINE: [30] XmppCommon.handleIQ#154: SENT: <iq to='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' from='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTg0MQBcDlH/2mo/auZqYMCWG5S9' type='result'></iq>
2020-08-28 23:41:28.695 INFO: [44] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=9a2r31egrn4u2c epId=ac71d18a local_ufrag=9a2r31egrn4u2c] Agent.setState#963: ICE state changed from Completed to Terminated.
2020-08-28 23:41:28.695 INFO: [44] [confId=2e214850638dd328 epId=ac71d18a local_ufrag=9a2r31egrn4u2c gid=286857 stats_id=Nickolas-EqM conf_name=y] IceTransport.iceStateChanged#321: ICE state changed old=Completed new=Terminated
2020-08-28 23:41:31.354 INFO: [77] [confId=2e214850638dd328 epId=bc7cfb53 gid=286857 stats_id=Nickolas-EqM conf_name=y] TlsClientImpl.notifyAlertReceived#211: close_notify received, connection closing
2020-08-28 23:41:31.573 FINE: [30] XmppCommon.handleIQ#147: RECV: <iq to='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' from='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTg1NABcDlH/2mo/auZqYMCWG5S9' type='set'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' gid='46089' name='y'><content name='audio'><channel expire='0' id='fb7568cfe80f0194'/></content><content name='video'><channel expire='0' id='7e629873849b8a88'/></content><content name='data'><sctpconnection endpoint='bc7cfb53' expire='0' id='2a274a9fcc64b9c9' port='5000'/></content></conference></iq>
2020-08-28 23:41:31.574 FINE: [43] XmppCommon.handleIQ#147: RECV: <iq to='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' from='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTg1NgBcDlH/2mo/auZqYMCWG5S9' type='set'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' gid='46089' name='y'><content name='audio'><channel endpoint='bc7cfb53' initiator='true' channel-bundle-id='bc7cfb53' last-n='-1'><payload-type name='opus' clockrate='48000' id='111' channels='2'><rtcp-fb xmlns='urn:xmpp:jingle:apps:rtp:rtcp-fb:0' type='transport-cc'/><parameter value='10' name='minptime'/><parameter value='1' name='useinbandfec'/></payload-type><payload-type id='103' name='ISAC' clockrate='16000'/><payload-type id='104' name='ISAC' clockrate='32000'/><payload-type id='126' name='telephone-event' clockrate='8000'/><rtp-hdrext id='1' uri='urn:ietf:params:rtp-hdrext:ssrc-audio-level'/><rtp-hdrext id='5' uri='http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01'/></channel></content><content name='video'><channel endpoint='bc7cfb53' initiator='true' channel-bundle-id='bc7cfb53' last-n='-1'><payload-type id='100' name='VP8' clockrate='90000'><rtcp-fb xmlns='urn:xmpp:jingle:apps:rtp:rtcp-fb:0' type='ccm' sub$2020-08-28 23:41:31.574 INFO: [30] [confId=2e214850638dd328 epId=bc7cfb53 gid=286857 stats_id=Nickolas-EqM conf_name=y] AbstractEndpoint.expire#233: Expiring.
2020-08-28 23:41:31.575 INFO: [30] [confId=2e214850638dd328 epId=bc7cfb53 gid=286857 stats_id=Nickolas-EqM conf_name=y] Transceiver.teardown#319: Tearing down
2020-08-28 23:41:31.575 INFO: [30] [confId=2e214850638dd328 epId=bc7cfb53 gid=286857 stats_id=Nickolas-EqM conf_name=y] RtpReceiverImpl.tearDown#296: Tearing down
2020-08-28 23:41:31.578 SEVERE: [43] XmppCommon.handleIQRequest#251: Exception handling IQ request
java.lang.NullPointerException
        at org.jitsi.videobridge.shim.ChannelShim.<init>(ChannelShim.java:163)
        at org.jitsi.videobridge.shim.ContentShim.createRtpChannel(ContentShim.java:135)
        at org.jitsi.videobridge.shim.ContentShim.getOrCreateChannelShim(ContentShim.java:276)
        at org.jitsi.videobridge.shim.VideobridgeShim.processChannels(VideobridgeShim.java:144)
        at org.jitsi.videobridge.shim.VideobridgeShim.handleColibriConferenceIQ(VideobridgeShim.java:336)
        at org.jitsi.videobridge.Videobridge.handleColibriConferenceIQ(Videobridge.java:424)
        at org.jitsi.videobridge.xmpp.XmppCommon.handleIQRequest(XmppCommon.java:228)
        at org.jitsi.videobridge.xmpp.XmppCommon.handleIQInternal(XmppCommon.java:179)
        at org.jitsi.videobridge.xmpp.XmppCommon.handleIQ(XmppCommon.java:150)
        at org.jitsi.videobridge.xmpp.ClientConnectionImpl.handleIq(ClientConnectionImpl.java:110)
        at org.jitsi.xmpp.mucclient.IQListener.handleIq(IQListener.java:50)
        at org.jitsi.xmpp.mucclient.MucClient.handleIq(MucClient.java:566)
        at org.jitsi.xmpp.mucclient.MucClient.access$700(MucClient.java:50)
        at org.jitsi.xmpp.mucclient.MucClient$2.handleIQRequest(MucClient.java:530)
        at org.jivesoftware.smack.AbstractXMPPConnection$4.run(AbstractXMPPConnection.java:1188)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at java.lang.Thread.run(Thread.java:748)
2020-08-28 23:41:31.581 INFO: [30] [confId=2e214850638dd328 epId=bc7cfb53 gid=286857 stats_id=Nickolas-EqM conf_name=y] RtpSenderImpl.tearDown#268: Tearing down
2020-08-28 23:41:31.582 INFO: [30] [confId=2e214850638dd328 epId=bc7cfb53 gid=286857 stats_id=Nickolas-EqM conf_name=y] DtlsTransport.stop#184: Stopping
2020-08-28 23:41:31.583 INFO: [30] [confId=2e214850638dd328 epId=bc7cfb53 local_ufrag=97tpi1egrn4sev gid=286857 stats_id=Nickolas-EqM conf_name=y] IceTransport.stop#235: Stopping
2020-08-28 23:41:31.583 INFO: [81] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM componentId=1 conf_name=y ufrag=97tpi1egrn4sev name=stream-bc7cfb53 epId=bc7cfb53 local_ufrag=97tpi1egrn4sev] MergingDatagramSocket$SocketContainer.runInReaderThread#770: Failed to receive: java.net.SocketException: Socket closed
2020-08-28 23:41:31.583 WARNING: [81] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM componentId=1 conf_name=y ufrag=97tpi1egrn4sev name=stream-bc7cfb53 epId=bc7cfb53 local_ufrag=97tpi1egrn4sev] MergingDatagramSocket.doRemove#349: Removing the active socket. Won't be able to send until a new one is elected.
2020-08-28 23:41:31.584 FINE: [43] XmppCommon.handleIQ#154: SENT: <iq to='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' from='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTg1NgBcDlH/2mo/auZqYMCWG5S9' type='error'><error type='cancel'><internal-server-error xmlns='urn:ietf:params:xml:ns:xmpp-stanzas'/></error></iq>
2020-08-28 23:41:31.598 INFO: [30] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM componentId=1 conf_name=y ufrag=97tpi1egrn4sev name=stream-bc7cfb53 epId=bc7cfb53 local_ufrag=97tpi1egrn4sev] MergingDatagramSocket.close#142: Closing.
2020-08-28 23:41:31.598 INFO: [77] [confId=2e214850638dd328 epId=bc7cfb53 local_ufrag=97tpi1egrn4sev gid=286857 stats_id=Nickolas-EqM conf_name=y] IceTransport.startReadingData#201: Socket closed, stopping reader
2020-08-28 23:41:31.598 INFO: [77] [confId=2e214850638dd328 epId=bc7cfb53 local_ufrag=97tpi1egrn4sev gid=286857 stats_id=Nickolas-EqM conf_name=y] IceTransport.startReadingData#213: No longer running, stopped reading packets
2020-08-28 23:41:31.598 INFO: [30] [confId=2e214850638dd328 epId=bc7cfb53 gid=286857 stats_id=Nickolas-EqM conf_name=y] Endpoint.expire#778: Expired.
2020-08-28 23:41:31.599 FINE: [30] XmppCommon.handleIQ#154: SENT: <iq to='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' from='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTg1NABcDlH/2mo/auZqYMCWG5S9' type='result'><conference xmlns='http://jitsi.org/protocol/colibri' id='2e214850638dd328' name='y'><content name='audio'/><content name='video'/><content name='data'/><endpoint id='b4d10dc5' stats-id='Nickolas-EqM'/><endpoint id='ac71d18a' stats-id='Nickolas-EqM'/><endpoint id='fa204af2' stats-id='Ernestina-BCM'/><endpoint id='c0811a93' stats-id='Nickolas-EqM'/><endpoint id='6c4f0f6c' stats-id='Ernestina-BCM'/><endpoint id='49ec848c' stats-id='Ernestina-BCM'/><endpoint id='469c08b3' stats-id='Ernestina-BCM'/></conference></iq>
2020-08-28 23:41:31.820 INFO: [36] [confId=2e214850638dd328 epId=6c4f0f6c gid=286857 stats_id=Ernestina-BCM conf_name=y] TlsClientImpl.notifyAlertReceived#211: close_notify received, connection closing
2020-08-28 23:41:32.170 INFO: [52] [confId=2e214850638dd328 epId=b4d10dc5 gid=286857 stats_id=Nickolas-EqM conf_name=y] TlsClientImpl.notifyAlertReceived#211: close_notify received, connection closing
2020-08-28 23:41:32.239 INFO: [51] [confId=2e214850638dd328 epId=469c08b3 gid=286857 stats_id=Ernestina-BCM conf_name=y] TlsClientImpl.notifyAlertReceived#211: close_notify received, connection closing
2020-08-28 23:41:32.240 INFO: [35] [confId=2e214850638dd328 epId=fa204af2 gid=286857 stats_id=Ernestina-BCM conf_name=y] TlsClientImpl.notifyAlertReceived#211: close_notify received, connection closing
2020-08-28 23:41:32.244 INFO: [71] [confId=2e214850638dd328 epId=49ec848c gid=286857 stats_id=Ernestina-BCM conf_name=y] TlsClientImpl.notifyAlertReceived#211: close_notify received, connection closing
2020-08-28 23:41:32.339 INFO: [78] [confId=2e214850638dd328 epId=ac71d18a gid=286857 stats_id=Nickolas-EqM conf_name=y] TlsClientImpl.notifyAlertReceived#211: close_notify received, connection closing
2020-08-28 23:41:32.369 INFO: [66] [confId=2e214850638dd328 epId=c0811a93 gid=286857 stats_id=Nickolas-EqM conf_name=y] TlsClientImpl.notifyAlertReceived#211: close_notify received, connection closing
2020-08-28 23:41:33.884 INFO: [19] Videobridge.createConference#255: create_conf, id=9203b96468f13e69 gid=-1 logging=false
2020-08-28 23:41:33.889 INFO: [19] AbstractHealthCheckService.run#182: Performed a successful health check in PT0.005S. Sticky failure: false
2020-08-28 23:41:35.013 INFO: [88] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=8m2h1egrn4cr4 epId=6c4f0f6c local_ufrag=8m2h1egrn4cr4] ConnectivityCheckClient.processTimeout#860: timeout for pair: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:32998/udp/prflx (stream-6c4f0f6c.RTP), failing.
2020-08-28 23:41:35.396 INFO: [88] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=2l67k1egrn4ar8 epId=fa204af2 local_ufrag=2l67k1egrn4ar8] ConnectivityCheckClient.processTimeout#860: timeout for pair: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:39412/udp/prflx (stream-fa204af2.RTP), failing.
2020-08-28 23:41:35.474 INFO: [88] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=6bm1h1egrn4r3q epId=b4d10dc5 local_ufrag=6bm1h1egrn4r3q] ConnectivityCheckClient.processTimeout#860: timeout for pair: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:10921/udp/prflx (stream-b4d10dc5.RTP), failing.
2020-08-28 23:41:36.372 INFO: [88] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=4efcp1egrn4apr epId=469c08b3 local_ufrag=4efcp1egrn4apr] ConnectivityCheckClient.processTimeout#860: timeout for pair: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:43730/udp/prflx (stream-469c08b3.RTP), failing.
2020-08-28 23:41:36.900 INFO: [89] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=9a2r31egrn4u2c epId=ac71d18a local_ufrag=9a2r31egrn4u2c] ConnectivityCheckClient.processTimeout#860: timeout for pair: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:1595/udp/prflx (stream-ac71d18a.RTP), failing.
2020-08-28 23:41:37.070 INFO: [89] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=5tjm81egrn4kam epId=c0811a93 local_ufrag=5tjm81egrn4kam] ConnectivityCheckClient.processTimeout#860: timeout for pair: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:13589/udp/prflx (stream-c0811a93.RTP), failing.
2020-08-28 23:41:37.357 INFO: [89] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=anbtl1egrn4fki epId=49ec848c local_ufrag=anbtl1egrn4fki] ConnectivityCheckClient.processTimeout#860: timeout for pair: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:11494/udp/prflx (stream-49ec848c.RTP), failing.
2020-08-28 23:41:38.013 INFO: [89] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=8m2h1egrn4cr4 epId=6c4f0f6c local_ufrag=8m2h1egrn4cr4] ConnectivityCheckClient.processTimeout#860: timeout for pair: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:32998/udp/prflx (stream-6c4f0f6c.RTP), failing.
2020-08-28 23:41:38.398 INFO: [89] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=2l67k1egrn4ar8 epId=fa204af2 local_ufrag=2l67k1egrn4ar8] ConnectivityCheckClient.processTimeout#860: timeout for pair: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:39412/udp/prflx (stream-fa204af2.RTP), failing.
2020-08-28 23:41:38.475 INFO: [89] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=6bm1h1egrn4r3q epId=b4d10dc5 local_ufrag=6bm1h1egrn4r3q] ConnectivityCheckClient.processTimeout#860: timeout for pair: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:10921/udp/prflx (stream-b4d10dc5.RTP), failing.
2020-08-28 23:41:38.679 FINE: [30] XmppCommon.handleIQ#147: RECV: <iq to='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' from='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTg5MABcDlH/2mo/auZqYMCWG5S9' type='get'><healthcheck xmlns='http://jitsi.org/protocol/healthcheck'/></iq>
2020-08-28 23:41:38.680 FINE: [30] XmppCommon.handleIQ#154: SENT: <iq to='jvbbrewery@internal.auth.cscserver3.canadaeast.cloudapp.azure.com/focus' from='jvb@auth.cscserver3.canadaeast.cloudapp.azure.com/aa3ed32f-08d3-48c4-b0b8-8ed90ff7bbdf' id='anZiQGF1dGguY3Njc2VydmVyMy5jYW5hZGFlYXN0LmNsb3VkYXBwLmF6dXJlLmNvbS9hYTNlZDMyZi0wOGQzLTQ4YzQtYjBiOC04ZWQ5MGZmN2JiZGYAd2s2MjUtNTg5MABcDlH/2mo/auZqYMCWG5S9' type='result'></iq>
2020-08-28 23:41:39.373 INFO: [88] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=4efcp1egrn4apr epId=469c08b3 local_ufrag=4efcp1egrn4apr] ConnectivityCheckClient.processTimeout#860: timeout for pair: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:43730/udp/prflx (stream-469c08b3.RTP), failing.
2020-08-28 23:41:39.900 INFO: [89] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=9a2r31egrn4u2c epId=ac71d18a local_ufrag=9a2r31egrn4u2c] ConnectivityCheckClient.processTimeout#860: timeout for pair: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:1595/udp/prflx (stream-ac71d18a.RTP), failing.
2020-08-28 23:41:40.071 INFO: [89] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=5tjm81egrn4kam epId=c0811a93 local_ufrag=5tjm81egrn4kam] ConnectivityCheckClient.processTimeout#860: timeout for pair: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:13589/udp/prflx (stream-c0811a93.RTP), failing.
2020-08-28 23:41:40.358 INFO: [89] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=anbtl1egrn4fki epId=49ec848c local_ufrag=anbtl1egrn4fki] ConnectivityCheckClient.processTimeout#860: timeout for pair: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:11494/udp/prflx (stream-49ec848c.RTP), failing.
2020-08-28 23:41:41.013 INFO: [89] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=8m2h1egrn4cr4 epId=6c4f0f6c local_ufrag=8m2h1egrn4cr4] ConnectivityCheckClient.processTimeout#860: timeout for pair: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:32998/udp/prflx (stream-6c4f0f6c.RTP), failing.
2020-08-28 23:41:41.397 INFO: [89] [confId=2e214850638dd328 gid=286857 stats_id=Ernestina-BCM conf_name=y ufrag=2l67k1egrn4ar8 epId=fa204af2 local_ufrag=2l67k1egrn4ar8] ConnectivityCheckClient.processTimeout#860: timeout for pair: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:39412/udp/prflx (stream-fa204af2.RTP), failing.
2020-08-28 23:41:41.474 INFO: [89] [confId=2e214850638dd328 gid=286857 stats_id=Nickolas-EqM conf_name=y ufrag=6bm1h1egrn4r3q epId=b4d10dc5 local_ufrag=6bm1h1egrn4r3q] ConnectivityCheckClient.processTimeout#860: timeout for pair: 52.235.32.130:10000/udp/srflx -> 72.138.65.206:10921/udp/prflx (stream-b4d10dc5.RTP), failing.

For a reason I don’t understand jicofo expires the channels for one endpoint and almost immediately allocates new ones. This leads to a race condition on the bridge. The reason we haven’t seen this in our environments is probably because we run the XMPP handler in sync mode. You can fix this by adding this property to your bridge config:
org.jitsi.videobridge.xmpp.user.XXX.IQ_HANDLER_MODE=sync (replace XXX with the name of the account used in your config file).

I’ll look at making this the default behavior. Thanks for the report.

Boris

Thank you! I didn’t see that SEVERE logging again after adding that config.
Just for curiosity, why would some channel expire if everyone is connected to the bridge? Is it because of the E2EE?

Thanks,
Thomas