1575666 - Intermittent Android dom/media/test/crashtests/1257700.html | load failed: timed out after 300000 ms waiting for 'load' event

Status: NEW

(Core :: Audio/Video: Playback, defect)

Description

[Geoff Brown [:gbrown]]

The most frequently failing test tracked by bug 1542346 is dom/media/test/crashtests/1257700.html.

Examples:
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=261931842&repo=autoland&lineNumber=4031
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=261822594&repo=autoland&lineNumber=4031
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=261633923&repo=mozilla-central&lineNumber=4028

[task 2019-08-16T03:29:26.679Z] 03:29:26     INFO -  REFTEST TEST-START | http://10.0.2.2:8854/tests/dom/media/test/crashtests/1257700.html
[task 2019-08-16T03:29:26.679Z] 03:29:26     INFO -  REFTEST TEST-LOAD | http://10.0.2.2:8854/tests/dom/media/test/crashtests/1257700.html | 622 / 3789 (16%)
[task 2019-08-16T03:34:23.996Z] 03:34:23     INFO -  REFTEST TEST-UNEXPECTED-FAIL | http://10.0.2.2:8854/tests/dom/media/test/crashtests/1257700.html | load failed: timed out after 300000 ms waiting for 'load' event for http://10.0.2.2:8854/tests/dom/media/test/crashtests/1257700.html
[task 2019-08-16T03:34:23.996Z] 03:34:23     INFO -  REFTEST INFO | Saved log: START http://10.0.2.2:8854/tests/dom/media/test/crashtests/1257700.html
[task 2019-08-16T03:34:23.996Z] 03:34:23     INFO -  REFTEST TEST-END | http://10.0.2.2:8854/tests/dom/media/test/crashtests/1257700.html

Comment 1

[Geoff Brown [:gbrown]]

Logcat has more info, like:

https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=261931842&repo=autoland&lineNumber=4031
https://taskcluster-artifacts.net/W6EkdkOrR_a_WEcP_pqUyw/0/public/test_info//logcat-emulator-5554.log

