Closed Bug 981881 Opened 10 years ago Closed 8 years ago

Android 2.3 /tests/dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html (and others)| Unexpected callback for 'INTERNAL_ERROR'

Categories

(Firefox for Android Graveyard :: Testing, defect)

x86_64
Linux
defect
Not set
normal

Tracking

(Not tracked)

RESOLVED WONTFIX

People

(Reporter: gbrown, Assigned: gbrown)

References

Details

On the Android 2.3 emulator, several tests in dom/media/tests/mochitest fail consistently and have been disabled for the initial run of these tests.

https://tbpl.mozilla.org/php/getParsedLog.php?id=34455702&tree=Ash&full=1#error0

17:34:38     INFO -  983 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | Unexpected callback for 'INTERNAL_ERROR' with message = 'Cannot start media channels; cause = OK' at ["PCW_setLocalDescription@http://mochi.test:8888/tests/dom/media/tests/mochitest/pc.js:1340","PCT_setLocalDescription@http://mochi.test:8888/tests/dom/media/tests/mochitest/pc.js:562","DCT_waitForInitialDataChannel@http://mochi.test:8888/tests/dom/media/tests/mochitest/pc.js:874","DCT_setLocalDescription@http://mochi.test:8888/tests/dom/media/tests/mochitest/pc.js:822","commandsDataChannel<@http://mochi.test:8888/tests/dom/media/tests/mochitest/templates.js:336","_executeNext@http://mochi.test:8888/tests/dom/media/tests/mochitest/pc.js:77",""]

17:34:38     INFO -  1029 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/media/tests/mochitest/test_dataChannel_basicAudioVideoCombined.html | Unexpected callback for 'INTERNAL_ERROR' with message = 'Cannot start media channels; cause = OK' at ["PCW_setLocalDescription@http://mochi.test:8888/tests/dom/media/tests/mochitest/pc.js:1340","PCT_setLocalDescription@http://mochi.test:8888/tests/dom/media/tests/mochitest/pc.js:562","DCT_waitForInitialDataChannel@http://mochi.test:8888/tests/dom/media/tests/mochitest/pc.js:874","DCT_setLocalDescription@http://mochi.test:8888/tests/dom/media/tests/mochitest/pc.js:822","commandsDataChannel<@http://mochi.test:8888/tests/dom/media/tests/mochitest/templates.js:336","_executeNext@http://mochi.test:8888/tests/dom/media/tests/mochitest/pc.js:77",""]

17:34:38     INFO -  1420 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/media/tests/mochitest/test_peerConnection_basicAudio.html | Unexpected callback for 'INTERNAL_ERROR' with message = 'Cannot start media channels; cause = OK' at ["PCW_setLocalDescription@http://mochi.test:8888/tests/dom/media/tests/mochitest/pc.js:1340","PCT_setLocalDescription@http://mochi.test:8888/tests/dom/media/tests/mochitest/pc.js:562","commandsPeerConnection<@http://mochi.test:8888/tests/dom/media/tests/mochitest/templates.js:132","_executeNext@http://mochi.test:8888/tests/dom/media/tests/mochitest/pc.js:77",""]

... and there are other failures in this log with very similar looking log messages.
Most Android 2.3 mochitests are running fine now. The dom/media tests are disabled. I tried enabling them again in a try run, but failures persist:

https://tbpl.mozilla.org/php/getParsedLog.php?id=40289456&tree=Try&full=1
Hi Gian-Carlo -- can you give me a sense of how much work it would be to fix these tests for Android 2.3?  (We're trying to figure out if it's a small amount of work or a lot.) Please don't spend more than a day or so investigating this;  IMO it's not worth more than a day (or two) of your time.  Thanks!!
Flags: needinfo?(gpascutto)
I did not get my new tests from bug 1018928 working on the new Android 2.3 testers either, so I'm going to have to disable them too. Even with (required) fixes for the broken Camera drivers in that bug, we don't even seem to get to the point where a gUM dialog pops up.

I don't think there's anything to fix *in the tests*. gUM is not working on the testing hardware, period.

I guess it should be possible to replicate the exact emulator setup locally and see what's up?
Flags: needinfo?(gpascutto)
You can replicate the emulator setup locally, but the emulator behavior is affected by its host. To replicate the test, your best bet is to borrow a slave: https://wiki.mozilla.org/ReleaseEngineering/How_To/Request_a_slave
Whiteboard: [test disabled on Android 2.3] → [test disabled on Android 2.3][test disabled on Android 4.3]
See Also: → 1189784
test_dataChannel_basicAudioVideo.html still fails on Android 2.3 and Android 4.3.

https://treeherder.mozilla.org/#/jobs?repo=try&revision=40701771833f

Android 2.3 opt: http://ftp.mozilla.org/pub/mozilla.org/mobile/try-builds/gbrown@mozilla.com-40701771833f/try-android-api-9/try_ubuntu64_vm_mobile_test-mochitest-9-bm123-tests1-linux64-build111.txt.gz

10:15:22     INFO -  4083 INFO TEST-OK | dom/media/tests/mochitest/test_dataChannel_basicAudio.html | took 150258ms
10:15:22     INFO -  4084 INFO TEST-START | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html
10:15:43     INFO -  INFO | automation.py | Application ran for: 0:57:01.540470
10:15:43     INFO -  INFO | zombiecheck | Reading PID log: /tmp/tmpZKwwlIpidlog
10:15:44     INFO -  /data/tombstones does not exist; tombstone check skipped
10:15:46     INFO -  mozcrash Downloading symbols from: https://queue.taskcluster.net/v1/task/QR8X-rc2TWe9G0qjG2a0lA/artifacts/public/build/fennec-42.0a1.en-US.android-arm.crashreporter-symbols.zip
10:16:06     INFO -  mozcrash Saved minidump as /builds/slave/test/build/blobber_upload_dir/7a5bf627-26c4-6237-48c0a1d9-40c9e9b0.dmp
10:16:06     INFO -  mozcrash Saved app info as /builds/slave/test/build/blobber_upload_dir/7a5bf627-26c4-6237-48c0a1d9-40c9e9b0.extra
10:16:06  WARNING -  PROCESS-CRASH | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | application crashed [@ 0x4]
10:16:06     INFO -  Crash dump filename: /tmp/tmp7iWiVp/7a5bf627-26c4-6237-48c0a1d9-40c9e9b0.dmp
10:16:06     INFO -  Operating system: Android
10:16:06     INFO -                    0.0.0 Linux 2.6.29-g4bb8fa0 #1 Fri Feb 20 17:28:01 MST 2015 armv7l generic/sdk/generic:2.3.7/GINGERBREAD/eng.ubuntu.20140123.014351:eng/test-keys
10:16:06     INFO -  CPU: arm
10:16:06     INFO -       0 CPUs
10:16:06     INFO -  Crash reason:  SIGSEGV
10:16:06     INFO -  Crash address: 0x4
10:16:06     INFO -  Thread 10 (crashed)
10:16:06     INFO -   0  0x4
10:16:06     INFO -       r4 = 0x0028d710    r5 = 0x53d24fac    r6 = 0x00001e88    r7 = 0x4b6fd958
10:16:06     INFO -       r8 = 0x61aef000    r9 = 0x0000ab90   r10 = 0x4b6fdb94    fp = 0x5a513b94
10:16:06     INFO -       sp = 0x4b6fd908    lr = 0x5297927d    pc = 0x00000004
10:16:06     INFO -      Found by: given as instruction pointer in context
10:16:06     INFO -   1  libxul.so!__aeabi_fcmpgt + 0x810769
10:16:06     INFO -       sp = 0x4b6fd90c    pc = 0x53d24fac
10:16:06     INFO -      Found by: stack scanning
10:16:06     INFO -   2  libxul.so!__aeabi_fcmpgt + 0x810769
10:16:06     INFO -       sp = 0x4b6fd910    pc = 0x53d24fac
10:16:06     INFO -      Found by: stack scanning
10:16:06     INFO -   3  libxul.so!webrtc::OpenSlesInput::Init [opensles_input.cc:40701771833f : 143 + 0x5]
10:16:06     INFO -       sp = 0x4b6fd920    pc = 0x52d93d6d
10:16:06     INFO -      Found by: stack scanning
10:16:06     INFO -   4  libxul.so!webrtc::AudioDeviceModuleImpl::Init [audio_device_impl.cc:40701771833f : 661 + 0x7]
10:16:06     INFO -       r4 = 0x00000000    r5 = 0x5a89a000    sp = 0x4b6fd938    pc = 0x52d95671
10:16:06     INFO -      Found by: call frame info
10:16:06     INFO -   5  libxul.so!webrtc::VoEBaseImpl::Init [voe_base_impl.cc:40701771833f : 376 + 0x3]
10:16:06     INFO -       r4 = 0x61aef0b8    r5 = 0x00000000    r6 = 0x00001e58    sp = 0x4b6fd948
10:16:06     INFO -       pc = 0x52d8e251
10:16:06     INFO -      Found by: call frame info
10:16:06     INFO -   6  libxul.so!mozilla::WebrtcAudioConduit::Init [AudioConduit.cpp:40701771833f : 293 + 0x3]
10:16:06     INFO -       r4 = 0x5a8c6e00    r5 = 0x61aef0a0    r6 = 0x536c7b77    r7 = 0x538e8688
10:16:06     INFO -       r8 = 0x61aef0a8    r9 = 0x0000ab90    sp = 0x4b6fda10    pc = 0x52326ee9
10:16:06     INFO -      Found by: call frame info
10:16:06     INFO -   7  libxul.so!mozilla::AudioSessionConduit::Create [AudioConduit.cpp:40701771833f : 50 + 0x3]
10:16:06     INFO -       r4 = 0x5a8c6e00    r5 = 0x00000000    r6 = 0x4b6fda98    r7 = 0x00000001
10:16:06     INFO -       r8 = 0x4b6fdc7c    r9 = 0x4b6fdc90    sp = 0x4b6fda40    pc = 0x52327185
10:16:06     INFO -      Found by: call frame info
10:16:06     INFO -   8  libxul.so!mozilla::MediaPipelineFactory::GetOrCreateAudioConduit [MediaPipelineFactory.cpp:40701771833f : 592 + 0x5]
10:16:06     INFO -       r4 = 0x5917c19c    r5 = 0x4b6fda98    r6 = 0x5a513b70    r7 = 0x00000001
10:16:06     INFO -       r8 = 0x4b6fdc7c    r9 = 0x4b6fdc90    sp = 0x4b6fda58    pc = 0x52333e03
10:16:06     INFO -      Found by: call frame info
10:16:06     INFO -   9  libxul.so!mozilla::MediaPipelineFactory::CreateOrUpdateMediaPipeline [MediaPipelineFactory.cpp:40701771833f : 382 + 0xb]
10:16:06     INFO -       r4 = 0x5a513b70    r5 = 0x00000000    r6 = 0x4b6fdc7c    r7 = 0x4b6fdb94
10:16:06     INFO -       r8 = 0x4b6fdc90    r9 = 0x5a513d30   r10 = 0x5a513d54    fp = 0x5a513b94
10:16:06     INFO -       sp = 0x4b6fdb58    pc = 0x52335f4f
10:16:06     INFO -      Found by: call frame info
10:16:06     INFO -  10  libxul.so!mozilla::PeerConnectionMedia::UpdateMediaPipelines [PeerConnectionMedia.cpp:40701771833f : 516 + 0x7]
10:16:06     INFO -       r4 = 0x58474470    r5 = 0x4b6fdc90    r6 = 0x5917c100    r7 = 0x00000000
10:16:06     INFO -       r8 = 0x00000000    r9 = 0x00000001   r10 = 0x611c5540    fp = 0xffffff88
10:16:06     INFO -       sp = 0x4b6fdc78    pc = 0x5233f187
10:16:06     INFO -      Found by: call frame info
10:16:06     INFO -  11  libxul.so!mozilla::PeerConnectionImpl::SetSignalingState_m [PeerConnectionImpl.cpp:40701771833f : 2505 + 0xb]
10:16:06     INFO -       r4 = 0x611c5540    r5 = 0x00000001    r6 = 0x00000000    r7 = 0x00000001
10:16:06     INFO -       r8 = 0x4b6fdd30    r9 = 0x4b6fdd5c   r10 = 0x611c5540    fp = 0xffffff88
10:16:06     INFO -       sp = 0x4b6fdce0    pc = 0x5233c5b3
10:16:06     INFO -      Found by: call frame info
10:16:06     INFO -  12  libxul.so!mozilla::PeerConnectionImpl::SetLocalDescription [PeerConnectionImpl.cpp:40701771833f : 1588 + 0x5]
10:16:06     INFO -       r4 = 0x00000000    r5 = 0x611c5540    r6 = 0x00000001    r7 = 0x00000001
10:16:06     INFO -       r8 = 0x4b6fdd30    r9 = 0x4b6fdd5c   r10 = 0x611c5540    fp = 0xffffff88
10:16:06     INFO -       sp = 0x4b6fdd18    pc = 0x5233d3c1
10:16:06     INFO -      Found by: call frame info
10:16:06     INFO -  13  libxul.so!mozilla::dom::PeerConnectionImplBinding::setLocalDescription [PeerConnectionImpl.h:40701771833f : 383 + 0x9]
10:16:06     INFO -       r4 = 0x00000001    r5 = 0x4b6fdf54    r6 = 0x4b6fde84    r7 = 0x4b6fde30
10:16:06     INFO -       r8 = 0x57171040    r9 = 0x00000001   r10 = 0x611c5540    fp = 0xffffff88
10:16:06     INFO -       sp = 0x4b6fde10    pc = 0x52600a8b
10:16:06     INFO -      Found by: call frame info

Android 4.3 debug: http://ftp.mozilla.org/pub/mozilla.org/mobile/try-builds/gbrown@mozilla.com-40701771833f/try-android-api-11-debug/try_ubuntu64_vm_armv7_large-debug_test-mochitest-9-bm51-tests1-linux64-build132.txt.gz

09:36:17     INFO -  151 INFO TEST-START | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html
09:37:33     INFO -  <snipped 131 output lines - if you need more context, please use SimpleTest.requestCompleteLog() in your test>
09:37:33     INFO -  152 INFO PeerConnectionWrapper (pcRemote): Successfully set the local description
09:37:33     INFO -  153 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | signalingState after remote setLocalDescription is 'stable'
09:37:33     INFO -  154 INFO Run step 32: PC_LOCAL_GET_ANSWER
09:37:33     INFO -  155 INFO Run step 33: PC_LOCAL_SET_REMOTE_DESCRIPTION
09:37:33     INFO -  156 INFO PeerConnectionWrapper (pcLocal): "onsignalingstatechange" event fired
09:37:33     INFO -  157 INFO PeerConnectionWrapper (pcLocal): 'signalingstatechange' event received
09:37:33     INFO -  158 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | PeerConnectionWrapper (pcLocal): legal signaling state transition from have-local-offer to stable
09:37:33     INFO -  159 INFO PeerConnectionWrapper (pcLocal): Successfully set remote description
09:37:33     INFO -  160 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | signalingState after local setRemoteDescription is 'stable'
09:37:33     INFO -  161 INFO Run step 34: PC_REMOTE_SANE_LOCAL_SDP
09:37:33     INFO -  162 INFO Examining this SessionDescription: {"type":"answer","sdp":"v=0\r\no=mozilla...THIS_IS_SDPARTA-42.0a1 5821565259462213854 0 IN IP4 0.0.0.0\r\ns=-\r\nt=0 0\r\na=fingerprint:sha-256 FE:41:59:6D:58:F8:53:68:9B:7B:5C:E7:94:63:40:37:8B:B2:25:84:77:32:CF:D8:60:AF:65:0F:31:9F:FE:87\r\na=group:BUNDLE sdparta_0 sdparta_1 sdparta_2\r\na=ice-options:trickle\r\na=msid-semantic:WMS *\r\nm=audio 9 RTP/SAVPF 109\r\nc=IN IP4 0.0.0.0\r\na=sendrecv\r\na=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level\r\na=ice-pwd:0000843472480d139b533696e6b57af5\r\na=ice-ufrag:f9b0d894\r\na=mid:sdparta_0\r\na=msid:{75bf1b84-6fe3-4659-b5fc-8752146c2e69} {23852afc-50b8-4840-8235-eadb5a235162}\r\na=rtcp-mux\r\na=rtpmap:109 opus/48000/2\r\na=setup:active\r\na=ssrc:3037845954 cname:{29ebb29b-3c09-4773-9603-2364015e606c}\r\nm=video 9 RTP/SAVPF 120\r\nc=IN IP4 0.0.0.0\r\na=sendrecv\r\na=fmtp:120 max-fs=12288;max-fr=60\r\na=ice-pwd:0000843472480d139b533696e6b57af5\r\na=ice-ufrag:f9b0d894\r\na=mid:sdparta_1\r\na=msid:{4dcbcffc-224f-4b24-aa94-06e0537ac1c1} {4742f838-d7bd-4cdc-898e-97e829a82d3d}\r\na=rtcp-fb:120 nack\r\na=rtcp-fb:120 nack pli\r\na=rtcp-fb:120 ccm fir\r\na=rtcp-mux\r\na=rtpmap:120 VP8/90000\r\na=setup:active\r\na=ssrc:828229805 cname:{29ebb29b-3c09-4773-9603-2364015e606c}\r\nm=application 9 DTLS/SCTP 5000\r\nc=IN IP4 0.0.0.0\r\na=sendrecv\r\na=ice-pwd:0000843472480d139b533696e6b57af5\r\na=ice-ufrag:f9b0d894\r\na=mid:sdparta_2\r\na=sctpmap:5000 webrtc-datachannel 256\r\na=setup:active\r\na=ssrc:2427903764 cname:{29ebb29b-3c09-4773-9603-2364015e606c}\r\n"}
09:37:33     INFO -  163 INFO offerConstraintsList: [{"audio":true},{"video":true}]
09:37:33     INFO -  164 INFO offerOptions: {}
09:37:33     INFO -  165 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | SessionDescription is not null
09:37:33     INFO -  166 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | SessionDescription type is answer
09:37:33     INFO -  167 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | SessionDescription body length is plausible
09:37:33     INFO -  168 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | ICE username is present in SDP
09:37:33     INFO -  169 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | ICE password is present in SDP
09:37:33     INFO -  170 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | ICE fingerprint is present in SDP
09:37:33     INFO -  171 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | loopback interface is absent from SDP
09:37:33     INFO -  172 INFO at least one ICE candidate is present in SDP
09:37:33     INFO -  173 INFO expected audio tracks: 1
09:37:33     INFO -  174 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | audio m-line is present in SDP
09:37:33     INFO -  175 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | OPUS codec is present in SDP
09:37:33     INFO -  176 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | RTCP Mux is offered in SDP
09:37:33     INFO -  177 INFO expected video tracks: 1
09:37:33     INFO -  178 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | video m-line is present in SDP
09:37:33     INFO -  179 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | VP8 codec is present in SDP
09:37:33     INFO -  180 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | RTCP Mux is offered in SDP
09:37:33     INFO -  181 INFO Run step 35: PC_LOCAL_SANE_REMOTE_SDP
09:37:33     INFO -  182 INFO Examining this SessionDescription: {"type":"answer","sdp":"v=0\r\no=mozilla...THIS_IS_SDPARTA-42.0a1 5821565259462213854 0 IN IP4 0.0.0.0\r\ns=-\r\nt=0 0\r\na=fingerprint:sha-256 FE:41:59:6D:58:F8:53:68:9B:7B:5C:E7:94:63:40:37:8B:B2:25:84:77:32:CF:D8:60:AF:65:0F:31:9F:FE:87\r\na=group:BUNDLE sdparta_0 sdparta_1 sdparta_2\r\na=ice-options:trickle\r\na=msid-semantic:WMS *\r\nm=audio 9 RTP/SAVPF 109\r\nc=IN IP4 0.0.0.0\r\na=sendrecv\r\na=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level\r\na=ice-pwd:0000843472480d139b533696e6b57af5\r\na=ice-ufrag:f9b0d894\r\na=mid:sdparta_0\r\na=msid:{75bf1b84-6fe3-4659-b5fc-8752146c2e69} {23852afc-50b8-4840-8235-eadb5a235162}\r\na=rtcp-mux\r\na=rtpmap:109 opus/48000/2\r\na=setup:active\r\na=ssrc:3037845954 cname:{29ebb29b-3c09-4773-9603-2364015e606c}\r\nm=video 9 RTP/SAVPF 120\r\nc=IN IP4 0.0.0.0\r\na=sendrecv\r\na=fmtp:120 max-fs=12288;max-fr=60\r\na=ice-pwd:0000843472480d139b533696e6b57af5\r\na=ice-ufrag:f9b0d894\r\na=mid:sdparta_1\r\na=msid:{4dcbcffc-224f-4b24-aa94-06e0537ac1c1} {4742f838-d7bd-4cdc-898e-97e829a82d3d}\r\na=rtcp-fb:120 nack\r\na=rtcp-fb:120 nack pli\r\na=rtcp-fb:120 ccm fir\r\na=rtcp-mux\r\na=rtpmap:120 VP8/90000\r\na=setup:active\r\na=ssrc:828229805 cname:{29ebb29b-3c09-4773-9603-2364015e606c}\r\nm=application 9 DTLS/SCTP 5000\r\nc=IN IP4 0.0.0.0\r\na=sendrecv\r\na=ice-pwd:0000843472480d139b533696e6b57af5\r\na=ice-ufrag:f9b0d894\r\na=mid:sdparta_2\r\na=sctpmap:5000 webrtc-datachannel 256\r\na=setup:active\r\na=ssrc:2427903764 cname:{29ebb29b-3c09-4773-9603-2364015e606c}\r\n"}
09:37:33     INFO -  183 INFO offerConstraintsList: [{"audio":true},{"video":true}]
09:37:33     INFO -  184 INFO offerOptions: {}
09:37:33     INFO -  185 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | SessionDescription is not null
09:37:33     INFO -  186 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | SessionDescription type is answer
09:37:33     INFO -  187 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | SessionDescription body length is plausible
09:37:33     INFO -  188 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | ICE username is present in SDP
09:37:33     INFO -  189 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | ICE password is present in SDP
09:37:33     INFO -  190 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | ICE fingerprint is present in SDP
09:37:33     INFO -  191 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | loopback interface is absent from SDP
09:37:33     INFO -  192 INFO at least one ICE candidate is present in SDP
09:37:33     INFO -  193 INFO expected audio tracks: 1
09:37:33     INFO -  194 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | audio m-line is present in SDP
09:37:33     INFO -  195 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | OPUS codec is present in SDP
09:37:33     INFO -  196 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | RTCP Mux is offered in SDP
09:37:33     INFO -  197 INFO expected video tracks: 1
09:37:33     INFO -  198 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | video m-line is present in SDP
09:37:33     INFO -  199 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | VP8 codec is present in SDP
09:37:33     INFO -  200 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | RTCP Mux is offered in SDP
09:37:33     INFO -  201 INFO Run step 36: PC_LOCAL_WAIT_FOR_ICE_CONNECTED
09:37:33     INFO -  202 INFO PeerConnectionWrapper (pcLocal): iceConnectionState = new
09:37:33     INFO -  203 INFO PeerConnectionWrapper (pcRemote): 'onaddstream' event fired for {}
09:37:33     INFO -  204 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | track id {23265b73-beb5-4771-ad63-eb2bad84a91a} was expected
09:37:33     INFO -  205 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | track id {23265b73-beb5-4771-ad63-eb2bad84a91a} was not yet observed
09:37:33     INFO -  206 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | track id {23265b73-beb5-4771-ad63-eb2bad84a91a} was of kind video, which matches video
09:37:33     INFO -  207 INFO PeerConnectionWrapper (pcRemote) remote stream {27ddfcd6-efe8-4590-ae79-68d4bd96e732} with video track {23265b73-beb5-4771-ad63-eb2bad84a91a}
09:37:33     INFO -  208 INFO Got media stream: video (remote)
09:37:33     INFO -  209 INFO PeerConnectionWrapper (pcRemote): 'onaddstream' event fired for {}
09:37:33     INFO -  210 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | track id {d45d3e8a-2330-40a6-bf22-426284d69309} was expected
09:37:33     INFO -  211 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | track id {d45d3e8a-2330-40a6-bf22-426284d69309} was not yet observed
09:37:33     INFO -  212 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | track id {d45d3e8a-2330-40a6-bf22-426284d69309} was of kind audio, which matches audio
09:37:33     INFO -  213 INFO PeerConnectionWrapper (pcRemote) remote stream {f9c96796-dcda-43e5-841f-2c315364a65c} with audio track {d45d3e8a-2330-40a6-bf22-426284d69309}
09:37:33     INFO -  214 INFO Got media stream: audio (remote)
09:37:33     INFO -  215 INFO PeerConnectionWrapper (pcLocal): 'onaddstream' event fired for {}
09:37:33     INFO -  216 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | track id {4742f838-d7bd-4cdc-898e-97e829a82d3d} was expected
09:37:33     INFO -  217 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | track id {4742f838-d7bd-4cdc-898e-97e829a82d3d} was not yet observed
09:37:33     INFO -  218 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | track id {4742f838-d7bd-4cdc-898e-97e829a82d3d} was of kind video, which matches video
09:37:33     INFO -  219 INFO PeerConnectionWrapper (pcLocal) remote stream {4dcbcffc-224f-4b24-aa94-06e0537ac1c1} with video track {4742f838-d7bd-4cdc-898e-97e829a82d3d}
09:37:33     INFO -  220 INFO Got media stream: video (remote)
09:37:33     INFO -  221 INFO PeerConnectionWrapper (pcLocal): 'onaddstream' event fired for {}
09:37:33     INFO -  222 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | track id {23852afc-50b8-4840-8235-eadb5a235162} was expected
09:37:33     INFO -  223 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | track id {23852afc-50b8-4840-8235-eadb5a235162} was not yet observed
09:37:33     INFO -  224 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | track id {23852afc-50b8-4840-8235-eadb5a235162} was of kind audio, which matches audio
09:37:33     INFO -  225 INFO PeerConnectionWrapper (pcLocal) remote stream {75bf1b84-6fe3-4659-b5fc-8752146c2e69} with audio track {23852afc-50b8-4840-8235-eadb5a235162}
09:37:33     INFO -  226 INFO Got media stream: audio (remote)
09:37:33     INFO -  227 INFO pcLocal: iceCandidate = {"candidate":"candidate:0 1 UDP 2130444543 10.0.2.15 47293 typ host","sdpMid":"","sdpMLineIndex":0}
09:37:33     INFO -  228 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | ICE candidate contains candidate
09:37:33     INFO -  229 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | SDP MID has length zero
09:37:33     INFO -  230 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | SDP MLine Index needs to exist
09:37:33     INFO -  231 INFO Received: {"candidate":"candidate:0 1 UDP 2130444543 10.0.2.15 47293 typ host","sdpMid":"","sdpMLineIndex":0} from pcLocal
09:37:33     INFO -  232 INFO PeerConnectionWrapper (pcRemote): adding ICE candidate {"candidate":"candidate:0 1 UDP 2130444543 10.0.2.15 47293 typ host","sdpMid":"","sdpMLineIndex":0}
09:37:33     INFO -  233 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | PeerConnectionWrapper (pcRemote) successfully added an ICE candidate
09:37:33     INFO -  234 INFO pcLocal: iceCandidate = {"candidate":"candidate:0 2 UDP 2130444542 10.0.2.15 37968 typ host","sdpMid":"","sdpMLineIndex":0}
09:37:33     INFO -  235 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | ICE candidate contains candidate
09:37:33     INFO -  236 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | SDP MID has length zero
09:37:33     INFO -  237 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | SDP MLine Index needs to exist
09:37:33     INFO -  238 INFO Received: {"candidate":"candidate:0 2 UDP 2130444542 10.0.2.15 37968 typ host","sdpMid":"","sdpMLineIndex":0} from pcLocal
09:37:33     INFO -  239 INFO PeerConnectionWrapper (pcRemote): adding ICE candidate {"candidate":"candidate:0 2 UDP 2130444542 10.0.2.15 37968 typ host","sdpMid":"","sdpMLineIndex":0}
09:37:33     INFO -  240 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | PeerConnectionWrapper (pcRemote) successfully added an ICE candidate
09:37:33     INFO -  241 INFO pcLocal: received end of trickle ICE event
09:37:33     INFO -  242 INFO pcRemote: iceCandidate = {"candidate":"candidate:0 1 UDP 2130444543 10.0.2.15 49933 typ host","sdpMid":"","sdpMLineIndex":0}
09:37:33     INFO -  243 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | ICE candidate contains candidate
09:37:33     INFO -  244 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | SDP MID has length zero
09:37:33     INFO -  245 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | SDP MLine Index needs to exist
09:37:33     INFO -  246 INFO Received: {"candidate":"candidate:0 1 UDP 2130444543 10.0.2.15 49933 typ host","sdpMid":"","sdpMLineIndex":0} from pcRemote
09:37:33     INFO -  247 INFO PeerConnectionWrapper (pcLocal): adding ICE candidate {"candidate":"candidate:0 1 UDP 2130444543 10.0.2.15 49933 typ host","sdpMid":"","sdpMLineIndex":0}
09:37:33     INFO -  248 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | PeerConnectionWrapper (pcLocal) successfully added an ICE candidate
09:37:33     INFO -  249 INFO pcRemote: received end of trickle ICE event
09:37:33     INFO -  250 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | iceConnectionState should not be undefined
09:37:33     INFO -  251 INFO PeerConnectionWrapper (pcRemote): oniceconnectionstatechange fired, new state is: failed
09:37:33     INFO -  252 INFO TEST-UNEXPECTED-FAIL | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | PeerConnectionWrapper (pcRemote): legal ICE state transition from new to failed
09:37:33     INFO -      PeerConnectionWrapper.prototype.logIceConnectionState/this.ice_connection_callbacks.logIceStatus@dom/media/tests/mochitest/pc.js:1174:11
09:37:33     INFO -      PeerConnectionWrapper/this._pc.oniceconnectionstatechange/<@dom/media/tests/mochitest/pc.js:699:7
09:37:33     INFO -      PeerConnectionWrapper/this._pc.oniceconnectionstatechange@dom/media/tests/mochitest/pc.js:698:5
09:37:33     INFO -  253 INFO TEST-PASS | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | iceConnectionState should not be undefined
09:37:33     INFO -  254 INFO PeerConnectionWrapper (pcLocal): oniceconnectionstatechange fired, new state is: failed
09:37:33     INFO -  255 INFO TEST-UNEXPECTED-FAIL | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | PeerConnectionWrapper (pcLocal): legal ICE state transition from new to failed
09:37:33     INFO -      PeerConnectionWrapper.prototype.logIceConnectionState/this.ice_connection_callbacks.logIceStatus@dom/media/tests/mochitest/pc.js:1174:11
09:37:33     INFO -      PeerConnectionWrapper/this._pc.oniceconnectionstatechange/<@dom/media/tests/mochitest/pc.js:699:7
09:37:33     INFO -      PeerConnectionWrapper/this._pc.oniceconnectionstatechange@dom/media/tests/mochitest/pc.js:698:5
09:37:33     INFO -  256 INFO PeerConnectionWrapper (pcLocal): iceConnectionState = failed
09:37:33     INFO -  257 INFO PeerConnectionWrapper (pcLocal): ICE connection state log: new,failed
09:37:33     INFO -  258 INFO PeerConnectionWrapper (pcLocal): iceConnectionState = failed
09:37:33     INFO -  259 INFO TEST-UNEXPECTED-FAIL | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | PeerConnectionWrapper (pcLocal): ICE switched to 'connected' state
09:37:33     INFO -      waitForIceConnected/<@dom/media/tests/mochitest/templates.js:84:7
09:37:33     INFO -  260 INFO Run step 37: PC_REMOTE_WAIT_FOR_ICE_CONNECTED
09:37:33     INFO -  261 INFO PeerConnectionWrapper (pcRemote): iceConnectionState = failed
09:37:33     INFO -  262 INFO TEST-UNEXPECTED-FAIL | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | PeerConnectionWrapper (pcRemote): ICE is already in bad state: failed
09:37:33     INFO -      waitForIceConnected@dom/media/tests/mochitest/templates.js:76:7
09:37:33     INFO -      PC_REMOTE_WAIT_FOR_ICE_CONNECTED@dom/media/tests/mochitest/templates.js:430:12
09:37:33     INFO -      CommandChain.prototype.execute/</<@dom/media/tests/mochitest/head.js:461:31
09:37:33     INFO -  263 INFO TEST-UNEXPECTED-FAIL | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | Error in test execution: Error: PeerConnectionWrapper (pcRemote): ICE is already in bad state: failed waitForIceConnected@http://mochi.test:8888/tests/dom/media/tests/mochitest/templates.js:77:29 ... PC_REMOTE_WAIT_FOR_ICE_CONNECTED@http://mochi.test:8888/tests/dom/media/tests/mochitest/templates.js:430:12 ... CommandChain.prototype.execute/</<@http://mochi.test:8888/tests/dom/media/tests/mochitest/head.js:461:31 ...
09:37:33     INFO -      CommandChain.prototype.execute/<@dom/media/tests/mochitest/head.js:465:1
09:37:33     INFO -  264 INFO closeDataChannels called with index: 0
09:37:33     INFO -  265 INFO TEST-FAIL | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | The author of the test has indicated that flaky timeouts are expected.  Reason: WebRTC inherently depends on timeouts
09:37:33     INFO -  266 INFO DataChannelWrapper (pcLocal_channel_0): Closing channel
09:37:33     INFO -  267 INFO TEST-FAIL | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | The author of the test has indicated that flaky timeouts are expected.  Reason: WebRTC inherently depends on timeouts
09:39:22     INFO -  268 INFO TEST-UNEXPECTED-FAIL | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | Error in test execution: Error: timeout after 60s: failed to close data channel pair timerGuard/<@http://mochi.test:8888/tests/dom/media/tests/mochitest/pc.js:121:13 ...
09:39:22     INFO -      PeerConnectionTest.prototype.run/<@dom/media/tests/mochitest/pc.js:413:1
09:42:12     INFO -  269 INFO TEST-UNEXPECTED-FAIL | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | Test timed out.
09:42:12     INFO -      reportError@SimpleTest/TestRunner.js:334:7
09:42:12     INFO -      TestRunner._checkForHangs@SimpleTest/TestRunner.js:354:7
09:42:58     INFO -  270 INFO TEST-UNEXPECTED-FAIL | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | Test timed out.
09:42:58     INFO -      reportError@SimpleTest/TestRunner.js:334:7
09:42:58     INFO -      TestRunner._checkForHangs@SimpleTest/TestRunner.js:354:7
09:43:45     INFO -  271 ERROR [SimpleTest.finish()] this test already called finish!
09:43:45     INFO -  272 INFO TEST-UNEXPECTED-ERROR | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | called finish() multiple times
09:43:45     INFO -  TEST-INFO took 449362ms
09:43:45     INFO -  273 INFO TEST-UNEXPECTED-FAIL | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | Test timed out.
09:43:45     INFO -      reportError@SimpleTest/TestRunner.js:334:7
09:43:45     INFO -      TestRunner._checkForHangs@SimpleTest/TestRunner.js:354:7
09:45:04     INFO -  274 ERROR [SimpleTest.finish()] this test already called finish!
09:45:04     INFO -  275 INFO TEST-UNEXPECTED-ERROR | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | called finish() multiple times
09:45:04     INFO -  TEST-INFO
09:45:04     INFO -  276 INFO TEST-UNEXPECTED-FAIL | dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html | Test timed out.
09:45:04     INFO -      reportError@SimpleTest/TestRunner.js:334:7
09:45:04     INFO -      TestRunner._checkForHangs@SimpleTest/TestRunner.js:354:7
09:45:04     INFO -  277 INFO TEST-UNEXPECTED-FAIL | (SimpleTest/TestRunner.js) | 4 test timeouts, giving up.
09:45:04     INFO -      reportError@SimpleTest/TestRunner.js:334:7
09:45:04     INFO -      TestRunner._checkForHangs@SimpleTest/TestRunner.js:362:9
09:45:04     INFO -  278 INFO TEST-UNEXPECTED-FAIL | (SimpleTest/TestRunner.js) | Skipping 121 remaining tests.
09:45:04     INFO -      reportError@SimpleTest/TestRunner.js:334:7
09:45:04     INFO -      TestRunner._checkForHangs@SimpleTest/TestRunner.js:364:9
09:47:09     INFO -  279 ERROR [SimpleTest.finish()] this test already called finish!
09:47:09     INFO -  280 INFO TEST-UNEXPECTED-ERROR | (SimpleTest/TestRunner.js) | called finish() multiple times
09:47:09     INFO -  TEST-INFO
09:48:11     INFO -  281 INFO TEST-UNEXPECTED-FAIL | (SimpleTest/TestRunner.js) | /tests/dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html - finished in a non-clean fashion, probably because it didn't call SimpleTest.finish()
09:48:11     INFO -  {u'loaded_test_url': u'/tests/dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html'}
09:48:11     INFO -  282 INFO TEST-OK | (SimpleTest/TestRunner.js) |
09:50:46     INFO -  283 INFO TEST-UNEXPECTED-FAIL | (SimpleTest/TestRunner.js) | undefined assertion name - Result logged after SimpleTest.finish()
09:50:59     INFO -  284 INFO TEST-START | Shutdown
Blocks: 1189784
See Also: 1189784
Could this be due to the VMs lacking some aspect of real audio hardware?  I'm presuming it's crashing somewhere inside OpenSLESProvider::RealizeEngine().
If it is a real hardware requirement, that's probably hard to fix.

