Closed Bug 1856096 Opened 1 year ago Closed 10 months ago

High Freq OSX TestNrSocketTest.FullConeTimeout | Value of: CheckConnectivityVia(public_addrs_[0], private_addrs_[0], sender_external_address)

Categories

(Core :: WebRTC: Networking, defect, P5)

defect

Tracking

()

RESOLVED FIXED
123 Branch
Tracking Status
firefox-esr115 --- unaffected
firefox120 --- unaffected
firefox121 --- fixed
firefox122 --- fixed
firefox123 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: bwc)

References

(Regression)

Details

(Keywords: intermittent-failure, regression, Whiteboard: [stockwell disable-recommended])

Attachments

(2 files)

Filed by: nfay [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=430834014&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/e9iOV9yGTye8F75uw0i4Aw/runs/0/artifacts/public/logs/live_backing.log


[task 2023-09-29T23:06:09.006Z] 23:06:09     INFO -  TEST-START | TestNrSocketTest.FullConeTimeout
[task 2023-09-29T23:06:09.350Z] 23:06:09  WARNING -  TEST-UNEXPECTED-FAIL | TestNrSocketTest.FullConeTimeout | Value of: CheckConnectivityVia(public_addrs_[0], private_addrs_[0], sender_external_address)
[task 2023-09-29T23:06:09.351Z] 23:06:09     INFO -    Actual: false
[task 2023-09-29T23:06:09.351Z] 23:06:09     INFO -  Expected: true
[task 2023-09-29T23:06:09.351Z] 23:06:09     INFO -   @ /builds/worker/checkouts/gecko/dom/media/webrtc/transport/test/test_nr_socket_unittest.cpp:750
[task 2023-09-29T23:06:09.351Z] 23:06:09     INFO -  ICE(IcePeer): no local addresses available
[task 2023-09-29T23:06:09.352Z] 23:06:09     INFO -  insert 'ice.pref.interface' (registry) succeeded: ice.pref.interface
[task 2023-09-29T23:06:09.352Z] 23:06:09     INFO -  insert 'ice.pref.interface.en0' (UCHAR) succeeded: 0x7f
[task 2023-09-29T23:06:09.352Z] 23:06:09     INFO -  ICE(IcePeer): All candidates initialized
[task 2023-09-29T23:06:09.352Z] 23:06:09     INFO -  ICE(IcePeer): no local addresses available
[task 2023-09-29T23:06:09.352Z] 23:06:09     INFO -  ICE(IcePeer2): no local addresses available
[task 2023-09-29T23:06:09.352Z] 23:06:09     INFO -  ICE(IcePeer): All candidates initialized
[task 2023-09-29T23:06:09.352Z] 23:06:09     INFO -  ICE(IcePeer2): All candidates initialized
[task 2023-09-29T23:06:09.353Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(CS8L): setting pair to state FROZEN: CS8L|IP4:10.49.58.213:59083/UDP|IP4:10.49.58.213:60778/UDP(host(IP4:10.49.58.213:59083/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 60778 typ host)
[task 2023-09-29T23:06:09.353Z] 23:06:09     INFO -  ICE(IcePeer2)/CAND-PAIR(CS8L): Pairing candidate IP4:10.49.58.213:59083/UDP (7e7f00ff):IP4:10.49.58.213:60778/UDP (7e7f00ff) priority=9115005270282338815 (7e7f00fffcfe01ff)
[task 2023-09-29T23:06:09.353Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(2C4i): setting pair to state FROZEN: 2C4i|IP4:10.49.58.213:52767/TCP|IP4:10.49.58.213:52943/TCP(host(IP4:10.49.58.213:52767/TCP) active|candidate:1 1 TCP 2105508095 10.49.58.213 52943 typ host tcptype passive)
[task 2023-09-29T23:06:09.353Z] 23:06:09     INFO -  ICE(IcePeer2)/CAND-PAIR(2C4i): Pairing candidate IP4:10.49.58.213:52767/TCP (7d7fc0ff):IP4:10.49.58.213:52943/TCP (7d7f80ff) priority=9043088413699310078 (7d7f80fffaff81fe)
[task 2023-09-29T23:06:09.354Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(OowL): setting pair to state FROZEN: OowL|IP4:10.49.58.213:58594/TCP|IP4:10.49.58.213:58628/TCP(host(IP4:10.49.58.213:58594/TCP) so|candidate:1 1 TCP 2105491711 10.49.58.213 58628 typ host tcptype so)
[task 2023-09-29T23:06:09.354Z] 23:06:09     INFO -  ICE(IcePeer2)/CAND-PAIR(OowL): Pairing candidate IP4:10.49.58.213:58594/TCP (7d7f40ff):IP4:10.49.58.213:58628/TCP (7d7f40ff) priority=9043018044955066879 (7d7f40fffafe81ff)
[task 2023-09-29T23:06:09.354Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(NYZJ): setting pair to state FROZEN: NYZJ|IP4:10.49.58.213:54888/UDP|IP4:10.49.58.213:57494/UDP(host(IP4:10.49.58.213:54888/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 57494 typ host)
[task 2023-09-29T23:06:09.354Z] 23:06:09     INFO -  ICE(IcePeer2)/CAND-PAIR(NYZJ): Pairing candidate IP4:10.49.58.213:54888/UDP (7e7f00fe):IP4:10.49.58.213:57494/UDP (7e7f00fe) priority=9115005265987371517 (7e7f00fefcfe01fd)
[task 2023-09-29T23:06:09.355Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(qgPV): setting pair to state FROZEN: qgPV|IP4:10.49.58.213:55262/TCP|IP4:10.49.58.213:65042/TCP(host(IP4:10.49.58.213:55262/TCP) active|candidate:1 2 TCP 2105508094 10.49.58.213 65042 typ host tcptype passive)
[task 2023-09-29T23:06:09.355Z] 23:06:09     INFO -  ICE(IcePeer2)/CAND-PAIR(qgPV): Pairing candidate IP4:10.49.58.213:55262/TCP (7d7fc0fe):IP4:10.49.58.213:65042/TCP (7d7f80fe) priority=9043088409404342780 (7d7f80fefaff81fc)
[task 2023-09-29T23:06:09.355Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(ADAB): setting pair to state FROZEN: ADAB|IP4:10.49.58.213:53077/TCP|IP4:10.49.58.213:61449/TCP(host(IP4:10.49.58.213:53077/TCP) so|candidate:1 2 TCP 2105491710 10.49.58.213 61449 typ host tcptype so)
[task 2023-09-29T23:06:09.355Z] 23:06:09     INFO -  ICE(IcePeer2)/CAND-PAIR(ADAB): Pairing candidate IP4:10.49.58.213:53077/TCP (7d7f40fe):IP4:10.49.58.213:61449/TCP (7d7f40fe) priority=9043018040660099581 (7d7f40fefafe81fd)
[task 2023-09-29T23:06:09.356Z] 23:06:09     INFO -  ICE(IcePeer2): peer (IcePeer2) starting grace period timer for 5000 ms
[task 2023-09-29T23:06:09.356Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(CS8L): setting pair to state WAITING: CS8L|IP4:10.49.58.213:59083/UDP|IP4:10.49.58.213:60778/UDP(host(IP4:10.49.58.213:59083/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 60778 typ host)
[task 2023-09-29T23:06:09.356Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(2C4i): setting pair to state WAITING: 2C4i|IP4:10.49.58.213:52767/TCP|IP4:10.49.58.213:52943/TCP(host(IP4:10.49.58.213:52767/TCP) active|candidate:1 1 TCP 2105508095 10.49.58.213 52943 typ host tcptype passive)
[task 2023-09-29T23:06:09.356Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/ICE-STREAM(IcePeer2): Starting check timer for stream.
[task 2023-09-29T23:06:09.356Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(CS8L): setting pair to state IN_PROGRESS: CS8L|IP4:10.49.58.213:59083/UDP|IP4:10.49.58.213:60778/UDP(host(IP4:10.49.58.213:59083/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 60778 typ host)
[task 2023-09-29T23:06:09.356Z] 23:06:09     INFO -  ICE(IcePeer2): peer (IcePeer2) is now checking
[task 2023-09-29T23:06:09.356Z] 23:06:09     INFO -  ICE(IcePeer2): peer (IcePeer2) no streams with pre-answer requests
[task 2023-09-29T23:06:09.356Z] 23:06:09     INFO -  STUN-SERVER(server(IP4:10.49.58.213:0/UDP)): Falling back to default client, username=: ufrag:ufrag
[task 2023-09-29T23:06:09.357Z] 23:06:09     INFO -  STUN-SERVER(server(IP4:10.49.58.213:0/UDP)): Falling back to default client, username=: ufrag:ufrag
[task 2023-09-29T23:06:09.357Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(rCwD): setting pair to state FROZEN: rCwD|IP4:10.49.58.213:60778/UDP|IP4:10.49.58.213:59083/UDP(host(IP4:10.49.58.213:60778/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 59083 typ host)
[task 2023-09-29T23:06:09.357Z] 23:06:09     INFO -  ICE(IcePeer)/CAND-PAIR(rCwD): Pairing candidate IP4:10.49.58.213:60778/UDP (7e7f00ff):IP4:10.49.58.213:59083/UDP (7e7f00ff) priority=9115005270282338815 (7e7f00fffcfe01ff)
[task 2023-09-29T23:06:09.357Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(dbEN): setting pair to state FROZEN: dbEN|IP4:10.49.58.213:59530/TCP|IP4:10.49.58.213:59383/TCP(host(IP4:10.49.58.213:59530/TCP) active|candidate:1 1 TCP 2105508095 10.49.58.213 59383 typ host tcptype passive)
[task 2023-09-29T23:06:09.357Z] 23:06:09     INFO -  ICE(IcePeer)/CAND-PAIR(dbEN): Pairing candidate IP4:10.49.58.213:59530/TCP (7d7fc0ff):IP4:10.49.58.213:59383/TCP (7d7f80ff) priority=9043088413699310079 (7d7f80fffaff81ff)
[task 2023-09-29T23:06:09.358Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(u3u6): setting pair to state FROZEN: u3u6|IP4:10.49.58.213:58628/TCP|IP4:10.49.58.213:58594/TCP(host(IP4:10.49.58.213:58628/TCP) so|candidate:1 1 TCP 2105491711 10.49.58.213 58594 typ host tcptype so)
[task 2023-09-29T23:06:09.358Z] 23:06:09     INFO -  ICE(IcePeer)/CAND-PAIR(u3u6): Pairing candidate IP4:10.49.58.213:58628/TCP (7d7f40ff):IP4:10.49.58.213:58594/TCP (7d7f40ff) priority=9043018044955066879 (7d7f40fffafe81ff)
[task 2023-09-29T23:06:09.358Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(wre1): setting pair to state FROZEN: wre1|IP4:10.49.58.213:57494/UDP|IP4:10.49.58.213:54888/UDP(host(IP4:10.49.58.213:57494/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 54888 typ host)
[task 2023-09-29T23:06:09.358Z] 23:06:09     INFO -  ICE(IcePeer)/CAND-PAIR(wre1): Pairing candidate IP4:10.49.58.213:57494/UDP (7e7f00fe):IP4:10.49.58.213:54888/UDP (7e7f00fe) priority=9115005265987371517 (7e7f00fefcfe01fd)
[task 2023-09-29T23:06:09.359Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(C3R0): setting pair to state FROZEN: C3R0|IP4:10.49.58.213:62905/TCP|IP4:10.49.58.213:56192/TCP(host(IP4:10.49.58.213:62905/TCP) active|candidate:1 2 TCP 2105508094 10.49.58.213 56192 typ host tcptype passive)
[task 2023-09-29T23:06:09.359Z] 23:06:09     INFO -  ICE(IcePeer)/CAND-PAIR(C3R0): Pairing candidate IP4:10.49.58.213:62905/TCP (7d7fc0fe):IP4:10.49.58.213:56192/TCP (7d7f80fe) priority=9043088409404342781 (7d7f80fefaff81fd)
[task 2023-09-29T23:06:09.359Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(pgtT): setting pair to state FROZEN: pgtT|IP4:10.49.58.213:61449/TCP|IP4:10.49.58.213:53077/TCP(host(IP4:10.49.58.213:61449/TCP) so|candidate:1 2 TCP 2105491710 10.49.58.213 53077 typ host tcptype so)
[task 2023-09-29T23:06:09.359Z] 23:06:09     INFO -  ICE(IcePeer)/CAND-PAIR(pgtT): Pairing candidate IP4:10.49.58.213:61449/TCP (7d7f40fe):IP4:10.49.58.213:53077/TCP (7d7f40fe) priority=9043018040660099581 (7d7f40fefafe81fd)
[task 2023-09-29T23:06:09.360Z] 23:06:09     INFO -  ICE(IcePeer): peer (IcePeer) starting grace period timer for 5000 ms
[task 2023-09-29T23:06:09.360Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(rCwD): setting pair to state WAITING: rCwD|IP4:10.49.58.213:60778/UDP|IP4:10.49.58.213:59083/UDP(host(IP4:10.49.58.213:60778/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 59083 typ host)
[task 2023-09-29T23:06:09.360Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(dbEN): setting pair to state WAITING: dbEN|IP4:10.49.58.213:59530/TCP|IP4:10.49.58.213:59383/TCP(host(IP4:10.49.58.213:59530/TCP) active|candidate:1 1 TCP 2105508095 10.49.58.213 59383 typ host tcptype passive)
[task 2023-09-29T23:06:09.360Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/ICE-STREAM(IcePeer): Starting check timer for stream.
[task 2023-09-29T23:06:09.360Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(rCwD): setting pair to state IN_PROGRESS: rCwD|IP4:10.49.58.213:60778/UDP|IP4:10.49.58.213:59083/UDP(host(IP4:10.49.58.213:60778/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 59083 typ host)
[task 2023-09-29T23:06:09.361Z] 23:06:09     INFO -  ICE(IcePeer): peer (IcePeer) is now checking
[task 2023-09-29T23:06:09.361Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(rCwD): triggered check on rCwD|IP4:10.49.58.213:60778/UDP|IP4:10.49.58.213:59083/UDP(host(IP4:10.49.58.213:60778/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 59083 typ host)
[task 2023-09-29T23:06:09.361Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(rCwD): setting pair to state FROZEN: rCwD|IP4:10.49.58.213:60778/UDP|IP4:10.49.58.213:59083/UDP(host(IP4:10.49.58.213:60778/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 59083 typ host)
[task 2023-09-29T23:06:09.361Z] 23:06:09     INFO -  ICE(IcePeer)/CAND-PAIR(rCwD): Pairing candidate IP4:10.49.58.213:60778/UDP (7e7f00ff):IP4:10.49.58.213:59083/UDP (7e7f00ff) priority=9115005270282338815 (7e7f00fffcfe01ff)
[task 2023-09-29T23:06:09.362Z] 23:06:09     INFO -  CAND-PAIR(rCwD): Adding pair to check list and trigger check queue: rCwD|IP4:10.49.58.213:60778/UDP|IP4:10.49.58.213:59083/UDP(host(IP4:10.49.58.213:60778/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 59083 typ host)
[task 2023-09-29T23:06:09.362Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(rCwD): setting pair to state WAITING: rCwD|IP4:10.49.58.213:60778/UDP|IP4:10.49.58.213:59083/UDP(host(IP4:10.49.58.213:60778/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 59083 typ host)
[task 2023-09-29T23:06:09.362Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(rCwD): setting pair to state CANCELLED: rCwD|IP4:10.49.58.213:60778/UDP|IP4:10.49.58.213:59083/UDP(host(IP4:10.49.58.213:60778/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 59083 typ host)
[task 2023-09-29T23:06:09.362Z] 23:06:09     INFO -  STUN-CLIENT(CS8L|IP4:10.49.58.213:59083/UDP|IP4:10.49.58.213:60778/UDP(host(IP4:10.49.58.213:59083/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 60778 typ host)): Received response; processing
[task 2023-09-29T23:06:09.363Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(CS8L): setting pair to state SUCCEEDED: CS8L|IP4:10.49.58.213:59083/UDP|IP4:10.49.58.213:60778/UDP(host(IP4:10.49.58.213:59083/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 60778 typ host)
[task 2023-09-29T23:06:09.363Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(NYZJ): setting pair to state WAITING: NYZJ|IP4:10.49.58.213:54888/UDP|IP4:10.49.58.213:57494/UDP(host(IP4:10.49.58.213:54888/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 57494 typ host)
[task 2023-09-29T23:06:09.363Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/STREAM(IcePeer2)/COMP(1)/CAND-PAIR(CS8L): nominated pair is CS8L|IP4:10.49.58.213:59083/UDP|IP4:10.49.58.213:60778/UDP(host(IP4:10.49.58.213:59083/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 60778 typ host)
[task 2023-09-29T23:06:09.364Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/STREAM(IcePeer2)/COMP(1)/CAND-PAIR(CS8L): cancelling all pairs but CS8L|IP4:10.49.58.213:59083/UDP|IP4:10.49.58.213:60778/UDP(host(IP4:10.49.58.213:59083/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 60778 typ host)
[task 2023-09-29T23:06:09.364Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/STREAM(IcePeer2)/COMP(1)/CAND-PAIR(2C4i): cancelling FROZEN/WAITING pair 2C4i|IP4:10.49.58.213:52767/TCP|IP4:10.49.58.213:52943/TCP(host(IP4:10.49.58.213:52767/TCP) active|candidate:1 1 TCP 2105508095 10.49.58.213 52943 typ host tcptype passive) because CAND-PAIR(CS8L) was nominated.
[task 2023-09-29T23:06:09.364Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(2C4i): setting pair to state CANCELLED: 2C4i|IP4:10.49.58.213:52767/TCP|IP4:10.49.58.213:52943/TCP(host(IP4:10.49.58.213:52767/TCP) active|candidate:1 1 TCP 2105508095 10.49.58.213 52943 typ host tcptype passive)
[task 2023-09-29T23:06:09.365Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/STREAM(IcePeer2)/COMP(1)/CAND-PAIR(OowL): cancelling FROZEN/WAITING pair OowL|IP4:10.49.58.213:58594/TCP|IP4:10.49.58.213:58628/TCP(host(IP4:10.49.58.213:58594/TCP) so|candidate:1 1 TCP 2105491711 10.49.58.213 58628 typ host tcptype so) because CAND-PAIR(CS8L) was nominated.
[task 2023-09-29T23:06:09.365Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(OowL): setting pair to state CANCELLED: OowL|IP4:10.49.58.213:58594/TCP|IP4:10.49.58.213:58628/TCP(host(IP4:10.49.58.213:58594/TCP) so|candidate:1 1 TCP 2105491711 10.49.58.213 58628 typ host tcptype so)
[task 2023-09-29T23:06:09.365Z] 23:06:09     INFO -  STUN-CLIENT(rCwD|IP4:10.49.58.213:60778/UDP|IP4:10.49.58.213:59083/UDP(host(IP4:10.49.58.213:60778/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 59083 typ host)): Received response; processing
[task 2023-09-29T23:06:09.365Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(rCwD): setting pair to state SUCCEEDED: rCwD|IP4:10.49.58.213:60778/UDP|IP4:10.49.58.213:59083/UDP(host(IP4:10.49.58.213:60778/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 59083 typ host)
[task 2023-09-29T23:06:09.366Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(wre1): setting pair to state WAITING: wre1|IP4:10.49.58.213:57494/UDP|IP4:10.49.58.213:54888/UDP(host(IP4:10.49.58.213:57494/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 54888 typ host)
[task 2023-09-29T23:06:09.366Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/STREAM(IcePeer)/COMP(1)/CAND-PAIR(rCwD): nominated pair is rCwD|IP4:10.49.58.213:60778/UDP|IP4:10.49.58.213:59083/UDP(host(IP4:10.49.58.213:60778/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 59083 typ host)
[task 2023-09-29T23:06:09.366Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/STREAM(IcePeer)/COMP(1)/CAND-PAIR(rCwD): cancelling all pairs but rCwD|IP4:10.49.58.213:60778/UDP|IP4:10.49.58.213:59083/UDP(host(IP4:10.49.58.213:60778/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 59083 typ host)
[task 2023-09-29T23:06:09.367Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/STREAM(IcePeer)/COMP(1)/CAND-PAIR(rCwD): cancelling FROZEN/WAITING pair rCwD|IP4:10.49.58.213:60778/UDP|IP4:10.49.58.213:59083/UDP(host(IP4:10.49.58.213:60778/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 59083 typ host) in trigger check queue because CAND-PAIR(rCwD) was nominated.
[task 2023-09-29T23:06:09.367Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(rCwD): setting pair to state CANCELLED: rCwD|IP4:10.49.58.213:60778/UDP|IP4:10.49.58.213:59083/UDP(host(IP4:10.49.58.213:60778/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 59083 typ host)
[task 2023-09-29T23:06:09.367Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/STREAM(IcePeer)/COMP(1)/CAND-PAIR(dbEN): cancelling FROZEN/WAITING pair dbEN|IP4:10.49.58.213:59530/TCP|IP4:10.49.58.213:59383/TCP(host(IP4:10.49.58.213:59530/TCP) active|candidate:1 1 TCP 2105508095 10.49.58.213 59383 typ host tcptype passive) because CAND-PAIR(rCwD) was nominated.
[task 2023-09-29T23:06:09.368Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(dbEN): setting pair to state CANCELLED: dbEN|IP4:10.49.58.213:59530/TCP|IP4:10.49.58.213:59383/TCP(host(IP4:10.49.58.213:59530/TCP) active|candidate:1 1 TCP 2105508095 10.49.58.213 59383 typ host tcptype passive)
[task 2023-09-29T23:06:09.368Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/STREAM(IcePeer)/COMP(1)/CAND-PAIR(u3u6): cancelling FROZEN/WAITING pair u3u6|IP4:10.49.58.213:58628/TCP|IP4:10.49.58.213:58594/TCP(host(IP4:10.49.58.213:58628/TCP) so|candidate:1 1 TCP 2105491711 10.49.58.213 58594 typ host tcptype so) because CAND-PAIR(rCwD) was nominated.
[task 2023-09-29T23:06:09.368Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(u3u6): setting pair to state CANCELLED: u3u6|IP4:10.49.58.213:58628/TCP|IP4:10.49.58.213:58594/TCP(host(IP4:10.49.58.213:58628/TCP) so|candidate:1 1 TCP 2105491711 10.49.58.213 58594 typ host tcptype so)
[task 2023-09-29T23:06:09.368Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(NYZJ): setting pair to state IN_PROGRESS: NYZJ|IP4:10.49.58.213:54888/UDP|IP4:10.49.58.213:57494/UDP(host(IP4:10.49.58.213:54888/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 57494 typ host)
[task 2023-09-29T23:06:09.369Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(wre1): setting pair to state IN_PROGRESS: wre1|IP4:10.49.58.213:57494/UDP|IP4:10.49.58.213:54888/UDP(host(IP4:10.49.58.213:57494/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 54888 typ host)
[task 2023-09-29T23:06:09.369Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(wre1): triggered check on wre1|IP4:10.49.58.213:57494/UDP|IP4:10.49.58.213:54888/UDP(host(IP4:10.49.58.213:57494/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 54888 typ host)
[task 2023-09-29T23:06:09.369Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(wre1): setting pair to state FROZEN: wre1|IP4:10.49.58.213:57494/UDP|IP4:10.49.58.213:54888/UDP(host(IP4:10.49.58.213:57494/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 54888 typ host)
[task 2023-09-29T23:06:09.369Z] 23:06:09     INFO -  ICE(IcePeer)/CAND-PAIR(wre1): Pairing candidate IP4:10.49.58.213:57494/UDP (7e7f00fe):IP4:10.49.58.213:54888/UDP (7e7f00fe) priority=9115005265987371517 (7e7f00fefcfe01fd)
[task 2023-09-29T23:06:09.370Z] 23:06:09     INFO -  CAND-PAIR(wre1): Adding pair to check list and trigger check queue: wre1|IP4:10.49.58.213:57494/UDP|IP4:10.49.58.213:54888/UDP(host(IP4:10.49.58.213:57494/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 54888 typ host)
[task 2023-09-29T23:06:09.370Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(wre1): setting pair to state WAITING: wre1|IP4:10.49.58.213:57494/UDP|IP4:10.49.58.213:54888/UDP(host(IP4:10.49.58.213:57494/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 54888 typ host)
[task 2023-09-29T23:06:09.370Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(wre1): setting pair to state CANCELLED: wre1|IP4:10.49.58.213:57494/UDP|IP4:10.49.58.213:54888/UDP(host(IP4:10.49.58.213:57494/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 54888 typ host)
[task 2023-09-29T23:06:09.371Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(NYZJ): triggered check on NYZJ|IP4:10.49.58.213:54888/UDP|IP4:10.49.58.213:57494/UDP(host(IP4:10.49.58.213:54888/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 57494 typ host)
[task 2023-09-29T23:06:09.371Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(NYZJ): setting pair to state FROZEN: NYZJ|IP4:10.49.58.213:54888/UDP|IP4:10.49.58.213:57494/UDP(host(IP4:10.49.58.213:54888/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 57494 typ host)
[task 2023-09-29T23:06:09.371Z] 23:06:09     INFO -  ICE(IcePeer2)/CAND-PAIR(NYZJ): Pairing candidate IP4:10.49.58.213:54888/UDP (7e7f00fe):IP4:10.49.58.213:57494/UDP (7e7f00fe) priority=9115005265987371517 (7e7f00fefcfe01fd)
[task 2023-09-29T23:06:09.371Z] 23:06:09     INFO -  CAND-PAIR(NYZJ): Adding pair to check list and trigger check queue: NYZJ|IP4:10.49.58.213:54888/UDP|IP4:10.49.58.213:57494/UDP(host(IP4:10.49.58.213:54888/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 57494 typ host)
[task 2023-09-29T23:06:09.372Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(NYZJ): setting pair to state WAITING: NYZJ|IP4:10.49.58.213:54888/UDP|IP4:10.49.58.213:57494/UDP(host(IP4:10.49.58.213:54888/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 57494 typ host)
[task 2023-09-29T23:06:09.372Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(NYZJ): setting pair to state CANCELLED: NYZJ|IP4:10.49.58.213:54888/UDP|IP4:10.49.58.213:57494/UDP(host(IP4:10.49.58.213:54888/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 57494 typ host)
[task 2023-09-29T23:06:09.372Z] 23:06:09     INFO -  STUN-CLIENT(NYZJ|IP4:10.49.58.213:54888/UDP|IP4:10.49.58.213:57494/UDP(host(IP4:10.49.58.213:54888/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 57494 typ host)): Received response; processing
[task 2023-09-29T23:06:09.372Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(NYZJ): setting pair to state SUCCEEDED: NYZJ|IP4:10.49.58.213:54888/UDP|IP4:10.49.58.213:57494/UDP(host(IP4:10.49.58.213:54888/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 57494 typ host)
[task 2023-09-29T23:06:09.373Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/STREAM(IcePeer2)/COMP(2)/CAND-PAIR(NYZJ): nominated pair is NYZJ|IP4:10.49.58.213:54888/UDP|IP4:10.49.58.213:57494/UDP(host(IP4:10.49.58.213:54888/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 57494 typ host)
[task 2023-09-29T23:06:09.373Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/STREAM(IcePeer2)/COMP(2)/CAND-PAIR(NYZJ): cancelling all pairs but NYZJ|IP4:10.49.58.213:54888/UDP|IP4:10.49.58.213:57494/UDP(host(IP4:10.49.58.213:54888/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 57494 typ host)
[task 2023-09-29T23:06:09.373Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/STREAM(IcePeer2)/COMP(2)/CAND-PAIR(NYZJ): cancelling FROZEN/WAITING pair NYZJ|IP4:10.49.58.213:54888/UDP|IP4:10.49.58.213:57494/UDP(host(IP4:10.49.58.213:54888/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 57494 typ host) in trigger check queue because CAND-PAIR(NYZJ) was nominated.
[task 2023-09-29T23:06:09.374Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(NYZJ): setting pair to state CANCELLED: NYZJ|IP4:10.49.58.213:54888/UDP|IP4:10.49.58.213:57494/UDP(host(IP4:10.49.58.213:54888/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 57494 typ host)
[task 2023-09-29T23:06:09.374Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/STREAM(IcePeer2)/COMP(2)/CAND-PAIR(qgPV): cancelling FROZEN/WAITING pair qgPV|IP4:10.49.58.213:55262/TCP|IP4:10.49.58.213:65042/TCP(host(IP4:10.49.58.213:55262/TCP) active|candidate:1 2 TCP 2105508094 10.49.58.213 65042 typ host tcptype passive) because CAND-PAIR(NYZJ) was nominated.
[task 2023-09-29T23:06:09.374Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(qgPV): setting pair to state CANCELLED: qgPV|IP4:10.49.58.213:55262/TCP|IP4:10.49.58.213:65042/TCP(host(IP4:10.49.58.213:55262/TCP) active|candidate:1 2 TCP 2105508094 10.49.58.213 65042 typ host tcptype passive)
[task 2023-09-29T23:06:09.375Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/STREAM(IcePeer2)/COMP(2)/CAND-PAIR(ADAB): cancelling FROZEN/WAITING pair ADAB|IP4:10.49.58.213:53077/TCP|IP4:10.49.58.213:61449/TCP(host(IP4:10.49.58.213:53077/TCP) so|candidate:1 2 TCP 2105491710 10.49.58.213 61449 typ host tcptype so) because CAND-PAIR(NYZJ) was nominated.
[task 2023-09-29T23:06:09.375Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(ADAB): setting pair to state CANCELLED: ADAB|IP4:10.49.58.213:53077/TCP|IP4:10.49.58.213:61449/TCP(host(IP4:10.49.58.213:53077/TCP) so|candidate:1 2 TCP 2105491710 10.49.58.213 61449 typ host tcptype so)
[task 2023-09-29T23:06:09.375Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/ICE-STREAM(IcePeer2): all active components have nominated candidate pairs
[task 2023-09-29T23:06:09.375Z] 23:06:09     INFO -  ICE-PEER(IcePeer2): all checks completed success=1 fail=0
[task 2023-09-29T23:06:09.375Z] 23:06:09     INFO -  ICE(IcePeer2): peer (IcePeer2) cancelling grace period timer
[task 2023-09-29T23:06:09.376Z] 23:06:09     INFO -  STUN-CLIENT(wre1|IP4:10.49.58.213:57494/UDP|IP4:10.49.58.213:54888/UDP(host(IP4:10.49.58.213:57494/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 54888 typ host)): Received response; processing
[task 2023-09-29T23:06:09.376Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(wre1): setting pair to state SUCCEEDED: wre1|IP4:10.49.58.213:57494/UDP|IP4:10.49.58.213:54888/UDP(host(IP4:10.49.58.213:57494/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 54888 typ host)
[task 2023-09-29T23:06:09.376Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/STREAM(IcePeer)/COMP(2)/CAND-PAIR(wre1): nominated pair is wre1|IP4:10.49.58.213:57494/UDP|IP4:10.49.58.213:54888/UDP(host(IP4:10.49.58.213:57494/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 54888 typ host)
[task 2023-09-29T23:06:09.377Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/STREAM(IcePeer)/COMP(2)/CAND-PAIR(wre1): cancelling all pairs but wre1|IP4:10.49.58.213:57494/UDP|IP4:10.49.58.213:54888/UDP(host(IP4:10.49.58.213:57494/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 54888 typ host)
[task 2023-09-29T23:06:09.377Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/STREAM(IcePeer)/COMP(2)/CAND-PAIR(wre1): cancelling FROZEN/WAITING pair wre1|IP4:10.49.58.213:57494/UDP|IP4:10.49.58.213:54888/UDP(host(IP4:10.49.58.213:57494/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 54888 typ host) in trigger check queue because CAND-PAIR(wre1) was nominated.
[task 2023-09-29T23:06:09.377Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(wre1): setting pair to state CANCELLED: wre1|IP4:10.49.58.213:57494/UDP|IP4:10.49.58.213:54888/UDP(host(IP4:10.49.58.213:57494/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 54888 typ host)
[task 2023-09-29T23:06:09.378Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/STREAM(IcePeer)/COMP(2)/CAND-PAIR(C3R0): cancelling FROZEN/WAITING pair C3R0|IP4:10.49.58.213:62905/TCP|IP4:10.49.58.213:56192/TCP(host(IP4:10.49.58.213:62905/TCP) active|candidate:1 2 TCP 2105508094 10.49.58.213 56192 typ host tcptype passive) because CAND-PAIR(wre1) was nominated.
[task 2023-09-29T23:06:09.378Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(C3R0): setting pair to state CANCELLED: C3R0|IP4:10.49.58.213:62905/TCP|IP4:10.49.58.213:56192/TCP(host(IP4:10.49.58.213:62905/TCP) active|candidate:1 2 TCP 2105508094 10.49.58.213 56192 typ host tcptype passive)
[task 2023-09-29T23:06:09.378Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/STREAM(IcePeer)/COMP(2)/CAND-PAIR(pgtT): cancelling FROZEN/WAITING pair pgtT|IP4:10.49.58.213:61449/TCP|IP4:10.49.58.213:53077/TCP(host(IP4:10.49.58.213:61449/TCP) so|candidate:1 2 TCP 2105491710 10.49.58.213 53077 typ host tcptype so) because CAND-PAIR(wre1) was nominated.
[task 2023-09-29T23:06:09.378Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(pgtT): setting pair to state CANCELLED: pgtT|IP4:10.49.58.213:61449/TCP|IP4:10.49.58.213:53077/TCP(host(IP4:10.49.58.213:61449/TCP) so|candidate:1 2 TCP 2105491710 10.49.58.213 53077 typ host tcptype so)
[task 2023-09-29T23:06:09.379Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/ICE-STREAM(IcePeer): all active components have nominated candidate pairs
[task 2023-09-29T23:06:09.379Z] 23:06:09     INFO -  ICE-PEER(IcePeer): all checks completed success=1 fail=0
[task 2023-09-29T23:06:09.379Z] 23:06:09     INFO -  ICE(IcePeer): peer (IcePeer) cancelling grace period timer
[task 2023-09-29T23:06:09.379Z] 23:06:09     INFO -  ICE(IcePeer): no local addresses available
[task 2023-09-29T23:06:09.379Z] 23:06:09     INFO -  ICE(IcePeer2): no local addresses available
[task 2023-09-29T23:06:09.379Z] 23:06:09     INFO -  ICE(IcePeer): All candidates initialized
[task 2023-09-29T23:06:09.379Z] 23:06:09     INFO -  ICE(IcePeer2): All candidates initialized
[task 2023-09-29T23:06:09.380Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(Qkom): setting pair to state FROZEN: Qkom|IP4:10.49.58.213:55716/UDP|IP4:10.49.58.213:49614/UDP(host(IP4:10.49.58.213:55716/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 49614 typ host)
[task 2023-09-29T23:06:09.380Z] 23:06:09     INFO -  ICE(IcePeer2)/CAND-PAIR(Qkom): Pairing candidate IP4:10.49.58.213:55716/UDP (7e7f00ff):IP4:10.49.58.213:49614/UDP (7e7f00ff) priority=9115005270282338815 (7e7f00fffcfe01ff)
[task 2023-09-29T23:06:09.380Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(WGqm): setting pair to state FROZEN: WGqm|IP4:10.49.58.213:63846/TCP|IP4:10.49.58.213:50149/TCP(host(IP4:10.49.58.213:63846/TCP) active|candidate:1 1 TCP 2105508095 10.49.58.213 50149 typ host tcptype passive)
[task 2023-09-29T23:06:09.380Z] 23:06:09     INFO -  ICE(IcePeer2)/CAND-PAIR(WGqm): Pairing candidate IP4:10.49.58.213:63846/TCP (7d7fc0ff):IP4:10.49.58.213:50149/TCP (7d7f80ff) priority=9043088413699310078 (7d7f80fffaff81fe)
[task 2023-09-29T23:06:09.381Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(O5+5): setting pair to state FROZEN: O5+5|IP4:10.49.58.213:61968/TCP|IP4:10.49.58.213:49583/TCP(host(IP4:10.49.58.213:61968/TCP) so|candidate:1 1 TCP 2105491711 10.49.58.213 49583 typ host tcptype so)
[task 2023-09-29T23:06:09.381Z] 23:06:09     INFO -  ICE(IcePeer2)/CAND-PAIR(O5+5): Pairing candidate IP4:10.49.58.213:61968/TCP (7d7f40ff):IP4:10.49.58.213:49583/TCP (7d7f40ff) priority=9043018044955066879 (7d7f40fffafe81ff)
[task 2023-09-29T23:06:09.381Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(20tL): setting pair to state FROZEN: 20tL|IP4:10.49.58.213:57979/UDP|IP4:10.49.58.213:51605/UDP(host(IP4:10.49.58.213:57979/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 51605 typ host)
[task 2023-09-29T23:06:09.381Z] 23:06:09     INFO -  ICE(IcePeer2)/CAND-PAIR(20tL): Pairing candidate IP4:10.49.58.213:57979/UDP (7e7f00fe):IP4:10.49.58.213:51605/UDP (7e7f00fe) priority=9115005265987371517 (7e7f00fefcfe01fd)
[task 2023-09-29T23:06:09.381Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(QSIU): setting pair to state FROZEN: QSIU|IP4:10.49.58.213:54339/TCP|IP4:10.49.58.213:49862/TCP(host(IP4:10.49.58.213:54339/TCP) active|candidate:1 2 TCP 2105508094 10.49.58.213 49862 typ host tcptype passive)
[task 2023-09-29T23:06:09.382Z] 23:06:09     INFO -  ICE(IcePeer2)/CAND-PAIR(QSIU): Pairing candidate IP4:10.49.58.213:54339/TCP (7d7fc0fe):IP4:10.49.58.213:49862/TCP (7d7f80fe) priority=9043088409404342780 (7d7f80fefaff81fc)
[task 2023-09-29T23:06:09.382Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(Xxnf): setting pair to state FROZEN: Xxnf|IP4:10.49.58.213:57157/TCP|IP4:10.49.58.213:60357/TCP(host(IP4:10.49.58.213:57157/TCP) so|candidate:1 2 TCP 2105491710 10.49.58.213 60357 typ host tcptype so)
[task 2023-09-29T23:06:09.382Z] 23:06:09     INFO -  ICE(IcePeer2)/CAND-PAIR(Xxnf): Pairing candidate IP4:10.49.58.213:57157/TCP (7d7f40fe):IP4:10.49.58.213:60357/TCP (7d7f40fe) priority=9043018040660099581 (7d7f40fefafe81fd)
[task 2023-09-29T23:06:09.382Z] 23:06:09     INFO -  ICE(IcePeer2): peer (IcePeer2) starting grace period timer for 5000 ms
[task 2023-09-29T23:06:09.383Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(Qkom): setting pair to state WAITING: Qkom|IP4:10.49.58.213:55716/UDP|IP4:10.49.58.213:49614/UDP(host(IP4:10.49.58.213:55716/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 49614 typ host)
[task 2023-09-29T23:06:09.383Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(WGqm): setting pair to state WAITING: WGqm|IP4:10.49.58.213:63846/TCP|IP4:10.49.58.213:50149/TCP(host(IP4:10.49.58.213:63846/TCP) active|candidate:1 1 TCP 2105508095 10.49.58.213 50149 typ host tcptype passive)
[task 2023-09-29T23:06:09.383Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/ICE-STREAM(IcePeer2): Starting check timer for stream.
[task 2023-09-29T23:06:09.383Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(Qkom): setting pair to state IN_PROGRESS: Qkom|IP4:10.49.58.213:55716/UDP|IP4:10.49.58.213:49614/UDP(host(IP4:10.49.58.213:55716/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 49614 typ host)
[task 2023-09-29T23:06:09.383Z] 23:06:09     INFO -  ICE(IcePeer2): peer (IcePeer2) is now checking
[task 2023-09-29T23:06:09.384Z] 23:06:09     INFO -  ICE(IcePeer2): peer (IcePeer2) no streams with pre-answer requests
[task 2023-09-29T23:06:09.384Z] 23:06:09     INFO -  STUN-SERVER(server(IP4:10.49.58.213:0/UDP)): Falling back to default client, username=: ufrag:ufrag
[task 2023-09-29T23:06:09.384Z] 23:06:09     INFO -  STUN-SERVER(server(IP4:10.49.58.213:0/UDP)): Falling back to default client, username=: ufrag:ufrag
[task 2023-09-29T23:06:09.384Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(zJuu): setting pair to state FROZEN: zJuu|IP4:10.49.58.213:49614/UDP|IP4:10.49.58.213:55716/UDP(host(IP4:10.49.58.213:49614/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 55716 typ host)
[task 2023-09-29T23:06:09.384Z] 23:06:09     INFO -  ICE(IcePeer)/CAND-PAIR(zJuu): Pairing candidate IP4:10.49.58.213:49614/UDP (7e7f00ff):IP4:10.49.58.213:55716/UDP (7e7f00ff) priority=9115005270282338815 (7e7f00fffcfe01ff)
[task 2023-09-29T23:06:09.384Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(Cjep): setting pair to state FROZEN: Cjep|IP4:10.49.58.213:62389/TCP|IP4:10.49.58.213:50912/TCP(host(IP4:10.49.58.213:62389/TCP) active|candidate:1 1 TCP 2105508095 10.49.58.213 50912 typ host tcptype passive)
[task 2023-09-29T23:06:09.385Z] 23:06:09     INFO -  ICE(IcePeer)/CAND-PAIR(Cjep): Pairing candidate IP4:10.49.58.213:62389/TCP (7d7fc0ff):IP4:10.49.58.213:50912/TCP (7d7f80ff) priority=9043088413699310079 (7d7f80fffaff81ff)
[task 2023-09-29T23:06:09.385Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(xQoD): setting pair to state FROZEN: xQoD|IP4:10.49.58.213:49583/TCP|IP4:10.49.58.213:61968/TCP(host(IP4:10.49.58.213:49583/TCP) so|candidate:1 1 TCP 2105491711 10.49.58.213 61968 typ host tcptype so)
[task 2023-09-29T23:06:09.385Z] 23:06:09     INFO -  ICE(IcePeer)/CAND-PAIR(xQoD): Pairing candidate IP4:10.49.58.213:49583/TCP (7d7f40ff):IP4:10.49.58.213:61968/TCP (7d7f40ff) priority=9043018044955066879 (7d7f40fffafe81ff)
[task 2023-09-29T23:06:09.385Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(rjRw): setting pair to state FROZEN: rjRw|IP4:10.49.58.213:51605/UDP|IP4:10.49.58.213:57979/UDP(host(IP4:10.49.58.213:51605/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 57979 typ host)
[task 2023-09-29T23:06:09.386Z] 23:06:09     INFO -  ICE(IcePeer)/CAND-PAIR(rjRw): Pairing candidate IP4:10.49.58.213:51605/UDP (7e7f00fe):IP4:10.49.58.213:57979/UDP (7e7f00fe) priority=9115005265987371517 (7e7f00fefcfe01fd)
[task 2023-09-29T23:06:09.386Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(BJ8G): setting pair to state FROZEN: BJ8G|IP4:10.49.58.213:64173/TCP|IP4:10.49.58.213:56810/TCP(host(IP4:10.49.58.213:64173/TCP) active|candidate:1 2 TCP 2105508094 10.49.58.213 56810 typ host tcptype passive)
[task 2023-09-29T23:06:09.386Z] 23:06:09     INFO -  ICE(IcePeer)/CAND-PAIR(BJ8G): Pairing candidate IP4:10.49.58.213:64173/TCP (7d7fc0fe):IP4:10.49.58.213:56810/TCP (7d7f80fe) priority=9043088409404342781 (7d7f80fefaff81fd)
[task 2023-09-29T23:06:09.386Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(YgmY): setting pair to state FROZEN: YgmY|IP4:10.49.58.213:60357/TCP|IP4:10.49.58.213:57157/TCP(host(IP4:10.49.58.213:60357/TCP) so|candidate:1 2 TCP 2105491710 10.49.58.213 57157 typ host tcptype so)
[task 2023-09-29T23:06:09.387Z] 23:06:09     INFO -  ICE(IcePeer)/CAND-PAIR(YgmY): Pairing candidate IP4:10.49.58.213:60357/TCP (7d7f40fe):IP4:10.49.58.213:57157/TCP (7d7f40fe) priority=9043018040660099581 (7d7f40fefafe81fd)
[task 2023-09-29T23:06:09.387Z] 23:06:09     INFO -  ICE(IcePeer): peer (IcePeer) starting grace period timer for 5000 ms
[task 2023-09-29T23:06:09.387Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(zJuu): setting pair to state WAITING: zJuu|IP4:10.49.58.213:49614/UDP|IP4:10.49.58.213:55716/UDP(host(IP4:10.49.58.213:49614/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 55716 typ host)
[task 2023-09-29T23:06:09.387Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(Cjep): setting pair to state WAITING: Cjep|IP4:10.49.58.213:62389/TCP|IP4:10.49.58.213:50912/TCP(host(IP4:10.49.58.213:62389/TCP) active|candidate:1 1 TCP 2105508095 10.49.58.213 50912 typ host tcptype passive)
[task 2023-09-29T23:06:09.388Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/ICE-STREAM(IcePeer): Starting check timer for stream.
[task 2023-09-29T23:06:09.388Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(zJuu): setting pair to state IN_PROGRESS: zJuu|IP4:10.49.58.213:49614/UDP|IP4:10.49.58.213:55716/UDP(host(IP4:10.49.58.213:49614/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 55716 typ host)
[task 2023-09-29T23:06:09.388Z] 23:06:09     INFO -  ICE(IcePeer): peer (IcePeer) is now checking
[task 2023-09-29T23:06:09.388Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(zJuu): triggered check on zJuu|IP4:10.49.58.213:49614/UDP|IP4:10.49.58.213:55716/UDP(host(IP4:10.49.58.213:49614/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 55716 typ host)
[task 2023-09-29T23:06:09.388Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(zJuu): setting pair to state FROZEN: zJuu|IP4:10.49.58.213:49614/UDP|IP4:10.49.58.213:55716/UDP(host(IP4:10.49.58.213:49614/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 55716 typ host)
[task 2023-09-29T23:06:09.389Z] 23:06:09     INFO -  ICE(IcePeer)/CAND-PAIR(zJuu): Pairing candidate IP4:10.49.58.213:49614/UDP (7e7f00ff):IP4:10.49.58.213:55716/UDP (7e7f00ff) priority=9115005270282338815 (7e7f00fffcfe01ff)
[task 2023-09-29T23:06:09.389Z] 23:06:09     INFO -  CAND-PAIR(zJuu): Adding pair to check list and trigger check queue: zJuu|IP4:10.49.58.213:49614/UDP|IP4:10.49.58.213:55716/UDP(host(IP4:10.49.58.213:49614/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 55716 typ host)
[task 2023-09-29T23:06:09.389Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(zJuu): setting pair to state WAITING: zJuu|IP4:10.49.58.213:49614/UDP|IP4:10.49.58.213:55716/UDP(host(IP4:10.49.58.213:49614/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 55716 typ host)
[task 2023-09-29T23:06:09.390Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(zJuu): setting pair to state CANCELLED: zJuu|IP4:10.49.58.213:49614/UDP|IP4:10.49.58.213:55716/UDP(host(IP4:10.49.58.213:49614/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 55716 typ host)
[task 2023-09-29T23:06:09.390Z] 23:06:09     INFO -  STUN-CLIENT(Qkom|IP4:10.49.58.213:55716/UDP|IP4:10.49.58.213:49614/UDP(host(IP4:10.49.58.213:55716/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 49614 typ host)): Received response; processing
[task 2023-09-29T23:06:09.390Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(Qkom): setting pair to state SUCCEEDED: Qkom|IP4:10.49.58.213:55716/UDP|IP4:10.49.58.213:49614/UDP(host(IP4:10.49.58.213:55716/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 49614 typ host)
[task 2023-09-29T23:06:09.390Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(20tL): setting pair to state WAITING: 20tL|IP4:10.49.58.213:57979/UDP|IP4:10.49.58.213:51605/UDP(host(IP4:10.49.58.213:57979/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 51605 typ host)
[task 2023-09-29T23:06:09.391Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/STREAM(IcePeer2)/COMP(1)/CAND-PAIR(Qkom): nominated pair is Qkom|IP4:10.49.58.213:55716/UDP|IP4:10.49.58.213:49614/UDP(host(IP4:10.49.58.213:55716/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 49614 typ host)
[task 2023-09-29T23:06:09.391Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/STREAM(IcePeer2)/COMP(1)/CAND-PAIR(Qkom): cancelling all pairs but Qkom|IP4:10.49.58.213:55716/UDP|IP4:10.49.58.213:49614/UDP(host(IP4:10.49.58.213:55716/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 49614 typ host)
[task 2023-09-29T23:06:09.391Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/STREAM(IcePeer2)/COMP(1)/CAND-PAIR(WGqm): cancelling FROZEN/WAITING pair WGqm|IP4:10.49.58.213:63846/TCP|IP4:10.49.58.213:50149/TCP(host(IP4:10.49.58.213:63846/TCP) active|candidate:1 1 TCP 2105508095 10.49.58.213 50149 typ host tcptype passive) because CAND-PAIR(Qkom) was nominated.
[task 2023-09-29T23:06:09.392Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(WGqm): setting pair to state CANCELLED: WGqm|IP4:10.49.58.213:63846/TCP|IP4:10.49.58.213:50149/TCP(host(IP4:10.49.58.213:63846/TCP) active|candidate:1 1 TCP 2105508095 10.49.58.213 50149 typ host tcptype passive)
[task 2023-09-29T23:06:09.392Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/STREAM(IcePeer2)/COMP(1)/CAND-PAIR(O5+5): cancelling FROZEN/WAITING pair O5+5|IP4:10.49.58.213:61968/TCP|IP4:10.49.58.213:49583/TCP(host(IP4:10.49.58.213:61968/TCP) so|candidate:1 1 TCP 2105491711 10.49.58.213 49583 typ host tcptype so) because CAND-PAIR(Qkom) was nominated.
[task 2023-09-29T23:06:09.392Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(O5+5): setting pair to state CANCELLED: O5+5|IP4:10.49.58.213:61968/TCP|IP4:10.49.58.213:49583/TCP(host(IP4:10.49.58.213:61968/TCP) so|candidate:1 1 TCP 2105491711 10.49.58.213 49583 typ host tcptype so)
[task 2023-09-29T23:06:09.393Z] 23:06:09     INFO -  STUN-CLIENT(zJuu|IP4:10.49.58.213:49614/UDP|IP4:10.49.58.213:55716/UDP(host(IP4:10.49.58.213:49614/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 55716 typ host)): Received response; processing
[task 2023-09-29T23:06:09.393Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(zJuu): setting pair to state SUCCEEDED: zJuu|IP4:10.49.58.213:49614/UDP|IP4:10.49.58.213:55716/UDP(host(IP4:10.49.58.213:49614/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 55716 typ host)
[task 2023-09-29T23:06:09.393Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(rjRw): setting pair to state WAITING: rjRw|IP4:10.49.58.213:51605/UDP|IP4:10.49.58.213:57979/UDP(host(IP4:10.49.58.213:51605/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 57979 typ host)
[task 2023-09-29T23:06:09.393Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/STREAM(IcePeer)/COMP(1)/CAND-PAIR(zJuu): nominated pair is zJuu|IP4:10.49.58.213:49614/UDP|IP4:10.49.58.213:55716/UDP(host(IP4:10.49.58.213:49614/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 55716 typ host)
[task 2023-09-29T23:06:09.394Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/STREAM(IcePeer)/COMP(1)/CAND-PAIR(zJuu): cancelling all pairs but zJuu|IP4:10.49.58.213:49614/UDP|IP4:10.49.58.213:55716/UDP(host(IP4:10.49.58.213:49614/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 55716 typ host)
[task 2023-09-29T23:06:09.394Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/STREAM(IcePeer)/COMP(1)/CAND-PAIR(zJuu): cancelling FROZEN/WAITING pair zJuu|IP4:10.49.58.213:49614/UDP|IP4:10.49.58.213:55716/UDP(host(IP4:10.49.58.213:49614/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 55716 typ host) in trigger check queue because CAND-PAIR(zJuu) was nominated.
[task 2023-09-29T23:06:09.394Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(zJuu): setting pair to state CANCELLED: zJuu|IP4:10.49.58.213:49614/UDP|IP4:10.49.58.213:55716/UDP(host(IP4:10.49.58.213:49614/UDP)|candidate:0 1 UDP 2122252543 10.49.58.213 55716 typ host)
[task 2023-09-29T23:06:09.395Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/STREAM(IcePeer)/COMP(1)/CAND-PAIR(Cjep): cancelling FROZEN/WAITING pair Cjep|IP4:10.49.58.213:62389/TCP|IP4:10.49.58.213:50912/TCP(host(IP4:10.49.58.213:62389/TCP) active|candidate:1 1 TCP 2105508095 10.49.58.213 50912 typ host tcptype passive) because CAND-PAIR(zJuu) was nominated.
[task 2023-09-29T23:06:09.395Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(Cjep): setting pair to state CANCELLED: Cjep|IP4:10.49.58.213:62389/TCP|IP4:10.49.58.213:50912/TCP(host(IP4:10.49.58.213:62389/TCP) active|candidate:1 1 TCP 2105508095 10.49.58.213 50912 typ host tcptype passive)
[task 2023-09-29T23:06:09.395Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/STREAM(IcePeer)/COMP(1)/CAND-PAIR(xQoD): cancelling FROZEN/WAITING pair xQoD|IP4:10.49.58.213:49583/TCP|IP4:10.49.58.213:61968/TCP(host(IP4:10.49.58.213:49583/TCP) so|candidate:1 1 TCP 2105491711 10.49.58.213 61968 typ host tcptype so) because CAND-PAIR(zJuu) was nominated.
[task 2023-09-29T23:06:09.396Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(xQoD): setting pair to state CANCELLED: xQoD|IP4:10.49.58.213:49583/TCP|IP4:10.49.58.213:61968/TCP(host(IP4:10.49.58.213:49583/TCP) so|candidate:1 1 TCP 2105491711 10.49.58.213 61968 typ host tcptype so)
[task 2023-09-29T23:06:09.396Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(20tL): setting pair to state IN_PROGRESS: 20tL|IP4:10.49.58.213:57979/UDP|IP4:10.49.58.213:51605/UDP(host(IP4:10.49.58.213:57979/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 51605 typ host)
[task 2023-09-29T23:06:09.396Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(rjRw): setting pair to state IN_PROGRESS: rjRw|IP4:10.49.58.213:51605/UDP|IP4:10.49.58.213:57979/UDP(host(IP4:10.49.58.213:51605/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 57979 typ host)
[task 2023-09-29T23:06:09.396Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(rjRw): triggered check on rjRw|IP4:10.49.58.213:51605/UDP|IP4:10.49.58.213:57979/UDP(host(IP4:10.49.58.213:51605/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 57979 typ host)
[task 2023-09-29T23:06:09.397Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(rjRw): setting pair to state FROZEN: rjRw|IP4:10.49.58.213:51605/UDP|IP4:10.49.58.213:57979/UDP(host(IP4:10.49.58.213:51605/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 57979 typ host)
[task 2023-09-29T23:06:09.397Z] 23:06:09     INFO -  ICE(IcePeer)/CAND-PAIR(rjRw): Pairing candidate IP4:10.49.58.213:51605/UDP (7e7f00fe):IP4:10.49.58.213:57979/UDP (7e7f00fe) priority=9115005265987371517 (7e7f00fefcfe01fd)
[task 2023-09-29T23:06:09.397Z] 23:06:09     INFO -  CAND-PAIR(rjRw): Adding pair to check list and trigger check queue: rjRw|IP4:10.49.58.213:51605/UDP|IP4:10.49.58.213:57979/UDP(host(IP4:10.49.58.213:51605/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 57979 typ host)
[task 2023-09-29T23:06:09.397Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(rjRw): setting pair to state WAITING: rjRw|IP4:10.49.58.213:51605/UDP|IP4:10.49.58.213:57979/UDP(host(IP4:10.49.58.213:51605/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 57979 typ host)
[task 2023-09-29T23:06:09.398Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(rjRw): setting pair to state CANCELLED: rjRw|IP4:10.49.58.213:51605/UDP|IP4:10.49.58.213:57979/UDP(host(IP4:10.49.58.213:51605/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 57979 typ host)
[task 2023-09-29T23:06:09.398Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(20tL): triggered check on 20tL|IP4:10.49.58.213:57979/UDP|IP4:10.49.58.213:51605/UDP(host(IP4:10.49.58.213:57979/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 51605 typ host)
[task 2023-09-29T23:06:09.398Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(20tL): setting pair to state FROZEN: 20tL|IP4:10.49.58.213:57979/UDP|IP4:10.49.58.213:51605/UDP(host(IP4:10.49.58.213:57979/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 51605 typ host)
[task 2023-09-29T23:06:09.399Z] 23:06:09     INFO -  ICE(IcePeer2)/CAND-PAIR(20tL): Pairing candidate IP4:10.49.58.213:57979/UDP (7e7f00fe):IP4:10.49.58.213:51605/UDP (7e7f00fe) priority=9115005265987371517 (7e7f00fefcfe01fd)
[task 2023-09-29T23:06:09.399Z] 23:06:09     INFO -  CAND-PAIR(20tL): Adding pair to check list and trigger check queue: 20tL|IP4:10.49.58.213:57979/UDP|IP4:10.49.58.213:51605/UDP(host(IP4:10.49.58.213:57979/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 51605 typ host)
[task 2023-09-29T23:06:09.399Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(20tL): setting pair to state WAITING: 20tL|IP4:10.49.58.213:57979/UDP|IP4:10.49.58.213:51605/UDP(host(IP4:10.49.58.213:57979/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 51605 typ host)
[task 2023-09-29T23:06:09.399Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(20tL): setting pair to state CANCELLED: 20tL|IP4:10.49.58.213:57979/UDP|IP4:10.49.58.213:51605/UDP(host(IP4:10.49.58.213:57979/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 51605 typ host)
[task 2023-09-29T23:06:09.400Z] 23:06:09     INFO -  STUN-CLIENT(20tL|IP4:10.49.58.213:57979/UDP|IP4:10.49.58.213:51605/UDP(host(IP4:10.49.58.213:57979/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 51605 typ host)): Received response; processing
[task 2023-09-29T23:06:09.400Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(20tL): setting pair to state SUCCEEDED: 20tL|IP4:10.49.58.213:57979/UDP|IP4:10.49.58.213:51605/UDP(host(IP4:10.49.58.213:57979/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 51605 typ host)
[task 2023-09-29T23:06:09.400Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/STREAM(IcePeer2)/COMP(2)/CAND-PAIR(20tL): nominated pair is 20tL|IP4:10.49.58.213:57979/UDP|IP4:10.49.58.213:51605/UDP(host(IP4:10.49.58.213:57979/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 51605 typ host)
[task 2023-09-29T23:06:09.400Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/STREAM(IcePeer2)/COMP(2)/CAND-PAIR(20tL): cancelling all pairs but 20tL|IP4:10.49.58.213:57979/UDP|IP4:10.49.58.213:51605/UDP(host(IP4:10.49.58.213:57979/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 51605 typ host)
[task 2023-09-29T23:06:09.401Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/STREAM(IcePeer2)/COMP(2)/CAND-PAIR(20tL): cancelling FROZEN/WAITING pair 20tL|IP4:10.49.58.213:57979/UDP|IP4:10.49.58.213:51605/UDP(host(IP4:10.49.58.213:57979/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 51605 typ host) in trigger check queue because CAND-PAIR(20tL) was nominated.
[task 2023-09-29T23:06:09.401Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(20tL): setting pair to state CANCELLED: 20tL|IP4:10.49.58.213:57979/UDP|IP4:10.49.58.213:51605/UDP(host(IP4:10.49.58.213:57979/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 51605 typ host)
[task 2023-09-29T23:06:09.401Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/STREAM(IcePeer2)/COMP(2)/CAND-PAIR(QSIU): cancelling FROZEN/WAITING pair QSIU|IP4:10.49.58.213:54339/TCP|IP4:10.49.58.213:49862/TCP(host(IP4:10.49.58.213:54339/TCP) active|candidate:1 2 TCP 2105508094 10.49.58.213 49862 typ host tcptype passive) because CAND-PAIR(20tL) was nominated.
[task 2023-09-29T23:06:09.402Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(QSIU): setting pair to state CANCELLED: QSIU|IP4:10.49.58.213:54339/TCP|IP4:10.49.58.213:49862/TCP(host(IP4:10.49.58.213:54339/TCP) active|candidate:1 2 TCP 2105508094 10.49.58.213 49862 typ host tcptype passive)
[task 2023-09-29T23:06:09.402Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/STREAM(IcePeer2)/COMP(2)/CAND-PAIR(Xxnf): cancelling FROZEN/WAITING pair Xxnf|IP4:10.49.58.213:57157/TCP|IP4:10.49.58.213:60357/TCP(host(IP4:10.49.58.213:57157/TCP) so|candidate:1 2 TCP 2105491710 10.49.58.213 60357 typ host tcptype so) because CAND-PAIR(20tL) was nominated.
[task 2023-09-29T23:06:09.402Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/CAND-PAIR(Xxnf): setting pair to state CANCELLED: Xxnf|IP4:10.49.58.213:57157/TCP|IP4:10.49.58.213:60357/TCP(host(IP4:10.49.58.213:57157/TCP) so|candidate:1 2 TCP 2105491710 10.49.58.213 60357 typ host tcptype so)
[task 2023-09-29T23:06:09.402Z] 23:06:09     INFO -  ICE-PEER(IcePeer2)/ICE-STREAM(IcePeer2): all active components have nominated candidate pairs
[task 2023-09-29T23:06:09.402Z] 23:06:09     INFO -  ICE-PEER(IcePeer2): all checks completed success=1 fail=0
[task 2023-09-29T23:06:09.403Z] 23:06:09     INFO -  ICE(IcePeer2): peer (IcePeer2) cancelling grace period timer
[task 2023-09-29T23:06:09.403Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(rjRw): setting pair to state IN_PROGRESS: rjRw|IP4:10.49.58.213:51605/UDP|IP4:10.49.58.213:57979/UDP(host(IP4:10.49.58.213:51605/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 57979 typ host)
[task 2023-09-29T23:06:09.403Z] 23:06:09     INFO -  STUN-CLIENT(rjRw|IP4:10.49.58.213:51605/UDP|IP4:10.49.58.213:57979/UDP(host(IP4:10.49.58.213:51605/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 57979 typ host)): Received response; processing
[task 2023-09-29T23:06:09.403Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(rjRw): setting pair to state SUCCEEDED: rjRw|IP4:10.49.58.213:51605/UDP|IP4:10.49.58.213:57979/UDP(host(IP4:10.49.58.213:51605/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 57979 typ host)
[task 2023-09-29T23:06:09.404Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/STREAM(IcePeer)/COMP(2)/CAND-PAIR(rjRw): nominated pair is rjRw|IP4:10.49.58.213:51605/UDP|IP4:10.49.58.213:57979/UDP(host(IP4:10.49.58.213:51605/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 57979 typ host)
[task 2023-09-29T23:06:09.404Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/STREAM(IcePeer)/COMP(2)/CAND-PAIR(rjRw): cancelling all pairs but rjRw|IP4:10.49.58.213:51605/UDP|IP4:10.49.58.213:57979/UDP(host(IP4:10.49.58.213:51605/UDP)|candidate:0 2 UDP 2122252542 10.49.58.213 57979 typ host)
[task 2023-09-29T23:06:09.404Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/STREAM(IcePeer)/COMP(2)/CAND-PAIR(BJ8G): cancelling FROZEN/WAITING pair BJ8G|IP4:10.49.58.213:64173/TCP|IP4:10.49.58.213:56810/TCP(host(IP4:10.49.58.213:64173/TCP) active|candidate:1 2 TCP 2105508094 10.49.58.213 56810 typ host tcptype passive) because CAND-PAIR(rjRw) was nominated.
[task 2023-09-29T23:06:09.404Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(BJ8G): setting pair to state CANCELLED: BJ8G|IP4:10.49.58.213:64173/TCP|IP4:10.49.58.213:56810/TCP(host(IP4:10.49.58.213:64173/TCP) active|candidate:1 2 TCP 2105508094 10.49.58.213 56810 typ host tcptype passive)
[task 2023-09-29T23:06:09.405Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/STREAM(IcePeer)/COMP(2)/CAND-PAIR(YgmY): cancelling FROZEN/WAITING pair YgmY|IP4:10.49.58.213:60357/TCP|IP4:10.49.58.213:57157/TCP(host(IP4:10.49.58.213:60357/TCP) so|candidate:1 2 TCP 2105491710 10.49.58.213 57157 typ host tcptype so) because CAND-PAIR(rjRw) was nominated.
[task 2023-09-29T23:06:09.405Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/CAND-PAIR(YgmY): setting pair to state CANCELLED: YgmY|IP4:10.49.58.213:60357/TCP|IP4:10.49.58.213:57157/TCP(host(IP4:10.49.58.213:60357/TCP) so|candidate:1 2 TCP 2105491710 10.49.58.213 57157 typ host tcptype so)
[task 2023-09-29T23:06:09.405Z] 23:06:09     INFO -  ICE-PEER(IcePeer)/ICE-STREAM(IcePeer): all active components have nominated candidate pairs
[task 2023-09-29T23:06:09.405Z] 23:06:09     INFO -  ICE-PEER(IcePeer): all checks completed success=1 fail=0
[task 2023-09-29T23:06:09.405Z] 23:06:09     INFO -  ICE(IcePeer): peer (IcePeer) cancelling grace period timer
[task 2023-09-29T23:06:09.406Z] 23:06:09     INFO -  TestNrSocket IP4:127.0.0.1:61966/UDP denying ingress from IP4:127.0.0.1:65353/UDP: Not behind the same NAT
[task 2023-09-29T23:06:09.406Z] 23:06:09     INFO -  TestNrSocket IP4:127.0.0.1:57302/UDP creating port mapping IP4:127.0.0.1:64485/UDP -> IP4:127.0.0.1:54054/UDP
[task 2023-09-29T23:06:09.406Z] 23:06:09     INFO -  TestNrSocket IP4:127.0.0.1:54054/UDP denying ingress from IP4:127.0.0.1:64485/UDP: Not behind the same NAT
[task 2023-09-29T23:06:09.406Z] 23:06:09     INFO -  TestNrSocket IP4:127.0.0.1:54054/UDP creating port mapping IP4:127.0.0.1:51949/UDP -> IP4:127.0.0.1:57302/UDP
[task 2023-09-29T23:06:09.406Z] 23:06:09     INFO -  TestNrSocket IP4:127.0.0.1:57302/UDP denying ingress from IP4:127.0.0.1:51949/UDP: Not behind the same NAT
[task 2023-09-29T23:06:09.406Z] 23:06:09     INFO -  TestNrSocket IP4:127.0.0.1:52349/UDP creating port mapping IP4:127.0.0.1:55863/UDP -> IP4:127.0.0.1:55965/UDP
[task 2023-09-29T23:06:09.407Z] 23:06:09     INFO -  TestNrSocket IP4:127.0.0.1:51551/UDP creating port mapping IP4:127.0.0.1:59858/UDP -> IP4:127.0.0.1:49806/UDP
[task 2023-09-29T23:06:09.407Z] 23:06:09     INFO -  TestNrSocket IP4:127.0.0.1:57098/UDP creating port mapping IP4:127.0.0.1:57240/UDP -> IP4:127.0.0.1:53435/UDP
[task 2023-09-29T23:06:09.407Z] 23:06:09     INFO -  TestNrSocket IP4:127.0.0.1:57098/UDP denying ingress from IP4:127.0.0.1:60176/UDP: Filtered (no port mapping for source)
[task 2023-09-29T23:06:09.407Z] 23:06:09     INFO -  TestNrSocket IP4:127.0.0.1:57098/UDP creating port mapping IP4:127.0.0.1:57240/UDP -> IP4:127.0.0.1:60176/UDP
[task 2023-09-29T23:06:09.407Z] 23:06:09     INFO -  TestNrSocket IP4:127.0.0.1:52457/UDP creating port mapping IP4:127.0.0.1:63534/UDP -> IP4:127.0.0.1:53479/UDP
[task 2023-09-29T23:06:09.407Z] 23:06:09     INFO -  TestNrSocket IP4:127.0.0.1:52457/UDP creating port mapping IP4:127.0.0.1:61728/UDP -> IP4:127.0.0.1:62732/UDP
[task 2023-09-29T23:06:09.408Z] 23:06:09     INFO -  TestNrSocket IP4:127.0.0.1:61780/UDP creating port mapping IP4:127.0.0.1:57040/UDP -> IP4:127.0.0.1:59025/UDP
[task 2023-09-29T23:06:09.408Z] 23:06:09     INFO -  TestNrSocket IP4:127.0.0.1:61780/UDP denying ingress from IP4:127.0.0.1:55808/UDP: Filtered (no port mapping for source)
[task 2023-09-29T23:06:09.408Z] 23:06:09     INFO -  TestNrSocket IP4:127.0.0.1:61780/UDP creating port mapping IP4:127.0.0.1:49570/UDP -> IP4:127.0.0.1:55808/UDP
[task 2023-09-29T23:06:09.408Z] 23:06:09     INFO -  TestNrSocket IP4:127.0.0.1:61895/UDP creating port mapping IP4:127.0.0.1:56142/UDP -> IP4:127.0.0.1:56287/UDP
[task 2023-09-29T23:06:09.408Z] 23:06:09     INFO -  TestNrSocket IP4:127.0.0.1:59565/UDP creating port mapping IP4:127.0.0.1:64042/UDP -> IP4:127.0.0.1:56142/UDP
[task 2023-09-29T23:06:09.408Z] 23:06:09     INFO -  TestNrSocket IP4:127.0.0.1:61895/UDP denying ingress from IP4:127.0.0.1:64042/UDP: Hairpinning disallowed
[task 2023-09-29T23:06:09.409Z] 23:06:09     INFO -  TestNrSocket IP4:127.0.0.1:61095/UDP creating port mapping IP4:127.0.0.1:51796/UDP -> IP4:127.0.0.1:61006/UDP
[task 2023-09-29T23:06:09.409Z] 23:06:09     INFO -  TestNrSocket IP4:127.0.0.1:64643/UDP creating port mapping IP4:127.0.0.1:51705/UDP -> IP4:127.0.0.1:51796/UDP
[task 2023-09-29T23:06:09.409Z] 23:06:09     INFO -  TestNrSocket IP4:127.0.0.1:54206/UDP creating port mapping IP4:127.0.0.1:64532/UDP -> IP4:127.0.0.1:51533/UDP
[task 2023-09-29T23:06:09.409Z] 23:06:09     INFO -  TestNrSocket IP4:127.0.0.1:54206/UDP denying ingress from IP4:127.0.0.1:51533/UDP: Stale port mapping
[task 2023-09-29T23:06:09.409Z] 23:06:09  WARNING -  TEST-UNEXPECTED-FAIL | TestNrSocketTest.FullConeTimeout | test completed (time: 345ms)
[task 2023-09-29T23:06:09.409Z] 23:06:09     INFO -  TEST-START | TestNrSocketTest.PublicConnectivityTcp
Status: NEW → RESOLVED
Closed: 1 year ago
Flags: needinfo?(eitan)
Resolution: --- → FIXED

Reopening this due to relanding of the patch and the problem still persisting, as it can be seen here.

Status: RESOLVED → REOPENED
Flags: needinfo?(eitan)
Resolution: FIXED → ---
Keywords: regression
Regressed by: 1845407

Set release status flags based on info from the regressing bug 1845407

Summary: High Freq TestNrSocketTest.FullConeTimeout | Value of: CheckConnectivityVia(public_addrs_[0], private_addrs_[0], sender_external_address) → High Freq OSX TestNrSocketTest.FullConeTimeout | Value of: CheckConnectivityVia(public_addrs_[0], private_addrs_[0], sender_external_address)

Update

There have been 33 total failures within the last 6 days:

  • 31 failures on OS X 10.15 WebRender opt
  • 2 failures on OS X 10.15 WebRender Shippable opt

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=437589436&repo=autoland&lineNumber=45548

[task 2023-11-24T15:19:22.094Z] 15:19:22     INFO -  TEST-START | TestNrSocketTest.FullConeTimeout
[task 2023-11-24T15:19:22.350Z] 15:19:22  WARNING -  TEST-UNEXPECTED-FAIL | TestNrSocketTest.FullConeTimeout | Value of: CheckConnectivityVia(public_addrs_[0], private_addrs_[0], sender_external_address)
[task 2023-11-24T15:19:22.350Z] 15:19:22     INFO -    Actual: false
[task 2023-11-24T15:19:22.350Z] 15:19:22     INFO -  Expected: true
[task 2023-11-24T15:19:22.350Z] 15:19:22     INFO -   @ /builds/worker/checkouts/gecko/dom/media/webrtc/transport/test/test_nr_socket_unittest.cpp:744
[task 2023-11-24T15:19:22.351Z] 15:19:22     INFO -  ICE(IcePeer): no local addresses available
[task 2023-11-24T15:19:22.351Z] 15:19:22     INFO -  insert 'ice.pref.interface' (registry) succeeded: ice.pref.interface
[task 2023-11-24T15:19:22.351Z] 15:19:22     INFO -  insert 'ice.pref.interface.en0' (UCHAR) succeeded: 0x7f
[task 2023-11-24T15:19:22.351Z] 15:19:22     INFO -  ICE(IcePeer): All candidates initialized
[task 2023-11-24T15:19:22.352Z] 15:19:22     INFO -  ICE(IcePeer): no local addresses available
[task 2023-11-24T15:19:22.352Z] 15:19:22     INFO -  ICE(IcePeer2): no local addresses available
[task 2023-11-24T15:19:22.352Z] 15:19:22     INFO -  ICE(IcePeer): All candidates initialized
[task 2023-11-24T15:19:22.352Z] 15:19:22     INFO -  ICE(IcePeer2): All candidates initialized
Whiteboard: [stockwell needswork:owner]
Flags: needinfo?(eitan)

Update

There have been 46 total failures within the last 7 days:

  • 41 failures on OS X 10.15 WebRender debug
  • 5 failures on OS X 10.15 WebRender Shippable opt

*Recent log:*https://treeherder.mozilla.org/logviewer?job_id=439771296&repo=mozilla-central&lineNumber=46703

Eitan, can you take a look at this please?
Thank you.

Flags: needinfo?(eitan)
Whiteboard: [stockwell disable-recommended] → [stockwell needswork]

I think I've found the issue. Testing a fix.

Bah. Fix didn't pan out. Back to the drawing board.

Assignee: nobody → docfaraday

The gtest issue looks resolved to me, although we need to wait for some mochitest results.

Try looks ok.

Pushed by bcampen@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/bd6e5545759c Fix bug in NAT simulator where we'd ignore non-stale port mappings if there was a stale one. r=mjf https://hg.mozilla.org/integration/autoland/rev/c351bac38167 Compensate for slow macos testers, and add some logging. r=mjf
Status: REOPENED → RESOLVED
Closed: 1 year ago10 months ago
Resolution: --- → FIXED
Target Milestone: --- → 123 Branch
Flags: needinfo?(eitan)
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: