Closed Bug 1727833 Opened 4 years ago Closed 4 years ago

Intermittent dom/media/webrtc/tests/mochitests/test_peerConnection_offerRequiresReceiveVideo.html | Got local candidate ID undefined for selected pair - didn't expect undefined, but got it

Categories

(Core :: WebRTC: Audio/Video, defect, P5)

defect

Tracking

()

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure)

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


[task 2021-08-26T20:30:40.103Z] 20:30:40     INFO -  TEST-START | dom/media/webrtc/tests/mochitests/test_peerConnection_offerRequiresReceiveVideo.html
[task 2021-08-26T20:30:40.109Z] 20:30:40     INFO -  <snipped 326 output lines - if you need more context, please use SimpleTest.requestCompleteLog() in your test>
[task 2021-08-26T20:30:40.109Z] 20:30:40     INFO -  Buffered messages logged at 20:30:37
[task 2021-08-26T20:30:40.109Z] 20:30:40     INFO -  TEST-PASS | dom/media/webrtc/tests/mochitests/test_peerConnection_offerRequiresReceiveVideo.html | Valid rtp timestamp 1630009837590 <= 1630009837598 (
[task 2021-08-26T20:30:40.109Z] 20:30:40     INFO -              -8 ms)
[task 2021-08-26T20:30:40.109Z] 20:30:40     INFO -  Checking stats for 11c5a0c6 : [object Object]
<...>
[task 2021-08-26T20:30:40.132Z] 20:30:40     INFO -  TEST-PASS | dom/media/webrtc/tests/mochitests/test_peerConnection_offerRequiresReceiveVideo.html | Local candidate type is what we expected for selected pair
[task 2021-08-26T20:30:40.132Z] 20:30:40     INFO -  Run step 40: PC_REMOTE_CHECK_ICE_CONNECTION_TYPE
[task 2021-08-26T20:30:40.133Z] 20:30:40     INFO -  PeerConnectionWrapper (pcRemote): Got stats: {"7577519":{"id":"7577519","timestamp":1630009837621,"type":"local-candidate","address":"192.168.100.188","candidateType":"host","port":54587,"priority":2122187007,"protocol":"udp"},"7e29a3a6":{"id":"7e29a3a6","timestamp":1630009837621,"type":"candidate-pair","bytesReceived":0,"bytesSent":0,"lastPacketReceivedTimestamp":0,"lastPacketSentTimestamp":0,"localCandidateId":"c9398789","nominated":false,"priority":9115005270282338000,"readable":true,"remoteCandidateId":"f4173579","selected":false,"state":"cancelled","transportId":"transport_0","writable":true},"c9398789":{"id":"c9398789","timestamp":1630009837621,"type":"local-candidate","address":"fec0::947b:5fef:98d:8d95","candidateType":"host","port":59122,"priority":2122252543,"protocol":"udp"},"a4aaaca7":{"id":"a4aaaca7","timestamp":1630009837621,"type":"local-candidate","address":"192.168.100.188","candidateType":"host","port":62390,"priority":2105458943,"protocol":"tcp"},"1efbadff":{"id":"1efbadff","timestamp":1630009837621,"type":"local-candidate","address":"fec0::947b:5fef:98d:8d95","candidateType":"host","port":54031,"priority":2105524479,"protocol":"tcp"},"8f909253":{"id":"8f909253","timestamp":1630009837621,"type":"remote-candidate","address":"192.168.100.188","candidateType":"host","port":45716,"priority":2122187007,"protocol":"udp"},"f4173579":{"id":"f4173579","timestamp":1630009837621,"type":"remote-candidate","address":"fec0::947b:5fef:98d:8d95","candidateType":"host","port":38494,"priority":2122252543,"protocol":"udp"},"5f17f53c":{"id":"5f17f53c","timestamp":1630009837621,"type":"remote-candidate","address":"192.168.100.188","candidateType":"host","port":9,"priority":2105458943,"protocol":"tcp"},"e147413a":{"id":"e147413a","timestamp":1630009837621,"type":"remote-candidate","address":"fec0::947b:5fef:98d:8d95","candidateType":"host","port":9,"priority":2105524479,"protocol":"tcp"},"8fcbb91a":{"id":"8fcbb91a","timestamp":1630009837621,"type":"outbound-rtp","kind":"video","mediaType":"video","ssrc":602773648,"bytesSent":31780,"packetsSent":72,"bitrateMean":6.87547856230663e-310,"bitrateStdDev":4e-323,"droppedFrames":0,"firCount":0,"framerateMean":6.8756393180011e-310,"framerateStdDev":6.3e-322,"framesEncoded":0,"nackCount":0,"pliCount":0}}
[task 2021-08-26T20:30:40.133Z] 20:30:40     INFO -  Buffered messages finished
[task 2021-08-26T20:30:40.133Z] 20:30:40  WARNING -  TEST-UNEXPECTED-FAIL | dom/media/webrtc/tests/mochitests/test_peerConnection_offerRequiresReceiveVideo.html | Got local candidate ID undefined for selected pair - didn't expect undefined, but got it
[task 2021-08-26T20:30:40.133Z] 20:30:40     INFO -  SimpleTest.isnot@https://example.com/tests/SimpleTest/SimpleTest.js:519:14
[task 2021-08-26T20:30:40.134Z] 20:30:40     INFO -  checkStatsIceConnectionType@https://example.com/tests/dom/media/webrtc/tests/mochitests/pc.js:2213:10
[task 2021-08-26T20:30:40.134Z] 20:30:40     INFO -  PC_REMOTE_CHECK_ICE_CONNECTION_TYPE/<@https://example.com/tests/dom/media/webrtc/tests/mochitests/templates.js:486:21
[task 2021-08-26T20:30:40.134Z] 20:30:40  WARNING -  TEST-UNEXPECTED-FAIL | dom/media/webrtc/tests/mochitests/test_peerConnection_offerRequiresReceiveVideo.html | Got remote candidate ID undefined for selected pair - didn't expect undefined, but got it
[task 2021-08-26T20:30:40.134Z] 20:30:40     INFO -  SimpleTest.isnot@https://example.com/tests/SimpleTest/SimpleTest.js:519:14
[task 2021-08-26T20:30:40.134Z] 20:30:40     INFO -  checkStatsIceConnectionType@https://example.com/tests/dom/media/webrtc/tests/mochitests/pc.js:2218:10
[task 2021-08-26T20:30:40.134Z] 20:30:40     INFO -  PC_REMOTE_CHECK_ICE_CONNECTION_TYPE/<@https://example.com/tests/dom/media/webrtc/tests/mochitests/templates.js:486:21
[task 2021-08-26T20:30:40.134Z] 20:30:40  WARNING -  TEST-UNEXPECTED-FAIL | dom/media/webrtc/tests/mochitests/test_peerConnection_offerRequiresReceiveVideo.html | failed to find candidatepair IDs or stats for local: undefined remote: undefined
[task 2021-08-26T20:30:40.134Z] 20:30:40     INFO -  SimpleTest.ok@https://example.com/tests/SimpleTest/SimpleTest.js:417:16
[task 2021-08-26T20:30:40.134Z] 20:30:40     INFO -  checkStatsIceConnectionType@https://example.com/tests/dom/media/webrtc/tests/mochitests/pc.js:2226:9
[task 2021-08-26T20:30:40.134Z] 20:30:40     INFO -  PC_REMOTE_CHECK_ICE_CONNECTION_TYPE/<@https://example.com/tests/dom/media/webrtc/tests/mochitests/templates.js:486:21
[task 2021-08-26T20:30:40.134Z] 20:30:40     INFO -  Run step 41: PC_LOCAL_CHECK_ICE_CONNECTIONS
[task 2021-08-26T20:30:40.135Z] 20:30:40     INFO -  PeerConnectionWrapper (pcLocal): Got stats: {"2424e34d":{"id":"2424e34d","timestamp":1630009837624,"type":"candidate-pair","bytesReceived":33815,"bytesSent":1284,"lastPacketReceivedTimestamp":1630009837610,"lastPacketSentTimestamp":1630009837621,"localCandidateId":"de3d4195","nominated":true,"priority":7961802290698650000,"readable":true,"remoteCandidateId":"d681645a","selected":true,"state":"succeeded","transportId":"transport_0","writable":true},"de3d4195":{"id":"de3d4195","timestamp":1630009837624,"type":"local-candidate","address":"192.168.100.188","candidateType":"host","port":45716,"priority":2122187007,"protocol":"udp"},"11c5a0c6":{"id":"11c5a0c6","timestamp":1630009837624,"type":"local-candidate","address":"fec0::947b:5fef:98d:8d95","candidateType":"host","port":38494,"priority":2122252543,"protocol":"udp"},"23b41001":{"id":"23b41001","timestamp":1630009837624,"type":"local-candidate","address":"192.168.100.188","candidateType":"host","port":55763,"priority":2105458943,"protocol":"tcp"},"afb5868f":{"id":"afb5868f","timestamp":1630009837624,"type":"local-candidate","address":"fec0::947b:5fef:98d:8d95","candidateType":"host","port":64102,"priority":2105524479,"protocol":"tcp"},"d681645a":{"id":"d681645a","timestamp":1630009837624,"type":"remote-candidate","address":"192.168.100.188","candidateType":"prflx","port":54587,"priority":1853751551,"protocol":"udp"},"602f6096":{"id":"602f6096","timestamp":1630009837624,"type":"inbound-rtp","kind":"video","mediaType":"video","ssrc":602773648,"discardedPackets":0,"jitter":0,"packetsLost":0,"packetsReceived":72,"bitrateMean":0,"bitrateStdDev":0,"bytesReceived":31780,"firCount":0,"framerateMean":6.87562254665855e-310,"framerateStdDev":0,"framesDecoded":0,"nackCount":0,"pliCount":0,"remoteId":"64752c1b"},"64752c1b":{"id":"64752c1b","timestamp":1630009837178,"type":"remote-outbound-rtp","kind":"video","mediaType":"video","ssrc":602773648,"bytesSent":0,"packetsSent":0,"localId":"602f6096","remoteTimestamp":0}}
[task 2021-08-26T20:30:40.136Z] 20:30:40     INFO -  ICE connections according to stats: 1
[task 2021-08-26T20:30:40.136Z] 20:30:40     INFO -  TEST-PASS | dom/media/webrtc/tests/mochitests/test_peerConnection_offerRequiresReceiveVideo.html | Number of ICE connections according to stats is not zero
[task 2021-08-26T20:30:40.136Z] 20:30:40     INFO -  TEST-PASS | dom/media/webrtc/tests/mochitests/test_peerConnection_offerRequiresReceiveVideo.html | stats reports exactly 1 ICE connection
[task 2021-08-26T20:30:40.136Z] 20:30:40     INFO -  Run step 42: PC_REMOTE_CHECK_ICE_CONNECTIONS
[task 2021-08-26T20:30:40.137Z] 20:30:40     INFO -  PeerConnectionWrapper (pcRemote): Got stats: {"7577519":{"id":"7577519","timestamp":1630009837626,"type":"local-candidate","address":"192.168.100.188","candidateType":"host","port":54587,"priority":2122187007,"protocol":"udp"},"7e29a3a6":{"id":"7e29a3a6","timestamp":1630009837626,"type":"candidate-pair","bytesReceived":0,"bytesSent":0,"lastPacketReceivedTimestamp":0,"lastPacketSentTimestamp":0,"localCandidateId":"c9398789","nominated":false,"priority":9115005270282338000,"readable":true,"remoteCandidateId":"f4173579","selected":false,"state":"cancelled","transportId":"transport_0","writable":true},"c9398789":{"id":"c9398789","timestamp":1630009837626,"type":"local-candidate","address":"fec0::947b:5fef:98d:8d95","candidateType":"host","port":59122,"priority":2122252543,"protocol":"udp"},"a4aaaca7":{"id":"a4aaaca7","timestamp":1630009837626,"type":"local-candidate","address":"192.168.100.188","candidateType":"host","port":62390,"priority":2105458943,"protocol":"tcp"},"1efbadff":{"id":"1efbadff","timestamp":1630009837626,"type":"local-candidate","address":"fec0::947b:5fef:98d:8d95","candidateType":"host","port":54031,"priority":2105524479,"protocol":"tcp"},"8f909253":{"id":"8f909253","timestamp":1630009837626,"type":"remote-candidate","address":"192.168.100.188","candidateType":"host","port":45716,"priority":2122187007,"protocol":"udp"},"f4173579":{"id":"f4173579","timestamp":1630009837626,"type":"remote-candidate","address":"fec0::947b:5fef:98d:8d95","candidateType":"host","port":38494,"priority":2122252543,"protocol":"udp"},"5f17f53c":{"id":"5f17f53c","timestamp":1630009837626,"type":"remote-candidate","address":"192.168.100.188","candidateType":"host","port":9,"priority":2105458943,"protocol":"tcp"},"e147413a":{"id":"e147413a","timestamp":1630009837626,"type":"remote-candidate","address":"fec0::947b:5fef:98d:8d95","candidateType":"host","port":9,"priority":2105524479,"protocol":"tcp"},"8fcbb91a":{"id":"8fcbb91a","timestamp":1630009837626,"type":"outbound-rtp","kind":"video","mediaType":"video","ssrc":602773648,"bytesSent":31780,"packetsSent":72,"bitrateMean":0,"bitrateStdDev":6.87564753901455e-310,"droppedFrames":0,"firCount":0,"framerateMean":-35048367641880170,"framerateStdDev":6.8756244563045e-310,"framesEncoded":0,"nackCount":0,"pliCount":0}}
[task 2021-08-26T20:30:40.137Z] 20:30:40     INFO -  ICE connections according to stats: 0
[task 2021-08-26T20:30:40.137Z] 20:30:40  WARNING -  TEST-UNEXPECTED-FAIL | dom/media/webrtc/tests/mochitests/test_peerConnection_offerRequiresReceiveVideo.html | Number of ICE connections according to stats is not zero - didn't expect +0, but got it
[task 2021-08-26T20:30:40.137Z] 20:30:40     INFO -  SimpleTest.isnot@https://example.com/tests/SimpleTest/SimpleTest.js:519:14
[task 2021-08-26T20:30:40.137Z] 20:30:40     INFO -  checkStatsIceConnections@https://example.com/tests/dom/media/webrtc/tests/mochitests/pc.js:2279:10
[task 2021-08-26T20:30:40.137Z] 20:30:40     INFO -  PC_REMOTE_CHECK_ICE_CONNECTIONS/<@https://example.com/tests/dom/media/webrtc/tests/mochitests/templates.js:501:21
[task 2021-08-26T20:30:40.137Z] 20:30:40  WARNING -  TEST-UNEXPECTED-FAIL | dom/media/webrtc/tests/mochitests/test_peerConnection_offerRequiresReceiveVideo.html | stats reports exactly 1 ICE connection - got +0, expected 1
[task 2021-08-26T20:30:40.138Z] 20:30:40     INFO -  SimpleTest.is@https://example.com/tests/SimpleTest/SimpleTest.js:500:14
[task 2021-08-26T20:30:40.138Z] 20:30:40     INFO -  checkStatsIceConnections@https://example.com/tests/dom/media/webrtc/tests/mochitests/pc.js:2286:11
[task 2021-08-26T20:30:40.138Z] 20:30:40     INFO -  PC_REMOTE_CHECK_ICE_CONNECTIONS/<@https://example.com/tests/dom/media/webrtc/tests/mochitests/templates.js:501:21
[task 2021-08-26T20:30:40.138Z] 20:30:40     INFO -  Run step 43: PC_LOCAL_CHECK_MSID
[task 2021-08-26T20:30:40.138Z] 20:30:40     INFO -  Run step 44: PC_REMOTE_CHECK_MSID
[task 2021-08-26T20:30:40.138Z] 20:30:40     INFO -  TEST-PASS | dom/media/webrtc/tests/mochitests/test_peerConnection_offerRequiresReceiveVideo.html | There should be a transceiver for each sender
<...>
[task 2021-08-26T20:30:40.149Z] 20:30:40     INFO -  a=rtpmap:125 rtx/90000
[task 2021-08-26T20:30:40.149Z] 20:30:40     INFO -  a=setup:active
[task 2021-08-26T20:30:40.149Z] 20:30:40     INFO -  a=ssrc:602773648 cname:{ca90a6a3-fb7a-485b-bb8c-5b8cb220fd7a}
[task 2021-08-26T20:30:40.149Z] 20:30:40     INFO -  a=ssrc:3330282282 cname:{ca90a6a3-fb7a-485b-bb8c-5b8cb220fd7a}
[task 2021-08-26T20:30:40.149Z] 20:30:40     INFO -  a=ssrc-group:FID 602773648 3330282282
[task 2021-08-26T20:30:40.149Z] 20:30:40     INFO -  TEST-PASS | dom/media/webrtc/tests/mochitests/test_peerConnection_offerRequiresReceiveVideo.html | pcRemote: SDP contains end-of-candidates
[task 2021-08-26T20:30:40.149Z] 20:30:40     INFO -  TEST-PASS | dom/media/webrtc/tests/mochitests/test_peerConnection_offerRequiresReceiveVideo.html | pcRemote: SDP contains rtcp-mux
[task 2021-08-26T20:30:40.149Z] 20:30:40     INFO -  TEST-PASS | dom/media/webrtc/tests/mochitests/test_peerConnection_offerRequiresReceiveVideo.html | pcRemote: SDP contains a=ssrc
[task 2021-08-26T20:30:40.150Z] 20:30:40     INFO -  TEST-FAIL | dom/media/webrtc/tests/mochitests/test_peerConnection_offerRequiresReceiveVideo.html | The author of the test has indicated that flaky timeouts are expected.  Reason: WebRTC inherently depends on timeouts
[task 2021-08-26T20:30:40.150Z] 20:30:40     INFO -  Closing peer connections
[task 2021-08-26T20:30:40.150Z] 20:30:40     INFO -  Waiting for track {a912159e-5fe3-4daf-813b-863dd0e206e4} (video) to end.
[task 2021-08-26T20:30:40.150Z] 20:30:40     INFO -  TEST-FAIL | dom/media/webrtc/tests/mochitests/test_peerConnection_offerRequiresReceiveVideo.html | The author of the test has indicated that flaky timeouts are expected.  Reason: WebRTC inherently depends on timeouts
[task 2021-08-26T20:30:40.150Z] 20:30:40     INFO -  PeerConnectionWrapper (pcLocal): Closed connection.
[task 2021-08-26T20:30:40.150Z] 20:30:40     INFO -  Waiting for track {48b4806d-a330-4923-8572-1e6da0eeec32} (video) to end.
[task 2021-08-26T20:30:40.150Z] 20:30:40     INFO -  TEST-FAIL | dom/media/webrtc/tests/mochitests/test_peerConnection_offerRequiresReceiveVideo.html | The author of the test has indicated that flaky timeouts are expected.  Reason: WebRTC inherently depends on timeouts
[task 2021-08-26T20:30:40.150Z] 20:30:40     INFO -  PeerConnectionWrapper (pcRemote): Closed connection.
[task 2021-08-26T20:30:40.150Z] 20:30:40     INFO -  TEST-FAIL | dom/media/webrtc/tests/mochitests/test_peerConnection_offerRequiresReceiveVideo.html | The author of the test has indicated that flaky timeouts are expected.  Reason: WebRTC inherently depends on timeouts
[task 2021-08-26T20:30:40.150Z] 20:30:40     INFO -  TEST-PASS | dom/media/webrtc/tests/mochitests/test_peerConnection_offerRequiresReceiveVideo.html | Event target should be the correct track
[task 2021-08-26T20:30:40.150Z] 20:30:40     INFO -  PeerConnectionWrapper (pcLocal) ended fired for track {a912159e-5fe3-4daf-813b-863dd0e206e4}
[task 2021-08-26T20:30:40.150Z] 20:30:40     INFO -  TEST-PASS | dom/media/webrtc/tests/mochitests/test_peerConnection_offerRequiresReceiveVideo.html | Event target should be the correct track
[task 2021-08-26T20:30:40.151Z] 20:30:40     INFO -  PeerConnectionWrapper (pcRemote) ended fired for track {48b4806d-a330-4923-8572-1e6da0eeec32}
[task 2021-08-26T20:30:40.151Z] 20:30:40     INFO -  TEST-OK | dom/media/webrtc/tests/mochitests/test_peerConnection_offerRequiresReceiveVideo.html | took 873ms
Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.