On a more optimistic note, I wonder if there is a dependency on some VM software/driver. For instance, in the past, we found that some tests require PulseAudio to be installed on the VM (it is now). If we just need some packages installed on the VM, that's relatively easy. I'm not sure how to determine what is required.
fwiw, if test_dataChannel_basicAudioVideo.html is skipped, the next test, test_dataChannel_basicAudioVideoCombined.html, crashes in just the same way:

https://treeherder.mozilla.org/#/jobs?repo=try&revision=9e1982f43cf3
I was surprised we're trying to use OpenSL on Android 2.3, but it looks like this bug 1020227 only disabled it for output. This looks like broken OpenSLES drivers in the emulator.

Even so that doesn't explain anything about 4.3.

It noticed these warnings:
09:52:46     INFO -  07-31 09:38:55.485 W/AudioTrackShared(   40): stepServer() could not lock cblk
09:52:46     INFO -  07-31 09:39:09.605 W/AudioTrackShared(   40): stepServer() could not lock cblk

More things broken in the emulator?
Geoff, Gian-Carlo -- Does anyone have the bandwidth to look into this?  If you aren't the right folks to be asking, can you point me at who is?  I don't care about getting tests running on Android 2.3, but I do care about them for Android 4.3.  Any help is appreciated.  Bug 1189784 (which is a P1 for me) is stuck until this bug gets unstuck.  Thanks.
Flags: needinfo?(gpascutto)
Flags: needinfo?(gbrown)
Flags: needinfo?(gbrown)
Summary: Android 2.3 /tests/dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html (and others)| Unexpected callback for 'INTERNAL_ERROR' → Android 4.3 (and 2.3) /tests/dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html (and others)| Unexpected callback for 'INTERNAL_ERROR'
I should be able to find time this week to investigate. My efforts would be focused on determining if there is something missing from the test environment -- a problem in the android image, the emulator, or the emulator host -- and right now that "something" feels pretty broad...I'm not sure what I'm looking for. If gcp (or someone else) could tell me more about what these tests are doing and what seems to be failing, that would be very helpful.
If this stuff works on a real device, I would recommend just disabling it in the emulator and running it in autophone instead.
The original report said 2.3. But the bug now says 4.3. Do we know when 4.3 started being a problem? It may not be worth the effort to throw much development at trying to fix bugs in 2.3 emulation.
This has always been a problem on the 4.3 emulator: As soon as we started running tests on the 4.3 emulator (March 2015), this failure was observed (whiteboard change, 2015-03-26).

autophone is an interesting option. It would be nice to know what's going wrong on the emulator though.
Curiously, if I run the emulator on my laptop, with the same 4.3 avd used in automation, this test passes, and most dom/media tests pass (I get a clean run on my laptop if I just add skip annotations for test_dataChannel_basicAudioVideoCombined.html, test_peerConnection_addSecondVideoStreamNoBundle.html, test_peerConnection_capturedVideo.html and test_getUserMedia_audioCapture.html). That suggests that it might be possible to get most tests running in automation by manipulating the host environment...somehow. I'll borrow an aws host and see if I can spot the difference.

gbrown@mozpad:~/src$ ./mach mochitest dom/media/tests/mochitest
From _tests: Kept 35946 existing; Added/updated 0; Removed 0 files and 0 directories.

######
### Now running mochitest-plain.
######

 0:01.12 LOG: MainThread INFO Android sdk version '18'; will use this to filter manifests
 0:01.39 LOG: MainThread INFO Checking for orphan ssltunnel processes...
 0:01.45 LOG: MainThread INFO Checking for orphan xpcshell processes...
 0:01.50 SUITE_START: MainThread 107
...
pk12util: PKCS12 IMPORT SUCCESSFUL
 0:07.22 LOG: MainThread INFO MochitestServer : launching [u'/home/gbrown/objdirs/firefox/dist/bin/xpcshell', '-g', '/home/gbrown/objdirs/firefox/dist/bin', '-v', '170', '-f', '/home/gbrown/objdirs/firefox/dist/bin/components/httpd.js', '-e', "const _PROFILE_PATH = '/tmp/tmp9l7ab8.mozrunner'; const _SERVER_PORT = '8888'; const _SERVER_ADDR = '192.168.0.81'; const _TEST_PREFIX = undefined; const _DISPLAY_RESULTS = false;", '-f', '/home/gbrown/objdirs/droid/_tests/testing/mochitest/server.js']
 0:07.22 LOG: MainThread INFO runtests.py | Server pid: 10245
 0:07.23 LOG: MainThread INFO runtests.py | Websocket server pid: 10248
 0:07.24 LOG: MainThread INFO runtests.py | SSL tunnel pid: 10256
 0:12.45 LOG: MainThread INFO runtests.py | Running tests: start.

