Closed Bug 1513464 Opened 7 years ago Closed 6 years ago

Intermittent dom/media/tests/mochitest/test_peerConnection_restartIceNoBundle.html | iceconnectionstate event 'failed' matches expected state 'checking' - got "failed", expected "checking"

Categories

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

Product:
Core
Component:
WebRTC: Networking
Type:
defect

Tracking

()

Status:
RESOLVED FIXED
Milestone:
mozilla70
Tracking Flags:
Tracking Status
firefox-esr60 --- unaffected
firefox-esr68 --- unaffected
firefox68 --- wontfix
firefox69 --- wontfix
firefox70 --- fixed

People

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

Details

(Keywords: intermittent-failure)

Attachments

(1 file)

Bug 1513464: Unset the grace period timer when we start ICE, and when ICE completes. r?mjf
47 bytes, text/x-phabricator-request
Details | Review
Filed by: rmaries [at] mozilla.com https://treeherder.mozilla.org/logviewer.html#?job_id=216542885&repo=mozilla-central https://queue.taskcluster.net/v1/task/RAhXs15uTeabHZfbFDai6A/runs/0/artifacts/public/logs/live_backing.log [task 2018-12-12T06:55:56.476Z] 06:55:56 INFO - CLINE-NO-DEFAULT-ADDR-SDP: "video 47517 UDP/TLS/RTP/SAVPF 120\r\nc=IN IP4 172.17.0.4\r\na=candidate:0 1 UDP 2122187007 172.17.0.4 47517 typ host\r\na=candidate:1 1 UDP 2122252543 fd15:4ba5:5a2b:100a:0:242:ac11:4 54470 typ host\r\na=candidate:2 1 TCP 2105458943 172.17.0.4 9 typ host tcptype active\r\na=candidate:3 1 TCP 2105524479 fd15:4ba5:5a2b:100a:0:242:ac11:4 9 typ host tcptype active\r\na=sendrecv\r\na=end-of-candidates\r\na=extmap:3 urn:ietf:params:rtp-hdrext:sdes:mid\r\na=extmap:4 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time\r\na=extmap:5 urn:ietf:params:rtp-hdrext:toffset\r\na=fmtp:120 max-fs=12288;max-fr=60\r\na=ice-pwd:eb758995621bcbc21553393bcd1f394a\r\na=ice-ufrag:c07d14d3\r\na=mid:1\r\na=msid:{2cd44ba1-d3bc-4a19-a069-b4b3bae60a80} {6dc88c04-b5c6-448e-9dcd-b7cdd57ec359}\r\na=rtcp-fb:120 nack\r\na=rtcp-fb:120 nack pli\r\na=rtcp-fb:120 ccm fir\r\na=rtcp-fb:120 goog-remb\r\na=rtcp-mux\r\na=rtpmap:120 VP8/90000\r\na=setup:active\r\na=ssrc:3398178244 cname:{f0d20deb-a1a3-4193-8543-ae7b30c1fb18}\r\n" [task 2018-12-12T06:55:56.477Z] 06:55:56 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_restartIceNoBundle.html | pcRemote: SDP contains non-zero IP c line [task 2018-12-12T06:55:56.518Z] 06:55:56 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_restartIceNoBundle.html | SDP MLine Index needs to exist [task 2018-12-12T06:55:56.519Z] 06:55:56 INFO - Received: {"candidate":"candidate:2 1 TCP 2105458943 172.17.0.4 9 typ host tcptype active","sdpMid":"1","sdpMLineIndex":1} from pcRemote [task 2018-12-12T06:55:56.519Z] 06:55:56 INFO - PeerConnectionWrapper (pcLocal): adding ICE candidate {"candidate":"candidate:2 1 TCP 2105458943 172.17.0.4 9 typ host tcptype active","sdpMid":"1","sdpMLineIndex":1} [task 2018-12-12T06:55:56.519Z] 06:55:56 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_restartIceNoBundle.html | PeerConnectionWrapper (pcLocal) successfully added an ICE candidate [task 2018-12-12T06:55:56.519Z] 06:55:56 INFO - pcRemote: iceCandidate = {"candidate":"candidate:3 1 TCP 2105524479 fd15:4ba5:5a2b:100a:0:242:ac11:4 9 typ host tcptype active","sdpMid":"1","sdpMLineIndex":1} [task 2018-12-12T06:55:56.547Z] 06:55:56 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_restartIceNoBundle.html | ICE candidate contains candidate [task 2018-12-12T06:55:56.549Z] 06:55:56 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_restartIceNoBundle.html | SDP mid not empty [task 2018-12-12T06:55:56.552Z] 06:55:56 INFO - CLINE-NO-DEFAULT-ADDR-SDP: "video 47517 UDP/TLS/RTP/SAVPF 120\r\nc=IN IP4 172.17.0.4\r\na=candidate:0 1 UDP 2122187007 172.17.0.4 47517 typ host\r\na=candidate:1 1 UDP 2122252543 fd15:4ba5:5a2b:100a:0:242:ac11:4 54470 typ host\r\na=candidate:2 1 TCP 2105458943 172.17.0.4 9 typ host tcptype active\r\na=candidate:3 1 TCP 2105524479 fd15:4ba5:5a2b:100a:0:242:ac11:4 9 typ host tcptype active\r\na=sendrecv\r\na=end-of-candidates\r\na=extmap:3 urn:ietf:params:rtp-hdrext:sdes:mid\r\na=extmap:4 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time\r\na=extmap:5 urn:ietf:params:rtp-hdrext:toffset\r\na=fmtp:120 max-fs=12288;max-fr=60\r\na=ice-pwd:eb758995621bcbc21553393bcd1f394a\r\na=ice-ufrag:c07d14d3\r\na=mid:1\r\na=msid:{2cd44ba1-d3bc-4a19-a069-b4b3bae60a80} {6dc88c04-b5c6-448e-9dcd-b7cdd57ec359}\r\na=rtcp-fb:120 nack\r\na=rtcp-fb:120 nack pli\r\na=rtcp-fb:120 ccm fir\r\na=rtcp-fb:120 goog-remb\r\na=rtcp-mux\r\na=rtpmap:120 VP8/90000\r\na=setup:active\r\na=ssrc:3398178244 cname:{f0d20deb-a1a3-4193-8543-ae7b30c1fb18}\r\n" [task 2018-12-12T06:55:56.555Z] 06:55:56 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_restartIceNoBundle.html | pcRemote: SDP contains non-zero IP c line [task 2018-12-12T06:55:56.557Z] 06:55:56 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_restartIceNoBundle.html | SDP MLine Index needs to exist [task 2018-12-12T06:55:56.562Z] 06:55:56 INFO - Received: {"candidate":"candidate:3 1 TCP 2105524479 fd15:4ba5:5a2b:100a:0:242:ac11:4 9 typ host tcptype active","sdpMid":"1","sdpMLineIndex":1} from pcRemote [task 2018-12-12T06:55:56.565Z] 06:55:56 INFO - PeerConnectionWrapper (pcLocal): adding ICE candidate {"candidate":"candidate:3 1 TCP 2105524479 fd15:4ba5:5a2b:100a:0:242:ac11:4 9 typ host tcptype active","sdpMid":"1","sdpMLineIndex":1} [task 2018-12-12T06:55:56.568Z] 06:55:56 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_restartIceNoBundle.html | PeerConnectionWrapper (pcLocal) successfully added an ICE candidate [task 2018-12-12T06:55:56.575Z] 06:55:56 INFO - pcRemote: received end of trickle ICE event [task 2018-12-12T06:55:56.576Z] 06:55:56 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_restartIceNoBundle.html | ICE gathering state has reached complete [task 2018-12-12T06:55:56.584Z] 06:55:56 INFO - Buffered messages logged at 06:55:53 [task 2018-12-12T06:55:56.587Z] 06:55:56 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_restartIceNoBundle.html | iceConnectionState should not be undefined [task 2018-12-12T06:55:56.594Z] 06:55:56 INFO - PeerConnectionWrapper (pcLocal): oniceconnectionstatechange fired, new state is: failed [task 2018-12-12T06:55:56.596Z] 06:55:56 INFO - Buffered messages finished [task 2018-12-12T06:55:56.597Z] 06:55:56 INFO - TEST-UNEXPECTED-FAIL | dom/media/tests/mochitest/test_peerConnection_restartIceNoBundle.html | iceconnectionstate event 'failed' matches expected state 'checking' - got "failed", expected "checking" [task 2018-12-12T06:55:56.599Z] 06:55:56 INFO - SimpleTest.is@SimpleTest/SimpleTest.js:320:5 [task 2018-12-12T06:55:56.601Z] 06:55:56 INFO - logIceConnectionState/this.ice_connection_callbacks.logIceStatus@dom/media/tests/mochitest/pc.js:1342:11 [task 2018-12-12T06:55:56.602Z] 06:55:56 INFO - PeerConnectionWrapper/this._pc.oniceconnectionstatechange/<@dom/media/tests/mochitest/pc.js:797:42 [task 2018-12-12T06:55:56.603Z] 06:55:56 INFO - PeerConnectionWrapper/this._pc.oniceconnectionstatechange@dom/media/tests/mochitest/pc.js:796:48 [task 2018-12-12T06:55:56.604Z] 06:55:56 INFO - GECKO(1828) | [Child 1924: Socket Thread]: D/mtransport (ice/INFO) ICE-PEER(PC:1544597307427659 (id=4294967596 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_basicScreenshare:default)/CAND-PAIR(1wR4): setting pair to state FROZEN: 1wR4|IP4:172.17.0.4:40635/UDP|IP4:172.17.0.4:36431/UDP(host(IP4:172.17.0.4:40635/UDP)|prflx) [task 2018-12-12T06:55:56.609Z] 06:55:56 INFO - GECKO(1828) | [Child 1924: Socket Thread]: D/mtransport (ice/INFO) ICE(PC:1544597307427659 (id=4294967596 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_basicScreenshare)/CAND-PAIR(1wR4): Pairing candidate IP4:172.17.0.4:40635/UDP (7e7e00ff):IP4:172.17.0.4:36431/UDP (6e7e00ff) priority=7961802290698650111 (6e7e00fffcfc01ff) [task 2018-12-12T06:55:56.610Z] 06:55:56 INFO - GECKO(1828) | [Child 1924: Socket Thread]: D/mtransport (ice/INFO) ICE-PEER(PC:1544597307427659 (id=4294967596 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_basicScreenshare:default)/CAND-PAIR(1wR4): setting pair to state FROZEN: 1wR4|IP4:172.17.0.4:40635/UDP|IP4:172.17.0.4:36431/UDP(host(IP4:172.17.0.4:40635/UDP)|prflx) [task 2018-12-12T06:55:56.613Z] 06:55:56 INFO - GECKO(1828) | [Child 1924: Socket Thread]: D/mtransport (ice/INFO) ICE-PEER(PC:1544597307427659 (id=4294967596 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_basicScreenshare:default)/ICE-STREAM(PC:1544597307427659 (id=4294967596 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_basicScreenshare transport-id=transport_0 - 69331f5e:9156eccfc9e976e27fc5a24c9274bf66): Starting check timer for stream. [task 2018-12-12T06:55:56.620Z] 06:55:56 INFO - GECKO(1828) | [Child 1924: Socket Thread]: D/mtransport (ice/INFO) ICE-PEER(PC:1544597307427659 (id=4294967596 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_basicScreenshare:default)/CAND-PAIR(1wR4): setting pair to state WAITING: 1wR4|IP4:172.17.0.4:40635/UDP|IP4:172.17.0.4:36431/UDP(host(IP4:172.17.0.4:40635/UDP)|prflx) [task 2018-12-12T06:55:56.621Z] 06:55:56 INFO - GECKO(1828) | [Child 1924: Socket Thread]: D/mtransport (ice/INFO) ICE-PEER(PC:1544597307427659 (id=4294967596 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_basicScreenshare:default)/CAND-PAIR(1wR4): setting pair to state IN_PROGRESS: 1wR4|IP4:172.17.0.4:40635/UDP|IP4:172.17.0.4:36431/UDP(host(IP4:172.17.0.4:40635/UDP)|prflx) [task 2018-12-12T06:55:56.622Z] 06:55:56 INFO - GECKO(1828) | [Child 1924: Socket Thread]: D/mtransport (ice/NOTICE) ICE(PC:1544597307427659 (id=4294967596 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_basicScreenshare): peer (PC:1544597307427659 (id=4294967596 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_basicScreenshare:default) is now checking [task 2018-12-12T06:55:56.659Z] 06:55:56 INFO - GECKO(1828) | [Child 1924: Socket Thread]: D/mtransport (ice/INFO) ICE-PEER(PC:1544597307427659 (id=4294967596 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_basicScreenshare:default)/CAND-PAIR(1wR4): triggered check on 1wR4|IP4:172.17.0.4:40635/UDP|IP4:172.17.0.4:36431/UDP(host(IP4:172.17.0.4:40635/UDP)|prflx) [task 2018-12-12T06:55:56.665Z] 06:55:56 INFO - GECKO(1828) | [Child 1924: Socket Thread]: D/mtransport (ice/INFO) ICE-PEER(PC:1544597307427659 (id=4294967596 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_basicScreenshare:default)/CAND-PAIR(1wR4): setting pair to state FROZEN: 1wR4|IP4:172.17.0.4:40635/UDP|IP4:172.17.0.4:36431/UDP(host(IP4:172.17.0.4:40635/UDP)|prflx) [task 2018-12-12T06:55:56.672Z] 06:55:56 INFO - GECKO(1828) | [Child 1924: Socket Thread]: D/mtransport (ice/INFO) ICE(PC:1544597307427659 (id=4294967596 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_basicScreenshare)/CAND-PAIR(1wR4): Pairing candidate IP4:172.17.0.4:40635/UDP (7e7e00ff):IP4:172.17.0.4:36431/UDP (6e7e00ff) priority=7961802290698650111 (6e7e00fffcfc01ff) [task 2018-12-12T06:55:56.677Z] 06:55:56 INFO - GECKO(1828) | [Child 1924: Socket Thread]: D/mtransport (ice/INFO) CAND-PAIR(1wR4): Adding pair to check list and trigger check queue: 1wR4|IP4:172.17.0.4:40635/UDP|IP4:172.17.0.4:36431/UDP(host(IP4:172.17.0.4:40635/UDP)|prflx) [task 2018-12-12T06:55:56.678Z] 06:55:56 INFO - GECKO(1828) | [Child 1924: Socket Thread]: D/mtransport (ice/INFO) ICE-PEER(PC:1544597307427659 (id=4294967596 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_basicScreenshare:default)/CAND-PAIR(1wR4): setting pair to state WAITING: 1wR4|IP4:172.17.0.4:40635/UDP|IP4:172.17.0.4:36431/UDP(host(IP4:172.17.0.4:40635/UDP)|prflx) [task 2018-12-12T06:55:56.679Z] 06:55:56 INFO - GECKO(1828) | [Child 1924: Socket Thread]: D/mtransport (ice/INFO) ICE-PEER(PC:1544597307427659 (id=4294967596 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_basicScreenshare:default)/CAND-PAIR(1wR4): setting pair to state CANCELLED: 1wR4|IP4:172.17.0.4:40635/UDP|IP4:172.17.0.4:36431/UDP(host(IP4:172.17.0.4:40635/UDP)|prflx) [task 2018-12-12T06:55:56.681Z] 06:55:56 INFO - GECKO(1828) | [Child 1924: Socket Thread]: D/mtransport (ice/INFO) ICE-PEER(PC:1544597307439323 (id=4294967596 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_basicScreenshare:default)/CAND-PAIR(d3+4): triggered check on d3+4|IP4:172.17.0.4:36431/UDP|IP4:172.17.0.4:40635/UDP(host(IP4:172.17.0.4:36431/UDP)|candidate:0 1 UDP 2122187007 172.17.0.4 40635 typ host) [task 2018-12-12T06:55:56.682Z] 06:55:56 INFO - GECKO(1828) | [Child 1924: Socket Thread]: D/mtransport (ice/INFO) ICE-PEER(PC:1544597307439323 (id=4294967596 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_basicScreenshare:default)/CAND-PAIR(d3+4): setting pair to state FROZEN: d3+4|IP4:172.17.0.4:36431/UDP|IP4:172.17.0.4:40635/UDP(host(IP4:172.17.0.4:36431/UDP)|candidate:0 1 UDP 2122187007 172.17.0.4 40635 typ host) [task 2018-12-12T06:55:56.684Z] 06:55:56 INFO - GECKO(1828) | [Child 1924: Socket Thread]: D/mtransport (ice/INFO) ICE(PC:1544597307439323 (id=4294967596 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_basicScreenshare)/CAND-PAIR(d3+4): Pairing candidate IP4:172.17.0.4:36431/UDP (7e7e00ff):IP4:172.17.0.4:40635/UDP (7e7e00ff) priority=9114723795305497087 (7e7e00fffcfc01ff) [task 2018-12-12T06:55:56.691Z] 06:55:56 INFO - GECKO(1828) | [Child 1924: Socket Thread]: D/mtransport (ice/INFO) CAND-PAIR(d3+4): Adding pair to check list and trigger check queue: d3+4|IP4:172.17.0.4:36431/UDP|IP4:172.17.0.4:40635/UDP(host(IP4:172.17.0.4:36431/UDP)|candidate:0 1 UDP 2122187007 172.17.0.4 40635 typ host) [task 2018-12-12T06:55:56.694Z] 06:55:56 INFO - GECKO(1828) | [Child 1924: Socket Thread]: D/mtransport (ice/INFO) ICE-PEER(PC:1544597307439323 (id=4294967596 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_basicScreenshare:default)/CAND-PAIR(d3+4): setting pair to state WAITING: d3+4|IP4:172.17.0.4:36431/UDP|IP4:172.17.0.4:40635/UDP(host(IP4:172.17.0.4:36431/UDP)|candidate:0 1 UDP 2122187007 172.17.0.4 40635 typ host) [task 2018-12-12T06:55:56.701Z] 06:55:56 INFO - GECKO(1828) | [Child 1924: Socket Thread]: D/mtransport (ice/INFO) ICE-PEER(PC:1544597307439323 (id=4294967596 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_basicScreenshare:default)/CAND-PAIR(d3+4): setting pair to state CANCELLED: d3+4|IP4:172.17.0.4:36431/UDP|IP4:172.17.0.4:40635/UDP(host(IP4:172.17.0.4:36431/UDP)|candidate:0 1 UDP 2122187007 172.17.0.4 40635 typ host) [task 2018-12-12T06:55:56.701Z] 06:55:56 INFO - GECKO(1828) | [Child 1924: Socket Thread]: D/mtransport (stun/INFO) STUN-CLIENT(d3+4|IP4:172.17.0.4:36431/UDP|IP4:172.17.0.4:40635/UDP(host(IP4:172.17.0.4:36431/UDP)|candidate:0 1 UDP 2122187007 172.17.0.4 40635 typ host)): Received response; processing [task 2018-12-12T06:55:56.702Z] 06:55:56 INFO - GECKO(1828) | [Child 1924: Socket Thread]: D/mtransport (ice/INFO) ICE-PEER(PC:1544597307439323 (id=4294967596 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_basicScreenshare:default)/CAND-PAIR(d3+4): setting pair to state SUCCEEDED: d3+4|IP4:172.17.0.4:36431/UDP|IP4:172.17.0.4:40635/UDP(host(IP4:172.17.0.4:36431/UDP)|candidate:0 1 UDP 2122187007 172.17.0.4 40635 typ host) [task 2018-12-12T06:55:56.704Z] 06:55:56 INFO - GECKO(1828) | [Child 1924: Socket Thread]: D/mtransport (ice/INFO) ICE-PEER(PC:1544597307439323 (id=4294967596 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_basicScreenshare:default)/STREAM(PC:1544597307439323 (id=4294967596 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_basicScreenshare transport-id=transport_0 - 9060c2e3:1cca73e5f0f301e60f3398bb4af7265e)/COMP(1)/CAND-PAIR(d3+4): nominated pair is d3+4|IP4:172.17.0.4:36431/UDP|IP4:172.17.0.4:40635/UDP(host(IP4:172.17.0.4:36431/UDP)|candidate:0 1 UDP 2122187007 172.17.0.4 40635 typ host) [task 2018-12-12T06:55:56.711Z] 06:55:56 INFO - Not taking screenshot here: see the one that was previously logged [task 2018-12-12T06:55:56.712Z] 06:55:56 INFO - TEST-UNEXPECTED-FAIL | dom/media/tests/mochitest/test_peerConnection_restartIceNoBundle.html | Error in test execution: Error: ICE failed PeerConnectionWrapper/this._pc.oniceconnectionstatechange@http://mochi.test:8888/tests/dom/media/tests/mochitest/pc.js:802:31 ... [task 2018-12-12T06:55:56.712Z] 06:55:56 INFO - SimpleTest.ok@SimpleTest/SimpleTest.js:275:7 [task 2018-12-12T06:55:56.716Z] 06:55:56 INFO - execute/<@dom/media/tests/mochitest/head.js:856:14 [task 2018-12-12T06:55:56.717Z] 06:55:56 INFO - TEST-FAIL | dom/media/tests/mochitest/test_peerConnection_restartIceNoBundle.html | The author of the test has indicated that flaky timeouts are expected. Reason: WebRTC inherently depends on timeouts [task 2018-12-12T06:55:56.724Z] 06:55:56 INFO - Closing peer connections [task 2018-12-12T06:55:56.730Z] 06:55:56 INFO - Waiting for track {4dd68985-40c5-42ae-8e9e-53bba8104352} (audio) to end. [task 2018-12-12T06:55:56.731Z] 06:55:56 INFO - TEST-FAIL | dom/media/tests/mochitest/test_peerConnection_restartIceNoBundle.html | The author of the test has indicated that flaky timeouts are expected. Reason: WebRTC inherently depends on timeouts [task 2018-12-12T06:55:56.741Z] 06:55:56 INFO - Waiting for track {2dee49a6-f054-48b5-a2bd-6d76fc2e7455} (video) to end. [task 2018-12-12T06:55:56.743Z] 06:55:56 INFO - TEST-FAIL | dom/media/tests/mochitest/test_peerConnection_restartIceNoBundle.html | The author of the test has indicated that flaky timeouts are expected. Reason: WebRTC inherently depends on timeouts [task 2018-12-12T06:55:56.744Z] 06:55:56 INFO - GECKO(1828) | [Child 1924: Socket Thread]: D/mtransport (ice/INFO) ICE-PEER(PC:1544597307439323 (id=4294967596 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_basicScreenshare:default)/STREAM(PC:1544597307439323 (id=4294967596 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_basicScreenshare transport-id=transport_0 - 9060c2e3:1cca73e5f0f301e60f3398bb4af7265e)/COMP(1)/CAND-PAIR(d3+4): cancelling all pairs but d3+4|IP4:172.17.0.4:36431/UDP|IP4:172.17.0.4:40635/UDP(host(IP4:172.17.0.4:36431/UDP)|candidate:0 1 UDP 2122187007 172.17.0.4 40635 typ host) [task 2018-12-12T06:55:56.746Z] 06:55:56 INFO - GECKO(1828) | [Child 1924: Socket Thread]: D/mtransport (ice/INFO) ICE-PEER(PC:1544597307439323 (id=4294967596 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_basicScreenshare:default)/STREAM(PC:1544597307439323 (id=4294967596 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_basicScreenshare transport-id=transport_0 - 9060c2e3:1cca73e5f0f301e60f3398bb4af7265e)/COMP(1)/CAND-PAIR(d3+4): cancelling FROZEN/WAITING pair d3+4|IP4:172.17.0.4:36431/UDP|IP4:172.17.0.4:40635/UDP(host(IP4:172.17.0.4:36431/UDP)|candidate:0 1 UDP 2122187007 172.17.0.4 40635 typ host) in trigger check queue because CAND-PAIR(d3+4) was nominated.

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup

Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → INCOMPLETE

Recent log failure:
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=230560951&repo=autoland&lineNumber=44370

Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup

Status: REOPENED → RESOLVED
Closed: 7 years ago → 7 years ago
Resolution: --- → INCOMPLETE

Recent log:
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=245263719&repo=autoland&lineNumber=52201

Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

It looks like our grace period timer is not being reset when we restart ICE, which is busted. Trying to determine how to fix.

Assignee: nobody → docfaraday

It looks like when ICE completes, the grace period timer keeps running, and when we start ICE again (but don't have pairs yet), we don't extend it. I think the most sensible thing to do is disable the grace period timer when ICE completes, and when we're about to start ICE again (we may restart the timer if there are pairs, but if not the timer will not be running).

Try looks ok so far. Check back on retriggers.

Flags: needinfo?(docfaraday)

Try looks good.

Flags: needinfo?(docfaraday)
Pushed by bcampen@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/f2e2b64a9329 Unset the grace period timer when we start ICE, and when ICE completes. r=mjf

https://hg.mozilla.org/mozilla-central/rev/f2e2b64a9329

Status: REOPENED → RESOLVED
Closed: 7 years ago → 6 years ago
status-firefox70: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla70
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: