Closed Bug 1035011 Opened 10 years ago Closed 9 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: 9 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.