INFO | automation.py | Application pid: 4370
 0:31.62 LOG:  INFO SimpleTest START
 0:31.68 TEST_START:  dom/media/tests/mochitest/test_dataChannel_basicAudio.html
 0:57.89 TEST_END:  OK
 0:58.27 TEST_START:  dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html
 2:52.56 TEST_END:  OK
 2:52.87 TEST_START:  dom/media/tests/mochitest/test_dataChannel_basicAudioVideoNoBundle.html
 4:07.90 TEST_END:  OK
 4:08.34 TEST_START:  dom/media/tests/mochitest/test_dataChannel_basicDataOnly.html
 4:11.54 TEST_END:  OK
 4:11.72 TEST_START:  dom/media/tests/mochitest/test_dataChannel_basicVideo.html
 4:33.36 TEST_END:  OK
 4:33.59 TEST_START:  dom/media/tests/mochitest/test_dataChannel_bug1013809.html
 5:10.00 TEST_END:  OK
 5:10.22 TEST_START:  dom/media/tests/mochitest/test_dataChannel_noOffer.html
 5:11.82 TEST_END:  OK
 5:12.00 TEST_START:  dom/media/tests/mochitest/test_enumerateDevices.html
 5:13.63 TEST_END:  OK
 5:13.86 TEST_START:  dom/media/tests/mochitest/test_getUserMedia_basicAudio.html
 5:15.42 TEST_END:  OK
 5:15.62 TEST_START:  dom/media/tests/mochitest/test_getUserMedia_basicVideo.html
 5:17.15 TEST_END:  OK
 5:17.34 TEST_START:  dom/media/tests/mochitest/test_getUserMedia_basicVideoAudio.html
 5:19.02 TEST_END:  OK
 5:19.23 TEST_START:  dom/media/tests/mochitest/test_getUserMedia_basicVideo_playAfterLoadedmetadata.html
 5:20.92 TEST_END:  OK
 5:21.13 TEST_START:  dom/media/tests/mochitest/test_getUserMedia_constraints.html
 5:23.21 TEST_END:  OK
 5:23.45 TEST_START:  dom/media/tests/mochitest/test_getUserMedia_gumWithinGum.html
 5:25.11 TEST_END:  OK
 5:25.29 TEST_START:  dom/media/tests/mochitest/test_getUserMedia_peerIdentity.html
 5:28.86 TEST_END:  OK
 5:29.22 TEST_START:  dom/media/tests/mochitest/test_getUserMedia_playAudioTwice.html
 5:30.90 TEST_END:  OK
 5:31.09 TEST_START:  dom/media/tests/mochitest/test_getUserMedia_playVideoAudioTwice.html
 5:32.70 TEST_END:  OK
 5:32.89 TEST_START:  dom/media/tests/mochitest/test_getUserMedia_playVideoTwice.html
 5:34.72 TEST_END:  OK
 5:34.91 TEST_START:  dom/media/tests/mochitest/test_getUserMedia_stopAudioStream.html
 5:36.48 TEST_END:  OK
 5:36.67 TEST_START:  dom/media/tests/mochitest/test_getUserMedia_stopAudioStreamWithFollowupAudio.html
 5:39.06 TEST_END:  OK
 5:39.24 TEST_START:  dom/media/tests/mochitest/test_getUserMedia_stopVideoAudioStream.html
 5:40.91 TEST_END:  OK
 5:41.09 TEST_START:  dom/media/tests/mochitest/test_getUserMedia_stopVideoAudioStreamWithFollowupVideoAudio.html
 5:42.99 TEST_END:  OK
 5:43.17 TEST_START:  dom/media/tests/mochitest/test_getUserMedia_stopVideoStream.html
 5:44.75 TEST_END:  OK
 5:44.98 TEST_START:  dom/media/tests/mochitest/test_getUserMedia_stopVideoStreamWithFollowupVideo.html
 5:46.76 TEST_END:  OK
 5:46.94 TEST_START:  dom/media/tests/mochitest/test_peerConnection_addDataChannel.html
 6:02.03 TEST_END:  OK
 6:02.29 TEST_START:  dom/media/tests/mochitest/test_peerConnection_addDataChannelNoBundle.html
 6:21.64 TEST_END:  OK
 6:21.91 TEST_START:  dom/media/tests/mochitest/test_peerConnection_addIceCandidate.html
 6:24.56 TEST_END:  OK
 6:24.77 TEST_START:  dom/media/tests/mochitest/test_peerConnection_addSecondAudioStream.html
 6:44.99 TEST_END:  OK
 6:45.28 TEST_START:  dom/media/tests/mochitest/test_peerConnection_addSecondAudioStreamNoBundle.html
 7:09.92 TEST_END:  OK
 7:10.32 TEST_START:  dom/media/tests/mochitest/test_peerConnection_addSecondVideoStream.html
