Closed Bug 919569 Opened 12 years ago Closed 12 years ago

Extremely frequent test_click.py TestClick.testClickingALinkMadeUpOfNumbersIsHandledCorrectly | InvalidResponseException after process crash followed by many more

Categories

(Firefox OS Graveyard :: General, defect)

Product:
Firefox OS Graveyard
Component:
General
Platform:
ARM
Gonk (Firefox OS)
Type:
defect
Priority:
Not set
Severity:
blocker

Tracking

(Not tracked)

Status:
RESOLVED DUPLICATE of bug 926715

People

(Reporter: RyanVM, Unassigned)

References

Details

(Keywords: intermittent-failure)

https://tbpl.mozilla.org/php/getParsedLog.php?id=28230362&tree=Mozilla-Central b2g_emulator mozilla-central opt test marionette-webapi on 2013-09-23 07:56:15 PDT for push 4df586670d2a slave: talos-r3-fed-058 08:00:49 INFO - TEST-START test_click.py 08:00:59 INFO - testClickingALinkMadeUpOfNumbersIsHandledCorrectly (test_click.TestClick) ... ERROR 08:00:59 INFO - ERROR 08:01:00 INFO - test_click (test_click.TestClick) ... ERROR 08:01:00 INFO - START LOG: 08:01:00 INFO - Error getting log: [Errno 32] Broken pipe 08:01:00 INFO - END LOG: 08:01:00 INFO - ====================================================================== 08:01:00 INFO - ERROR: testClickingALinkMadeUpOfNumbersIsHandledCorrectly (test_click.TestClick) 08:01:00 INFO - ---------------------------------------------------------------------- 08:01:00 INFO - Traceback (most recent call last): 08:01:00 INFO - File "/home/cltbld/talos-slave/test/build/tests/marionette/marionette/marionette_test.py", line 132, in run 08:01:00 INFO - testMethod() 08:01:00 INFO - File "/home/cltbld/talos-slave/test/build/tests/marionette/tests/testing/marionette/client/marionette/tests/unit/test_click.py", line 20, in testClickingALinkMadeUpOfNumbersIsHandledCorrectly 08:01:00 INFO - self.marionette.navigate(test_html) 08:01:00 INFO - File "/home/cltbld/talos-slave/test/build/tests/marionette/marionette/marionette.py", line 861, in navigate 08:01:00 INFO - response = self._send_message('goUrl', 'ok', value=url) 08:01:00 INFO - File "/home/cltbld/talos-slave/test/build/tests/marionette/marionette/marionette.py", line 557, in _send_message 08:01:00 INFO - response = self.client.send(message) 08:01:00 INFO - File "/home/cltbld/talos-slave/test/build/tests/marionette/marionette/client.py", line 95, in send 08:01:00 INFO - response = self.receive() 08:01:00 INFO - File "/home/cltbld/talos-slave/test/build/tests/marionette/marionette/client.py", line 58, in receive 08:01:00 INFO - status=ErrorCodes.INVALID_RESPONSE) 08:01:00 ERROR - TEST-UNEXPECTED-FAIL | test_click.py TestClick.testClickingALinkMadeUpOfNumbersIsHandledCorrectly | InvalidResponseException: Could not successfully complete transport of message to Gecko, socket closed? From the logcat dump: 08:04:44 INFO - 09-23 15:00:50.801 45 45 I Gecko : MARIONETTE LOG: INFO: TEST-START: /home/cltbld/talos-slave/test/build/tests/marionette/tests/testing/marionette/client/marionette/tests/unit/test_click.py:testClickingALinkMadeUpOfNumbersIsHandledCorrectly 08:04:44 INFO - 09-23 15:00:50.831 45 45 I Gecko : 1379948450832 Marionette INFO sendToClient: {"from":"0","value":null}, {d9cc0d84-c932-4adf-bcca-0f22aca95eaf}, {d9cc0d84-c932-4adf-bcca-0f22aca95eaf} 08:04:44 INFO - 09-23 15:00:51.162 45 45 I Gecko : 1379948451135 Marionette TRACE Got: {"to": "0", "session": "6-b2g", "type": "goUrl", "value": "http://10.12.50.223:49903/clicks.html"} 08:04:44 INFO - 09-23 15:00:53.811 159 159 I Gecko : MobileConnection initialized 08:04:44 INFO - 09-23 15:00:53.871 209 209 D : HostConnection::get() New Host Connection established 0x444218b0, tid 209 08:04:44 INFO - 09-23 15:00:54.412 209 209 E GeckoConsole: Content JS ERROR at app://homescreen.gaiamobile.org/gaia_build_defer_index.js:361 in loadSVConfFileError: Failed parsing singleVariant configuration file [js/singlevariantconf.json]: [Exception... "File error: Not found" nsresult: "0x80520012 (NS_ERROR_FILE_NOT_FOUND)" location: "JS frame :: app://homescreen.gaiamobile.org/gaia_build_defer_index.js :: loadFile :: line 354" data: no] 08:04:44 WARNING - 09-23 15:00:59.342 45 45 E GeckoConsole: [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.12.50.223:49903/clicks.html" line: 0}] 08:04:44 ERROR - 09-23 15:00:59.432 45 45 F libc : Fatal signal 11 (SIGSEGV) at 0x0000002d (code=-6) 08:04:44 ERROR - This usually indicates the B2G process has crashed 08:04:45 INFO - 09-23 15:00:59.821 159 159 I Gecko : 08:04:45 INFO - 09-23 15:00:59.821 159 159 I Gecko : ###!!! [Child][SyncChannel] Error: Channel error: cannot send/recv 08:04:45 INFO - 09-23 15:00:59.821 159 159 I Gecko : 08:04:45 INFO - 09-23 15:00:59.871 33 33 I ServiceManager: service 'media.resource_manager' died 08:04:45 INFO - 09-23 15:00:59.941 37 37 I DEBUG : debuggerd committing suicide to free the zombie! 08:04:45 INFO - 09-23 15:00:59.961 33 33 I ServiceManager: service 'media.audio_policy' died 08:04:45 INFO - 09-23 15:00:59.961 33 33 I ServiceManager: service 'media.audio_flinger' died 08:04:45 INFO - 09-23 15:00:59.961 33 33 I ServiceManager: service 'media.player' died 08:04:45 INFO - 09-23 15:00:59.961 33 33 I ServiceManager: service 'media.camera' died 08:04:45 INFO - 09-23 15:00:59.992 276 276 I DEBUG : debuggerd: Sep 23 2013 08:04:34 08:04:45 INFO - 09-23 15:01:01.062 275 275 I : ServiceManager: 0xf958 What we've been able to figure out so far: * This happens on all m-c branches. Attempts to reproduce on Aurora have not been successful. * The earliest I've been able to reproduce this on m-c is with today's inbound -> m-c merge. ** https://tbpl.mozilla.org/?rev=4df586670d2a * This is also happening on b2g-inbound, which hasn't seen a merge from m-c since yesterday. * I have *NOT* been able to reproduce this on the last common cset between the two branches. * Green runs can be retriggered red, and red runs can be retriggered green. At this point, I am at a loss as to what's going on. This needs attention ASAP as it is causing near perma-fail in the Mnw suite. Otherwise, I will need to hide the suite.
Also, I believe that this line is a red herring as I see it in some of the green runs as well. 08:04:44 INFO - 09-23 15:00:54.412 209 209 E GeckoConsole: Content JS ERROR at app://homescreen.gaiamobile.org/gaia_build_defer_index.js:361 in loadSVConfFileError: Failed parsing singleVariant configuration file [js/singlevariantconf.json]: [Exception... "File error: Not found" nsresult: "0x80520012 (NS_ERROR_FILE_NOT_FOUND)" location: "JS frame :: app://homescreen.gaiamobile.org/gaia_build_defer_index.js :: loadFile :: line 354" data: no]
(In reply to Ryan VanderMeulen [:RyanVM UTC-4] from comment #1) > Also, I believe that this line is a red herring as I see it in some of the > green runs as well. > > 08:04:44 INFO - 09-23 15:00:54.412 209 209 E GeckoConsole: Content > JS ERROR at app://homescreen.gaiamobile.org/gaia_build_defer_index.js:361 in > loadSVConfFileError: Failed parsing singleVariant configuration file > [js/singlevariantconf.json]: [Exception... "File error: Not found" > nsresult: "0x80520012 (NS_ERROR_FILE_NOT_FOUND)" location: "JS frame :: > app://homescreen.gaiamobile.org/gaia_build_defer_index.js :: loadFile :: > line 354" data: no] That's correct. We should silent it if that helps you though.
(In reply to Fabrice Desré [:fabrice] from comment #2) > That's correct. We should silent it if that helps you though. In general, I'm opposed to spurious warnings showing up in logs :)
The instance from Friday on inbound certainly seems to support this going back further. Just odd that it's nearly perma-fail now, but basically didn't occur at all over the weekend.
Depends on: 919579
Ryan, Andrew has offered to help track down people that can work on oranges that we're hitting for B2G. Please cc/needinfo him on bugs like this rather than me.
Andrew, here's a frequent intermittent failure that needs some developer attention.
Flags: needinfo?(overholt)
For the benefit of those playing along at home, I'm still working on this. mdas helped a bit via IRC and I'm continuing investigation.
Flags: needinfo?(overholt)
I ran the marionette unit test (test_click.py) 25x on my local Ubuntu VM, but couldn't reproduce the issue; it passed each time. I also ran the test that runs immediately before it (test_import_script.py) followed by test_click.py several times, all passed fine.
(In reply to Rob Wood [:rwood] from comment #66) > I ran the marionette unit test (test_click.py) 25x on my local Ubuntu VM, > but couldn't reproduce the issue; it passed each time. I also ran the test > that runs immediately before it (test_import_script.py) followed by > test_click.py several times, all passed fine. Thanks, Rob. I guess that means this depends more on the machine than we'd like. There haven't been any TBPL Robot reports here since October 6th. Did we turn off the tests or did this magically fix itself?
Flags: needinfo?(ryanvm)
Looks that way. Guess the Mnw failures have moved on to new bugs.
Flags: needinfo?(ryanvm)
Isn't this a dupe of bug 926715?
> > There haven't been any TBPL Robot reports here since October 6th. Did we > turn off the tests or did this magically fix itself? Neither; there were just two bugs opened for this failure, and most of the failures are being reported against the other. The bug is still quite frequent.
Status: NEW → RESOLVED
Closed: 12 years ago
Resolution: --- → DUPLICATE
You need to log in before you can comment on or make changes to this bug.