Closed Bug 1035011 Opened 11 years ago Closed 10 years ago

Intermittent test_dataChannel_bug1013809.html | pc_local: ICE failed to switch to 'connected' state: failed | PeerConnectionWrapper (pcLocal) timed out while waiting for dataChannels[0] to open - got connecting, expected open

Categories

(Core :: WebRTC, defect)

Product:
Core
Component:
WebRTC
Platform:
x86_64
Linux
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

()

Status:
RESOLVED INCOMPLETE

People

(Reporter: nigelb, Unassigned)

References

(
URL
)

Details

(Keywords: intermittent-failure)

Ubuntu VM 12.04 mozilla-central opt test mochitest-e10s-3 on 2014-07-06 10:15:49 PDT for push 1dc6b294800d slave: tst-linux32-spot-495 https://tbpl.mozilla.org/php/getParsedLog.php?id=43211654&tree=Mozilla-Central 10:19:22 INFO - 916 INFO TEST-INFO | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | PeerConnectionWrapper (pcRemote): Register callbacks for 'ondatachannel' and 'onopen' 10:19:22 INFO - 917 INFO TEST-INFO | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | Run step: PC_LOCAL_SET_REMOTE_DESCRIPTION 10:19:22 INFO - 918 INFO TEST-PASS | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | iceConnectionState should not be undefined 10:19:22 INFO - 919 INFO TEST-INFO | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | PeerConnectionWrapper (pcLocal): oniceconnectionstatechange fired, new state is: checking 10:19:22 INFO - 920 INFO TEST-PASS | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | PeerConnectionWrapper (pcLocal): legal ICE state transition from new to checking 10:19:22 INFO - 921 INFO TEST-INFO | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | PeerConnectionWrapper (pcLocal): 'onaddstream' event fired for {} 10:19:22 INFO - 922 INFO TEST-INFO | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | Got media stream: audio (remote) 10:19:22 INFO - 923 INFO TEST-INFO | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | PeerConnectionWrapper (pcLocal): 'onsignalingstatechange' event fired 10:19:22 INFO - 924 INFO TEST-PASS | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | PeerConnectionWrapper (pcLocal): legal signaling state transition from have-local-offer to stable 10:19:22 INFO - 925 INFO TEST-INFO | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | PeerConnectionWrapper (pcLocal): 'onsignalingstatechange' event 'stable' received 10:19:22 INFO - 926 INFO TEST-INFO | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | PeerConnectionWrapper (pcLocal): Successfully set remote description 10:19:22 INFO - 927 INFO TEST-PASS | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | signalingState after local setRemoteDescription is 'stable' 10:19:22 INFO - 928 INFO TEST-INFO | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | Run step: PC_REMOTE_SET_LOCAL_DESCRIPTION 10:19:22 INFO - 929 INFO TEST-INFO | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | canplaythrough fired for media element pcLocal_remote_audio 10:19:22 INFO - 930 INFO TEST-INFO | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | timeupdate fired for media element pcLocal_remote_audio 10:19:22 INFO - 931 INFO TEST-INFO | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | time passed for media element pcLocal_remote_audio 10:19:22 INFO - 932 INFO TEST-INFO | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | timeupdate fired for media element pcLocal_local_audio 10:19:22 INFO - 933 INFO TEST-INFO | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | time passed for media element pcLocal_local_audio 10:19:22 INFO - 934 INFO TEST-INFO | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | PeerConnectionWrapper (pcRemote): 'onaddstream' event fired for {} 10:19:22 INFO - 935 INFO TEST-INFO | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | Got media stream: audio (remote) 10:19:22 INFO - 936 INFO TEST-INFO | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | PeerConnectionWrapper (pcRemote): 'onsignalingstatechange' event fired 10:19:22 INFO - 937 INFO TEST-PASS | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | PeerConnectionWrapper (pcRemote): legal signaling state transition from have-remote-offer to stable 10:19:22 INFO - 938 INFO TEST-INFO | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | PeerConnectionWrapper (pcRemote): 'onsignalingstatechange' event 'stable' received 10:19:22 INFO - 939 INFO TEST-INFO | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | PeerConnectionWrapper (pcRemote): Successfully set the local description 10:19:22 INFO - 940 INFO TEST-PASS | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | signalingState after remote setLocalDescription is 'stable' 10:19:22 INFO - 941 INFO TEST-INFO | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | Run step: PC_LOCAL_WAIT_FOR_ICE_CONNECTED 10:19:22 INFO - 942 INFO TEST-INFO | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | iceConnectionState: checking 10:19:22 INFO - 943 INFO TEST-INFO | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | timeupdate fired for media element pcRemote_remote_audio 10:19:22 INFO - 944 INFO TEST-INFO | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | canplaythrough fired for media element pcRemote_remote_audio 10:19:22 INFO - 945 INFO TEST-INFO | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | timeupdate fired for media element pcRemote_local_audio 10:19:22 INFO - 946 INFO TEST-INFO | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | time passed for media element pcRemote_local_audio 10:19:22 INFO - 947 INFO TEST-PASS | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | iceConnectionState should not be undefined 10:19:22 INFO - 948 INFO TEST-INFO | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | PeerConnectionWrapper (pcRemote): oniceconnectionstatechange fired, new state is: checking 10:19:22 INFO - 949 INFO TEST-PASS | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | PeerConnectionWrapper (pcRemote): legal ICE state transition from new to checking 10:19:22 INFO - 950 INFO TEST-INFO | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | timeupdate fired for media element pcRemote_remote_audio 10:19:22 INFO - 951 INFO TEST-INFO | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | time passed for media element pcRemote_remote_audio 10:19:22 INFO - 952 INFO TEST-PASS | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | iceConnectionState should not be undefined 10:19:22 INFO - 953 INFO TEST-INFO | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | PeerConnectionWrapper (pcLocal): oniceconnectionstatechange fired, new state is: failed 10:19:22 INFO - 954 INFO TEST-PASS | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | PeerConnectionWrapper (pcLocal): legal ICE state transition from checking to failed 10:19:22 INFO - 955 INFO TEST-INFO | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | iceConnectionState: failed 10:19:22 INFO - 956 INFO TEST-UNEXPECTED-FAIL | /tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html | pc_local: ICE failed to switch to 'connected' state: failed 10:19:22 INFO - -1734362304[a31cae80]: [MediaStreamGrph|WebrtcAudioSessionConduit] AudioConduit.cpp:688: A/V sync: sync delta: 0ms, audio jitter delay 215ms, playout delay 0ms 10:19:22 INFO - -1734362304[a31cae80]: [MediaStreamGrph|WebrtcAudioSessionConduit] AudioConduit.cpp:688: A/V sync: sync delta: 0ms, audio jitter delay 222ms, playout delay 0ms 10:19:22 INFO - -1380979904[b2733ac0]: [Socket Thread|WebrtcAudioSessionConduit] AudioConduit.cpp:778: Error: ReceivedRTCPPacket when not receiving 10:19:22 INFO - -1380979904[b2733ac0]: [Socket Thread|WebrtcAudioSessionConduit] AudioConduit.cpp:778: Error: ReceivedRTCPPacket when not receiving 10:19:23 INFO - (stun/INFO) STUN-CLIENT(DHtu|IP4:10.132.59.215:54289/UDP|IP4:10.132.59.215:60496/UDP(host(IP4:10.132.59.215:54289/UDP)|candidate:0 1 UDP 2122252543 10.132.59.215 60496 typ host)): Timed out 10:19:23 INFO - (ice/INFO) ICE-PEER(PC:1404667140636911 (id=385 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html):default)/CAND-PAIR(DHtu): setting pair to state FAILED: DHtu|IP4:10.132.59.215:54289/UDP|IP4:10.132.59.215:60496/UDP(host(IP4:10.132.59.215:54289/UDP)|candidate:0 1 UDP 2122252543 10.132.59.215 60496 typ host) 10:19:23 INFO - (ice/INFO) ICE-PEER(PC:1404667140636911 (id=385 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html):default)/STREAM(1404667140636911 (id=385 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html): stream2/video)/COMP(1): All pairs are failed, and grace period has elapsed. Marking component as failed. 10:19:23 INFO - -1380979904[b2733ac0]: NrIceCtx(PC:1404667140636911 (id=385 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html)): state 1->3 10:19:23 INFO - -1380979904[b2733ac0]: NrIceCtx(PC:1404667140636911 (id=385 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_dataChannel_bug1013809.html)): dumping r_log ringbuffer... 10:19:23 INFO - -1380979904[b2733ac0]: (registry/INFO) insert 'ice' (registry) succeeded: ice 10:19:23 INFO - -1380979904[b2733ac0]: (registry/INFO) insert 'ice.pref' (registry) succeeded: ice.pref 10:19:23 INFO - -1380979904[b2733ac0]: (registry/INFO) insert 'ice.pref.type' (registry) succeeded: ice.pref.type 10:19:23 INFO - -1380979904[b2733ac0]: (registry/INFO) insert 'ice.pref.type.srv_rflx' (UCHAR) succeeded: 0x64 10:19:23 INFO - -1380979904[b2733ac0]: (registry/INFO) insert 'ice.pref.type.peer_rflx' (UCHAR) succeeded: 0x6e 10:19:23 INFO - -1380979904[b2733ac0]: (registry/INFO) insert 'ice.pref.type.host' (UCHAR) succeeded: 0x7e 10:19:23 INFO - -1380979904[b2733ac0]: (registry/INFO) insert 'ice.pref.type.relayed' (UCHAR) succeeded: 0x05 10:19:23 INFO - -1380979904[b2733ac0]: (registry/INFO) insert 'ice.pref.type.relayed_tcp' (UCHAR) succeeded: 0x00 10:19:23 INFO - -1380979904[b2733ac0]: (registry/INFO) insert 'ice.pref.interface' (registry) succeeded: ice.pref.interface 10:19:23 INFO - -1380979904[b2733ac0]: (registry/INFO) insert 'ice.pref.interface.rl0' (UCHAR) succeeded: 0xff 10:19:23 INFO - -1380979904[b2733ac0]: (registry/INFO) insert 'ice.pref.interface.wi0' (UCHAR) succeeded: 0xfe 10:19:23 INFO - -1380979904[b2733ac0]: (registry/INFO) insert 'ice.pref.interface.lo0' (UCHAR) succeeded: 0xfd 10:19:23 INFO - -1380979904[b2733ac0]: (registry/INFO) insert 'ice.pref.interface.en1' (UCHAR) succeeded: 0xfc 10:19:23 INFO - -1380979904[b2733ac0]: (registry/INFO) insert 'ice.pref.interface.en0' (UCHAR) succeeded: 0xfb 10:19:23 INFO - -1380979904[b2733ac0]: (registry/INFO) insert 'ice.pref.interface.eth0' (UCHAR) succeeded: 0xfc 10:19:23 INFO - -1380979904[b2733ac0]: (registry/INFO) insert 'ice.pref.interface.eth1' (UCHAR) succeeded: 0xfb 10:19:23 INFO - -1380979904[b2733ac0]: (registry/INFO) insert 'ice.pref.interface.eth2' (UCHAR) succeeded: 0xf9 10:19:23 INFO - -1380979904[b2733ac0]: (registry/INFO) insert 'ice.pref.interface.ppp' (UCHAR) succeeded: 0xfa 10:19:23 INFO - -1380979904[b2733ac0]: (registry/INFO) insert 'ice.pref.interface.ppp0' (UCHAR) succeeded: 0xf9 10:19:23 INFO - -1380979904[b2733ac0]: (registry/INFO) insert 'ice.pref.interface.en2' (UCHAR) succeeded: 0xf8 10:19:23 INFO - -1380979904[b2733ac0]: (registry/INFO) insert 'ice.pref.interface.en3' (UCHAR) succeeded: 0xf7 10:19:23 INFO - -1380979904[b2733ac0]: (registry/INFO) insert 'ice.pref.interface.em0' (UCHAR) succeeded: 0xfb 10:19:23 INFO - -1380979904[b2733ac0]: (registry/INFO) insert 'ice.pref.interface.em1' (UCHAR) succeeded: 0xfc 10:19:23 INFO - -1380979904[b2733ac0]: (registry/INFO) insert 'ice.pref.interface.vmnet0' (UCHAR) succeeded: 0xf0 10:19:23 INFO - -1380979904[b2733ac0]: (registry/INFO) insert 'ice.pref.interface.vmnet1' (UCHAR) succeeded: 0xf1 10:19:23 INFO - -1380979904[b2733ac0]: (registry/INFO) insert 'ice.pref.interface.vmnet3' (UCHAR) succeeded: 0xef 10:19:23 INFO - -1380979904[b2733ac0]: (registry/INFO) insert 'ice.pref.interface.vmnet4' (UCHAR) succeeded: 0xee 10:19:23 INFO - -1380979904[b2733ac0]: (registry/INFO) insert 'ice.pref.interface.vmnet5' (UCHAR) succeeded: 0xed 10:19:23 INFO - -1380979904[b2733ac0]: (registry/INFO) insert 'ice.pref.interface.vmnet6' (UCHAR) succeeded: 0xec 10:19:23 INFO - -1380979904[b2733ac0]: (registry/INFO) insert 'ice.pref.interface.vmnet7' (UCHAR) succeeded: 0xeb (and more, too many to copy into the bug)
Status: NEW → RESOLVED
Closed: 10 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.