...
Depends on: 1193054
I borrowed an aws host, but it was accidentally misconfigured and test results were consistent with my local results (Comment 15). When the aws configuration was corrected, new test results on the loaner were consistent with try results.

I verified that pulseaudio was running on both aws loaners. Also both aws loaners had the same pulseaudio and alsa packages installed. Indeed, all the same packages were installed on the first aws loaner as on the second. The only difference between the first and second aws loaners was the aws ec2 instance type: Most dom/media mochitests pass if the emulator is run on a c3.xlarge instance; several tests fail if the emulator is run on a m1.medium instance. Maybe the single-core m1.medium instance is too slow, or perhaps timing differences avoid a fatal condition on multi-core instances.

I am trying to verify that these results are consistent. If they are, I will propose that Android 4.3 mochitests are moved to c3.xlarge. A few tests will still need to be skipped, but it looks like many will pass.
Geoff is (successfully) looking into this.
Flags: needinfo?(gpascutto)
(In reply to Gian-Carlo Pascutto [:gcp] from comment #17)
> Geoff is (successfully) looking into this.

Cool, Thanks, Geoff (and Gian-Carlo)!
Assignee: nobody → gbrown
I have not seen this failure on 4.3 lately (since the change to c3.xlarge hosts?). test_dataChannel_basicAudioVideo.html is still disabled on 4.3, but for intermittent timeouts (via bug 1189784). Probably best to say this is a 2.3-only bug now.
Assignee: gbrown → nobody
Summary: Android 4.3 (and 2.3) /tests/dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html (and others)| Unexpected callback for 'INTERNAL_ERROR' → Android 2.3 /tests/dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html (and others)| Unexpected callback for 'INTERNAL_ERROR'
Whiteboard: [test disabled on Android 2.3][test disabled on Android 4.3] → [test disabled on Android 2.3]
Android 2.3 is no longer supported in Firefox 48+.

Test manifests were updated in bug 1251013.

(Still skipped on 4.3 -- bug 1189784/bug 1200411.)
Assignee: nobody → gbrown
Status: NEW → RESOLVED
Closed: 8 years ago
Resolution: --- → WONTFIX
Whiteboard: [test disabled on Android 2.3]
Product: Firefox for Android → Firefox for Android Graveyard
You need to log in before you can comment on or make changes to this bug.