08-16 04:29:20.687  2792  2807 I Gecko   : {"action":"log","time":1565926160687,"thread":null,"pid":null,"source":"reftest","level":"DEBUG","message":"Loading a blank page"}
08-16 04:29:20.694  2862  3108 I libOpenSLES: Emulating old channel mask behavior (ignoring positional mask 0x3, using default mask 0x3 based on channel count of 2)
08-16 04:29:20.694  2862  3108 D AudioTrack: Client defaulted notificationFrames to 720 for frameCount 1440
08-16 04:29:20.697  2792  2807 I Gecko   : 
08-16 04:29:20.697  2792  2807 I Gecko   : {"action":"test_start","time":1565926160697,"thread":null,"pid":null,"source":"reftest","test":"http://10.0.2.2:8854/tests/dom/media/test/crashtests/1257700.html"}
08-16 04:29:20.697  2792  2807 I Gecko   : REFTEST TEST-LOAD | http://10.0.2.2:8854/tests/dom/media/test/crashtests/1257700.html | 622 / 3789 (16%)
08-16 04:29:20.697  2792  2807 I Gecko   : 
08-16 04:29:20.697  2792  2807 I Gecko   : {"action":"log","time":1565926160697,"thread":null,"pid":null,"source":"reftest","level":"DEBUG","message":"START http://10.0.2.2:8854/tests/dom/media/test/crashtests/1257700.html"}
08-16 04:29:20.737  2862  2877 E Web Content: [JavaScript Error: "The character encoding of the HTML document was not declared. The document will render with garbled text in some browser configurations if the document contains characters from outside the US-ASCII range. The character encoding of the page must be declared in the document or in the transfer protocol." {file: "http://10.0.2.2:8854/tests/dom/media/test/crashtests/1257700.html" line: 0}]
08-16 04:29:20.785  2792  2804 D EGL_emulation: eglCreateContext: 0x731deabd00a0: maj 2 min 0 rcv 2
08-16 04:29:20.785  2792  2804 D EGL_emulation: eglMakeCurrent: 0x731deabd00a0: ver 2 0 (tinfo 0x731dc4e189a0)
08-16 04:29:20.800  2862  3191 D         : HostConnection::get() New Host Connection established 0x731deaaedb40, tid 3191
08-16 04:29:20.828  1359  1359 I MediaPlayerService: MediaPlayerService::getOMX
08-16 04:29:20.828  3042  3198 I OMXClient: MuxOMX ctor
08-16 04:29:20.829  1356  1366 I OMXMaster: makeComponentInstance(OMX.google.vp9.decoder) in mediacodec process
08-16 04:29:20.840  1359  1370 E ResourceManagerService: Rejected addResource call with invalid pid.
08-16 04:29:20.840  3042  3197 I MediaCodec: MediaCodec will operate in async mode
08-16 04:29:20.840  3042  3057 D HardwareCodecCapability: The device ModelID is Android SDK built for x86_64
08-16 04:29:20.841  3042  3197 I MediaCodec: [OMX.google.vp9.decoder] setting surface generation to 3115011
08-16 04:29:20.841  1356  1982 W OMXNodeInstance: [54c0024:google.vp9.decoder] component does not support metadata mode; using fallback
08-16 04:29:20.841  3042  3198 E ACodec  : [OMX.google.vp9.decoder] storeMetaDataInBuffers failed w/ err -1010
08-16 04:29:20.854  1356  1982 E OMXNodeInstance: getParameter(54c0024:google.vp9.decoder, ParamVideoAndroidVp8Encoder(0x6f600007)) ERROR: UnsupportedIndex(0x8000101a)
08-16 04:29:20.861  1359  1370 E ResourceManagerService: Rejected addResource call with invalid pid.
08-16 04:29:20.870  1356  3199 E SoftVPX : on2 decoder failed to decode frame. err: 7
08-16 04:29:20.871  3042  3198 E ACodec  : [OMX.google.vp9.decoder] ERROR(0x80001001)
08-16 04:29:20.871  3042  3198 E ACodec  : signalError(omxError 0x80001001, internalError -2147483648)
08-16 04:29:20.871  3042  3197 E MediaCodec: Codec reported err 0x80001001, actionCode 0, while in state 6
08-16 04:29:20.871  3042  3042 W System.err: android.media.MediaCodec$CodecException: Error 0x80001001
08-16 04:29:20.871  3042  3042 W System.err: java.lang.Exception: codec error:0
08-16 04:29:20.872  3042  3042 W System.err: 	at org.mozilla.gecko.media.Codec$Callbacks.onError(Codec.java:48)
08-16 04:29:20.872  3042  3042 W System.err: 	at org.mozilla.gecko.media.LollipopAsyncCodec$CodecCallback$Forwarder.handleMessage(LollipopAsyncCodec.java:62)
08-16 04:29:20.872  3042  3042 W System.err: 	at org.mozilla.gecko.media.LollipopAsyncCodec$CodecCallback$Forwarder.notify(LollipopAsyncCodec.java:76)
08-16 04:29:20.872  3042  3042 W System.err: 	at org.mozilla.gecko.media.LollipopAsyncCodec$CodecCallback$Forwarder.onError(LollipopAsyncCodec.java:94)
08-16 04:29:20.872  3042  3042 W System.err: 	at org.mozilla.gecko.media.LollipopAsyncCodec$CodecCallback$Forwarder.access$400(LollipopAsyncCodec.java:32)
08-16 04:29:20.872  3042  3042 W System.err: 	at org.mozilla.gecko.media.LollipopAsyncCodec$CodecCallback.onError(LollipopAsyncCodec.java:134)
08-16 04:29:20.872  3042  3042 W System.err: 	at android.media.MediaCodec$EventHandler.handleCallback(MediaCodec.java:1669)
08-16 04:29:20.872  3042  3042 W System.err: 	at android.media.MediaCodec$EventHandler.handleMessage(MediaCodec.java:1609)
08-16 04:29:20.872  3042  3042 W System.err: 	at android.os.Handler.dispatchMessage(Handler.java:102)
08-16 04:29:20.872  3042  3042 W System.err: 	at android.os.Looper.loop(Looper.java:154)
08-16 04:29:20.872  3042  3042 W System.err: 	at android.app.ActivityThread.main(ActivityThread.java:6077)
08-16 04:29:20.872  3042  3042 W System.err: 	at java.lang.reflect.Method.invoke(Native Method)
08-16 04:29:20.872  3042  3042 W System.err: 	at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:866)
08-16 04:29:20.872  3042  3042 W System.err: 	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:756)
08-16 04:29:20.872  3042  3058 E MediaCodec: getBufferAndFormat - not executing
08-16 04:29:20.872  3042  3058 E MediaCodec: getBufferAndFormat - not executing
08-16 04:29:20.872  3042  3058 E MediaCodec: getBufferAndFormat - not executing
08-16 04:29:23.785  1351  1378 W audio_hw_generic: Not supplying enough data to HAL, expected position 949473 , only wrote 475200
08-16 04:32:17.454  1629  1642 I GnssLocationProvider: WakeLock acquired by handleInjectNtpTime()
08-16 04:32:17.751  1629  3489 D SntpClient: round trip: 72ms, clock offset: 528ms
08-16 04:32:17.751  1629  3489 I GnssLocationProvider: WakeLock acquired by sendMessage(10, 0, null)
08-16 04:32:17.751  1629  3489 I GnssLocationProvider: WakeLock released by handleInjectNtpTime()
08-16 04:32:17.751  1629  1642 I GnssLocationProvider: WakeLock released by handleMessage(10, 0, null)
08-16 04:34:20.727  2792  2807 I Gecko   : 
08-16 04:34:20.727  2792  2807 I Gecko   : {"action":"test_status","time":1565926460727,"thread":null,"pid":null,"source":"reftest","test":"http://10.0.2.2:8854/tests/dom/media/test/crashtests/1257700.html","subtest":"load failed: timed out after 300000 ms waiting for 'load' event for http://10.0.2.2:8854/tests/dom/media/test/crashtests/1257700.html","status":"FAIL","expected":"PASS"}
08-16 04:34:20.728  2792  2807 I Gecko   : 

:jhlin -- It looks like you are familiar with LollipopAsyncCodec.java; could you have a look at this?

Comment 2

[Geoff Brown [:gbrown]]

This is still failing intermittently, about once a day (failures in bug 1542346).

Comment 3

[Geoff Brown [:gbrown]]

Attachment: Bug 1575666 - skip crashtest 1257700.html on Android; r=

This test fails intermittently on geckoview; when it fails, many later-running
tests fail also, causing some confusion in bug classification.

Comment 4

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/c00a69d25890
skip crashtest 1257700.html on Android; r=geckoview-reviewers,snorp

Comment 5

[Noemi Erli[:noemi_erli]]

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