Closed Bug 1102402 Opened 5 years ago Closed 5 years ago

Android mochitest-gl-1 triggers to many retried jobs (/tests/dom/canvas/test/webgl-conformance/_wrappers)

Categories

(Testing :: General, defect)

x86_64
Linux
defect
Not set

Tracking

(Not tracked)

RESOLVED FIXED
mozilla36

People

(Reporter: armenzg, Assigned: armenzg)

Details

Attachments

(1 file)

e.g. https://tbpl.mozilla.org/?tree=Mozilla-Inbound&jobname=-gl&revision=f64269859030
http://ftp.mozilla.org/pub/mozilla.org/mobile/try-builds/armenzg@mozilla.com-cec4080ae299/try-android/try_ubuntu64_vm_mobile_test-mochitest-gl-1-bm67-tests1-linux64-build20.txt.gz
http://ftp.mozilla.org/pub/mozilla.org/mobile/try-builds/armenzg@mozilla.com-cec4080ae299/try-android/try_ubuntu64_vm_mobile_test-mochitest-gl-1-bm114-tests1-linux64-build128.txt.gz
http://ftp.mozilla.org/pub/mozilla.org/mobile/try-builds/armenzg@mozilla.com-cec4080ae299/try-android/try_ubuntu64_vm_mobile_test-mochitest-gl-1-bm117-tests1-linux64-build28.txt.gz
https://tbpl.mozilla.org/php/getParsedLog.php?id=53073364&tree=Mozilla-Inbound&full=1
https://tbpl.mozilla.org/php/getParsedLog.php?id=53074954&tree=Mozilla-Inbound&full=1
https://tbpl.mozilla.org/php/getParsedLog.php?id=53076418&tree=Mozilla-Inbound&full=1
https://tbpl.mozilla.org/php/getParsedLog.php?id=53077593&tree=Mozilla-Inbound&full=1

The issues seem to steam from the same set of tests:
/tests/dom/canvas/test/webgl-conformance/_wrappers/*

I see jgilbert and jdashg touching that area recently.

08:55:48     INFO -  INFO | automation.py | Application pid: 587
08:55:48     INFO -  Running tests 1-164/327
08:55:48     INFO -  0 INFO SimpleTest START
08:55:48     INFO -  1 INFO TEST-START | /tests/dom/canvas/test/webgl-conformance/_wrappers/test_always-fail.html
08:55:48     INFO -  2 INFO TEST-OK | /tests/dom/canvas/test/webgl-conformance/_wrappers/test_always-fail.html | took 11174ms
08:55:48     INFO -  3 INFO TEST-START | /tests/dom/canvas/test/webgl-conformance/_wrappers/test_conformance__attribs__gl-enable-vertex-attrib.html
08:55:48     INFO -  4 INFO TEST-OK | /tests/dom/canvas/test/webgl-conformance/_wrappers/test_conformance__attribs__gl-enable-vertex-attrib.html | took 13752ms
08:55:48     INFO -  5 INFO TEST-START | /tests/dom/canvas/test/webgl-conformance/_wrappers/test_conformance__attribs__gl-vertex-attrib-zero-issues.html
08:55:48     INFO -  6 INFO TEST-OK | /tests/dom/canvas/test/webgl-conformance/_wrappers/test_conformance__attribs__gl-vertex-attrib-zero-issues.html | took 9439ms
08:55:48     INFO -  7 INFO TEST-START | /tests/dom/canvas/test/webgl-conformance/_wrappers/test_conformance__attribs__gl-vertex-attrib.html
08:55:48     INFO -  8 INFO TEST-OK | /tests/dom/canvas/test/webgl-conformance/_wrappers/test_conformance__attribs__gl-vertex-attrib.html | took 16436ms
08:55:48     INFO -  9 INFO TEST-START | /tests/dom/canvas/test/webgl-conformance/_wrappers/test_conformance__attribs__gl-vertexattribpointer-offsets.html
08:55:48     INFO -  10 INFO TEST-OK | /tests/dom/canvas/test/webgl-conformance/_wrappers/test_conformance__attribs__gl-vertexattribpointer-offsets.html | took 17780ms
08:55:48     INFO -  11 INFO TEST-START | /tests/dom/canvas/test/webgl-conformance/_wrappers/test_conformance__attribs__gl-vertexattribpointer.html
08:55:48     INFO -  12 INFO TEST-OK | /tests/dom/canvas/test/webgl-conformance/_wrappers/test_conformance__attribs__gl-vertexattribpointer.html | took 37012ms
08:55:48     INFO -  13 INFO TEST-START | /tests/dom/canvas/test/webgl-conformance/_wrappers/test_conformance__buffers__buffer-bind-test.html
08:55:48     INFO -  14 INFO TEST-OK | /tests/dom/canvas/test/webgl-conformance/_wrappers/test_conformance__buffers__buffer-bind-test.html | took 8126ms
08:55:48     INFO -  15 INFO TEST-START | /tests/dom/canvas/test/webgl-conformance/_wrappers/test_conformance__buffers__buffer-data-array-buffer.html
08:55:48     INFO -  16 INFO TEST-OK | /tests/dom/canvas/test/webgl-conformance/_wrappers/test_conformance__buffers__buffer-data-array-buffer.html | took 8665ms
08:55:48     INFO -  17 INFO TEST-START | /tests/dom/canvas/test/webgl-conformance/_wrappers/test_conformance__buffers__index-validation-copies-indices.html
08:55:48     INFO -  18 INFO TEST-OK | /tests/dom/canvas/test/webgl-conformance/_wrappers/test_conformance__buffers__index-validation-copies-indices.html | took 9614ms
08:55:48     INFO -  19 INFO TEST-START | /tests/dom/canvas/test/webgl-conformance/_wrappers/test_conformance__buffers__index-validation-crash-with-buffer-sub-data.html
08:55:48     INFO -  20 INFO TEST-OK | /tests/dom/canvas/test/webgl-conformance/_wrappers/test_conformance__buffers__index-validation-crash-with-buffer-sub-data.html | took 7886ms
08:55:48     INFO -  21 INFO TEST-START | /tests/dom/canvas/test/webgl-conformance/_wrappers/test_conformance__buffers__index-validation-verifies-too-many-indices.html
08:55:48     INFO -  22 INFO TEST-OK | /tests/dom/canvas/test/webgl-conformance/_wrappers/test_conformance__buffers__index-validation-verifies-too-many-indices.html | took 8788ms
08:55:48     INFO -  23 INFO TEST-START | /tests/dom/canvas/test/webgl-conformance/_wrappers/test_conformance__buffers__index-validation-with-resized-buffer.html
08:55:48     INFO -  Traceback (most recent call last):
08:55:48     INFO -    File "/builds/slave/test/build/tests/mochitest/runtests.py", line 1875, in doTests
08:55:48     INFO -      quiet=options.quiet
08:55:48     INFO -    File "/builds/slave/test/build/tests/mochitest/runtestsremote.py", line 594, in runApp
08:55:48     INFO -      return self._automation.runApp(*args, **kwargs)
08:55:48     INFO -    File "/builds/slave/test/build/tests/mochitest/automation.py", line 855, in runApp
08:55:48     INFO -      status = self.waitForFinish(proc, utilityPath, timeout, maxTime, startTime, debuggerInfo, symbolsPath)
08:55:48     INFO -    File "/builds/slave/test/build/tests/mochitest/remoteautomation.py", line 92, in waitForFinish
08:55:48     INFO -      status = proc.wait(timeout = maxTime, noOutputTimeout = timeout)
08:55:48     INFO -    File "/builds/slave/test/build/tests/mochitest/remoteautomation.py", line 351, in wait
08:55:48     INFO -      while (self.dm.getTopActivity() == self.procName):
08:55:48     INFO -    File "/builds/slave/test/build/tests/mochitest/droid.py", line 217, in getTopActivity
08:55:48     INFO -      return self._runCmds([{ 'cmd': "activity" }]).strip()
08:55:48     INFO -    File "/builds/slave/test/build/tests/mochitest/devicemanagerSUT.py", line 151, in _runCmds
08:55:48     INFO -      self._sendCmds(cmdlist, outputfile, timeout, retryLimit=retryLimit)
08:55:48     INFO -    File "/builds/slave/test/build/tests/mochitest/devicemanagerSUT.py", line 142, in _sendCmds
08:55:48     INFO -      raise DMError("Remote Device Error: unable to connect to %s after %s attempts" % (self.host, retryLimit))
08:55:48     INFO -  DMError: Remote Device Error: unable to connect to 127.0.0.1 after 5 attempts
08:55:48     INFO -  24 ERROR Automation Error: Received unexpected exception while running application
I pushed a backout of http://hg.mozilla.org/mozilla-central/rev/9652f8a8c37b
to Try to determine if the high retry numbers comes from it:
https://treeherder.mozilla.org/ui/#/jobs?repo=try&revision=cae5d265baff
I suspect the test logs may be inaccurate, in terms of identifying the last test. The logcats seem more consistent, with the final messages coming from /tests/dom/canvas/test/webgl-conformance/_wrappers/test_conformance__canvas__buffer-offscreen-test.html.
Nvm my first try push it won't even build.

gbrown thanks for pointing it out!
How do you determine that?
Is it because it is the last mentioned test?

I have pushed a new try push disabling that test for Android:
https://tbpl.mozilla.org/?tree=Try&rev=8614a4eb9b7d

I also want to point out one of the last warnings/errors:
11-20 09:16:19.029 W/GeckoConsole(  587): [JavaScript Warning: "Error: WebGL: Exceeded 4 live WebGL contexts, losing the least recently used one." {file: "http://mochi.test:8888/tests/dom/canvas/test/webgl-conformance/conformance/resources/webgl-test.js" line: 49}]

Since you point it out I can find the emulator log:
http://mozilla-releng-blobs.s3.amazonaws.com/blobs/mozilla-inbound/sha512/393a891240b0f0d8f1fe961bad1fb7eb5b304994669fa5e52f20f43dbcab1669ed9184a1fb20c4423405bddd85cf040c4c5a7fd9810e7521df3406da946cc7c0

and I look at the end:
11-20 09:16:10.760 I/GeckoDump(  587): ⰲ겿{"action":"test_status","time":1416503770764,"thread":"","js_source":"TestRunner","pid":null,"source":"mochitest","test":"/tests/dom/canvas/test/webgl-conformance/_wrappers/test_conformance__buffers__index-validation.html","subtest":"gl.drawElements(gl.TRIANGLES, 3, gl.UNSIGNED_SHORT, 0) is undefined.","status":"PASS"}ⰲ겿
11-20 09:16:10.770 W/GeckoConsole(  587): [JavaScript Warning: "Error: WebGL: vertexAttribPointer: negative offset" {file: "http://mochi.test:8888/tests/dom/canvas/test/webgl-conformance/conformance/buffers/index-validation.html" line: 132}]
11-20 09:16:10.780 I/GeckoDump(  587): ⰲ겿{"action":"test_status","time":1416503770780,"thread":"","js_source":"TestRunner","pid":null,"source":"mochitest","test":"/tests/dom/canvas/test/webgl-conformance/_wrappers/test_conformance__buffers__index-validation.html","subtest":"getError was expected value: INVALID_VALUE : ","status":"PASS"}ⰲ겿
11-20 09:16:10.790 I/GeckoDump(  587): ⰲ겿{"action":"test_status","time":1416503770792,"thread":"","js_source":"TestRunner","pid":null,"source":"mochitest","test":"/tests/dom/canvas/test/webgl-conformance/_wrappers/test_conformance__buffers__index-validation.html","subtest":"gl.drawElements(gl.TRIANGLES, 3, gl.UNSIGNED_SHORT, 0) is undefined.","status":"PASS"}ⰲ겿
11-20 09:16:11.019 I/GeckoDump(  587): ⰲ겿{"action":"test_status","time":1416503771020,"thread":"","js_source":"TestRunner","pid":null,"source":"mochitest","test":"/tests/dom/canvas/test/webgl-conformance/_wrappers/test_conformance__buffers__index-validation.html","subtest":"Expected no failures: conformance/buffers/index-validation.html","status":"PASS"}ⰲ겿
11-20 09:16:11.069 I/GeckoDump(  587): ⰲ겿{"action":"log","time":1416503771071,"thread":"","js_source":"TestRunner","pid":null,"source":"mochitest","level":"INFO","message":"MEMORY STAT vsize after test: 509714432"}ⰲ겿
11-20 09:16:11.079 I/GeckoDump(  587): ⰲ겿{"action":"log","time":1416503771082,"thread":"","js_source":"TestRunner","pid":null,"source":"mochitest","level":"INFO","message":"MEMORY STAT residentFast after test: 151810048"}ⰲ겿
11-20 09:16:11.089 I/GeckoDump(  587): ⰲ겿{"action":"log","time":1416503771089,"thread":"","js_source":"TestRunner","pid":null,"source":"mochitest","level":"INFO","message":"MEMORY STAT heapAllocated after test: 23425368"}ⰲ겿
11-20 09:16:12.109 I/GeckoDump(  587): ⰲ겿{"action":"test_end","time":1416503772102,"thread":"","js_source":"TestRunner","pid":null,"source":"mochitest","test":"/tests/dom/canvas/test/webgl-conformance/_wrappers/test_conformance__buffers__index-validation.html","status":"OK","message":"Finished in 9894ms","extra":{"runtime":9894}}ⰲ겿
11-20 09:16:12.889 W/GeckoConsole(  587): [JavaScript Warning: "The character encoding of a framed document was not declared. The document may appear different if viewed without the document framing it." {file: "http://mochi.test:8888/tests/SimpleTest/iframe-between-tests.html" line: 0}]
11-20 09:16:13.237 I/GeckoDump(  587): ⰲ겿{"action":"test_start","time":1416503773225,"thread":"","js_source":"TestRunner","pid":null,"source":"mochitest","test":"/tests/dom/canvas/test/webgl-conformance/_wrappers/test_conformance__canvas__buffer-offscreen-test.html"}ⰲ겿
11-20 09:16:16.499 I/Gecko   (  587): WebGL(0x5a260c00)::ForceLoseContext
11-20 09:16:16.519 I/Gecko   (  587): WebGL(0x5b393c00)::ForceLoseContext
11-20 09:16:16.999 I/GeckoConsole(  587): Info: GL vendor: Google (VMware, Inc.)
11-20 09:16:17.010 I/GeckoConsole(  587): Info: GL renderer: Android Emulator OpenGL ES Translator (Gallium 0.4 on llvmpipe (LLVM 0x300))
11-20 09:16:17.029 I/GeckoConsole(  587): Info: OS detected as: android
11-20 09:16:17.039 I/GeckoConsole(  587): Info:   Version: 10
11-20 09:16:17.049 I/GeckoConsole(  587): Info: GL driver detected as: mesa
11-20 09:16:17.049 I/GeckoConsole(  587): testPath: conformance/canvas/buffer-offscreen-test.html
11-20 09:16:19.029 W/GeckoConsole(  587): [JavaScript Warning: "Error: WebGL: Exceeded 4 live WebGL contexts, losing the least recently used one." {file: "http://mochi.test:8888/tests/dom/canvas/test/webgl-conformance/conformance/resources/webgl-test.js" line: 49}]
11-20 09:16:19.029 I/Gecko   (  587): WebGL(0x5acb6000)::ForceLoseContext
11-20 09:16:19.099 I/GeckoDump(  587): ⰲ겿{"action":"test_status","time":1416503779092,"thread":"","js_source":"TestRunner","pid":null,"source":"mochitest","test":"/tests/dom/canvas/test/webgl-conformance/_wrappers/test_conformance__canvas__buffer-offscreen-test.html","subtest":"gl1 != null is true","status":"PASS"}ⰲ겿
11-20 09:16:19.119 I/GeckoDump(  587): ⰲ겿{"action":"test_status","time":1416503779122,"thread":"","js_source":"TestRunner","pid":null,"source":"mochitest","test":"/tests/dom/canvas/test/webgl-conformance/_wrappers/test_conformance__canvas__buffer-offscreen-test.html","subtest":"gl2 != null is true","status":"PASS"}ⰲ겿
11-20 09:16:19.149 I/GeckoDump(  587): ⰲ겿{"action":"test_status","time":1416503779145,"thread":"","js_source":"TestRunner","pid":null,"source":"mochitest","test":"/tests/dom/canvas/test/webgl-conformance/_wrappers/test_conformance__canvas__buffer-offscreen-test.html","subtest":"gl1.getContextAttributes().preserveDrawingBuffer == false is true","status":"PASS"}ⰲ겿
11-20 09:16:19.169 I/GeckoDump(  587): ⰲ겿{"action":"test_status","time":1416503779167,"thread":"","js_source":"TestRunner","pid":null,"source":"mochitest","test":"/tests/dom/canvas/test/webgl-conformance/_wrappers/test_conformance__canvas__buffer-offscreen-test.html","subtest":"gl2.getContextAttributes().preserveDrawingBuffer == false is true","status":"PASS"}ⰲ겿
11-20 09:16:19.812 W/GeckoEventDispatcher(  587): No listeners for robocop:scroll
(In reply to Armen Zambrano - Automation & Tools Engineer (:armenzg) from comment #5)
> gbrown thanks for pointing it out!
> How do you determine that?
> Is it because it is the last mentioned test?

Yes. I opened a few of the logs, found the associated aws logcats, opened the logcats, scrolled to the end.
It causes intermittent issues which causes us to retrigger the job again and again.

Can we please disable until someone can make time to fix it?
Attachment #8526966 - Flags: review?(jgilbert)
Comment on attachment 8526966 [details] [diff] [review]
Disable test_conformance__canvas__buffer-offscreen-test.html until fix is found

Review of attachment 8526966 [details] [diff] [review]:
-----------------------------------------------------------------

::: dom/canvas/test/_webgl-conformance.ini
@@ +498,5 @@
>  [webgl-conformance/_wrappers/test_conformance__buffers__index-validation-verifies-too-many-indices.html]
>  [webgl-conformance/_wrappers/test_conformance__buffers__index-validation-with-resized-buffer.html]
>  [webgl-conformance/_wrappers/test_conformance__buffers__index-validation.html]
>  [webgl-conformance/_wrappers/test_conformance__canvas__buffer-offscreen-test.html]
> +skip-if = os == 'android'

Leave a comment about why it's disabled.
Attachment #8526966 - Flags: review?(jgilbert) → review+
I've landed the patch adding the comment.

Should we file a bug to investigate the issue and hopefully re-enable it?
Or move this one to the right component?
Assignee: nobody → armenzg
Flags: needinfo?(jgilbert)
(In reply to Armen Zambrano - Automation & Tools Engineer (:armenzg) from comment #10)
> I've landed the patch adding the comment.
> 
> Should we file a bug to investigate the issue and hopefully re-enable it?
> Or move this one to the right component?

Please file a bug that references this one in the Core/WebGL component.
Flags: needinfo?(jgilbert)
https://hg.mozilla.org/mozilla-central/rev/8bb9c85397f2
Status: NEW → RESOLVED
Closed: 5 years ago
Flags: in-testsuite-
Resolution: --- → FIXED
Target Milestone: --- → mozilla36
You need to log in before you can comment on or make changes to this bug.