Closed Bug 906716 Opened 6 years ago Closed 3 years ago

Intermittent B2G emulator "timed out after 1000 seconds of no output"

Categories

(Testing :: General, defect)

ARM
Gonk (Firefox OS)
defect
Not set

Tracking

(Not tracked)

RESOLVED WONTFIX

People

(Reporter: emorley, Unassigned)

References

Details

(Keywords: intermittent-failure)

Attachments

(1 file)

b2g_emulator b2g-inbound opt test reftest-3 on 2013-08-19 03:08:01 PDT for push 414c4b2e0837

slave: talos-r3-fed-064

https://tbpl.mozilla.org/php/getParsedLog.php?id=26713255&tree=B2g-Inbound

{
03:09:10     INFO - #####
03:09:10     INFO - ##### Running run-tests step.
03:09:10     INFO - #####
03:09:10     INFO - Running pre-action listener: _resource_record_pre_action
03:09:10     INFO - Running main action method: run_tests
03:09:10     INFO - Getting output from command: ['/home/cltbld/talos-slave/test/build/venv/bin/python', '-c', 'from distutils.sysconfig import get_python_lib; print(get_python_lib())']
03:09:10     INFO - Copy/paste: /home/cltbld/talos-slave/test/build/venv/bin/python -c "from distutils.sysconfig import get_python_lib; print(get_python_lib())"
03:09:10     INFO - Reading from file tmpfile_stdout
03:09:10     INFO - Output received:
03:09:10     INFO -  /home/cltbld/talos-slave/test/build/venv/lib/python2.6/site-packages
03:09:10     INFO - retry: Calling <built-in function remove> with args: ('tmpfile_stderr',), kwargs: {}, attempt #1
03:09:10     INFO - retry: Calling <built-in function remove> with args: ('tmpfile_stdout',), kwargs: {}, attempt #1
03:09:10     INFO - Running command: ['/home/cltbld/talos-slave/test/build/venv/bin/python', 'runreftestb2g.py', '--adbpath=/home/cltbld/talos-slave/test/build/emulator/b2g-distro/out/host/linux-x86/bin/adb', '--b2gpath=/home/cltbld/talos-slave/test/build/emulator/b2g-distro', '--emulator=arm', '--emulator-res=800x1000', '--logcat-dir=/home/cltbld/talos-slave/test/build', '--remote-webserver=10.0.2.2', '--ignore-window-size', '--xre-path=/home/cltbld/talos-slave/test/build/xre/bin', '--symbols-path=http://pvtbuilds.pvt.build.mozilla.org//pub/mozilla.org/b2g/tinderbox-builds/b2g-inbound-generic/20130819011116/emulator.crashreporter-symbols.zip', '--busybox=/home/cltbld/talos-slave/test/build/busybox', '--total-chunks=10', '--this-chunk=3', 'tests/layout/reftests/reftest.list'] in /home/cltbld/talos-slave/test/build/tests/reftest
03:09:10     INFO - Copy/paste: /home/cltbld/talos-slave/test/build/venv/bin/python runreftestb2g.py --adbpath=/home/cltbld/talos-slave/test/build/emulator/b2g-distro/out/host/linux-x86/bin/adb --b2gpath=/home/cltbld/talos-slave/test/build/emulator/b2g-distro --emulator=arm --emulator-res=800x1000 --logcat-dir=/home/cltbld/talos-slave/test/build --remote-webserver=10.0.2.2 --ignore-window-size --xre-path=/home/cltbld/talos-slave/test/build/xre/bin --symbols-path=http://pvtbuilds.pvt.build.mozilla.org//pub/mozilla.org/b2g/tinderbox-builds/b2g-inbound-generic/20130819011116/emulator.crashreporter-symbols.zip --busybox=/home/cltbld/talos-slave/test/build/busybox --total-chunks=10 --this-chunk=3 tests/layout/reftests/reftest.list
03:09:10     INFO - Using env: {'CVS_RSH': 'ssh',
03:09:10     INFO -  'DISPLAY': ':0',
03:09:10     INFO -  'G_BROKEN_FILENAMES': '1',
03:09:10     INFO -  'HISTCONTROL': 'ignoreboth',
03:09:10     INFO -  'HISTSIZE': '1000',
03:09:10     INFO -  'HOME': '/home/cltbld',
03:09:10     INFO -  'HOSTNAME': 'talos-r3-fed-064.build.mozilla.org',
03:09:10     INFO -  'LANG': 'en_US.UTF-8',
03:09:10     INFO -  'LESSOPEN': '|/usr/bin/lesspipe.sh %s',
03:09:10     INFO -  'LOGNAME': 'cltbld',
03:09:10     INFO -  'MAIL': '/var/spool/mail/cltbld',
03:09:10     INFO -  'MINIDUMP_STACKWALK': '/home/cltbld/talos-slave/test/build/tools/breakpad/linux/minidump_stackwalk',
03:09:10     INFO -  'PATH': '/home/cltbld/bin:/tools/buildbot-0.8.0/bin:/usr/kerberos/sbin:/usr/kerberos/bin:/usr/local/bin:/bin:/usr/bin:/usr/local/sbin:/usr/sbin:/sbin',
03:09:10     INFO -  'PROPERTIES_FILE': '/home/cltbld/talos-slave/test/buildprops.json',
03:09:10     INFO -  'PWD': '/home/cltbld/talos-slave/test',
03:09:10     INFO -  'SHELL': '/bin/bash',
03:09:10     INFO -  'SHLVL': '1',
03:09:10     INFO -  'SSH_ASKPASS': '/usr/libexec/openssh/gnome-ssh-askpass',
03:09:10     INFO -  'TERM': 'xterm',
03:09:10     INFO -  'USER': 'cltbld',
03:09:10     INFO -  '_': '/home/cltbld/bin/python'}
03:25:50    ERROR - timed out after 1000 seconds of no output
03:25:50    ERROR - Return code: 9
}

logcat:
{
...
03:25:51     INFO -  08-19 10:09:33.910    45    45 I Gecko   : 1376906973914	Marionette	INFO	marionette-server.js loaded
03:25:51     INFO -  08-19 10:09:35.341    45    45 I Gecko   : 1376906975343	Marionette	INFO	B2G emulator: yes
03:25:51     INFO -  08-19 10:09:35.350    45    45 I Gecko   : 1376906975352	Marionette	INFO	Device detected is generic
03:25:51     INFO -  08-19 10:09:35.360    45    45 I Gecko   : 1376906975354	Marionette	INFO	Bypassing offline status.
03:25:51     INFO -  08-19 10:09:35.380    45    45 I Gecko   : 1376906975385	Marionette	INFO	Listening on port 2828
03:25:51     INFO -  08-19 10:09:35.380    45    45 I Gecko   :
03:25:51     INFO -  08-19 10:09:35.380    45    45 I Gecko   : 1376906975388	Marionette	INFO	Marionette server ready
03:25:51     INFO -  08-19 10:09:36.660    45    45 I Gonk    : Socket open for RIL
03:25:51     INFO -  08-19 10:09:37.171    45    45 I Gecko   : 1376906977174	Marionette	DEBUG	accepted connection on 127.0.0.1:58351
03:25:51     INFO -  08-19 10:09:40.230    45    45 I FMRadio : FMRadio is initialized.
03:25:51     INFO -  08-19 10:09:43.130    45    45 I Gecko   : Handler function DebuggerTransport.prototype.onStopRequest threw an exception: TypeError: this.curBrowser is null
03:25:51     INFO -  08-19 10:09:43.130    45    45 I Gecko   : Call stack:
03:25:51     INFO -  08-19 10:09:43.130    45    45 I Gecko   : MDA_switchToGlobalMM@chrome://marionette/content/marionette-server.js:181
03:25:51     INFO -  08-19 10:09:43.130    45    45 I Gecko   : MDA_sessionTearDown@chrome://marionette/content/marionette-server.js:1927
03:25:51     INFO -  08-19 10:09:43.130    45    45 I Gecko   : MSC_onClosed@chrome://marionette/content/marionette-server.js:166
03:25:51     INFO -  08-19 10:09:43.130    45    45 I Gecko   : DT_onStopRequest@chrome://marionette/content/marionette-server.js -> resource://gre/modules/devtools/server/transport.js:130
03:25:51     INFO -  08-19 10:09:43.130    45    45 I Gecko   : makeInfallible/<@chrome://marionette/content/marionette-server.js -> resource://gre/modules/devtools/DevToolsUtils.js:61
03:25:51     INFO -  08-19 10:09:43.130    45    45 I Gecko   :
03:25:51  WARNING -  08-19 10:09:43.130    45    45 E GeckoConsole: [JavaScript Error: "Handler function DebuggerTransport.prototype.onStopRequest threw an exception: TypeError: this.curBrowser is null
03:25:51     INFO -  08-19 10:09:43.130    45    45 E GeckoConsole: Call stack:
03:25:51     INFO -  08-19 10:09:43.130    45    45 E GeckoConsole: MDA_switchToGlobalMM@chrome://marionette/content/marionette-server.js:181
03:25:51     INFO -  08-19 10:09:43.130    45    45 E GeckoConsole: MDA_sessionTearDown@chrome://marionette/content/marionette-server.js:1927
03:25:51     INFO -  08-19 10:09:43.130    45    45 E GeckoConsole: MSC_onClosed@chrome://marionette/content/marionette-server.js:166
03:25:51     INFO -  08-19 10:09:43.130    45    45 E GeckoConsole: DT_onStopRequest@chrome://marionette/content/marionette-server.js -> resource://gre/modules/devtools/server/transport.js:130
03:25:51     INFO -  08-19 10:09:43.130    45    45 E GeckoConsole: makeInfallible/<@chrome://marionette/content/marionette-server.js -> resource://gre/modules/devtools/DevToolsUtils.js:61
03:25:51     INFO -  08-19 10:09:43.130    45    45 E GeckoConsole: " {file: "chrome://marionette/content/marionette-server.js -> resource://gre/modules/devtools/DevToolsUtils.js" line: 37}]
03:25:51     INFO -  08-19 10:09:53.530    45    45 I Gecko   : 1376906993533	Marionette	DEBUG	accepted connection on 127.0.0.1:58352
03:25:51     INFO -  08-19 10:09:54.180    45   130 I Gecko   : RIL Worker[0]: DateTimeZone string
03:25:51  WARNING -  08-19 10:10:00.390    45    45 E GeckoConsole: [JavaScript Error: "PermissionsTable.jsm: expandPermissions: Unknown Permission: network-tcp" {file: "resource://gre/modules/PermissionsTable.jsm" line: 319}]
03:25:51     INFO -  08-19 10:10:00.390    45    45 I Gecko   : PermissionsTable.jsm: expandPermissions: Unknown Permission: network-tcp
03:25:51  WARNING -  08-19 10:10:00.390    45    45 E GeckoConsole: [JavaScript Error: "PermissionsTable.jsm: expandPermissions: Unknown Permission: network-http" {file: "resource://gre/modules/PermissionsTable.jsm" line: 319}]
03:25:51     INFO -  08-19 10:10:00.390    45    45 I Gecko   : PermissionsTable.jsm: expandPermissions: Unknown Permission: network-http
03:25:51  WARNING -  08-19 10:10:00.620    45    45 E GeckoConsole: [JavaScript Error: "PermissionsInstaller.jsm: 'network-tcp' is not a valid Webapps permission name." {file: "resource://gre/modules/PermissionsInstaller.jsm" line: 124}]
03:25:51     INFO -  08-19 10:10:00.620    45    45 I Gecko   : PermissionsInstaller.jsm: 'network-tcp' is not a valid Webapps permission name.
03:25:51  WARNING -  08-19 10:10:00.850    45    45 E GeckoConsole: [JavaScript Error: "PermissionsInstaller.jsm: 'network-http' is not a valid Webapps permission name." {file: "resource://gre/modules/PermissionsInstaller.jsm" line: 124}]
03:25:51     INFO -  08-19 10:10:00.850    45    45 I Gecko   : PermissionsInstaller.jsm: 'network-http' is not a valid Webapps permission name.
03:25:51     INFO -  08-19 10:10:06.220    45    45 I Gecko   : 1376907006219	Marionette	TRACE	Got: {"to": "root", "type": "getMarionetteID"}
03:25:51     INFO -  08-19 10:10:06.470    45    45 I Gecko   : 1376907006473	Marionette	TRACE	Got: {"to": "0", "type": "newSession"}
03:25:51     INFO -  08-19 10:10:06.670    45   133 D NetUtils: failed to remove default route for tiwlan0: No such device
03:25:51     INFO -  08-19 10:10:06.740    45   131 D DHCP    : failed to turn on interface tiwlan0: No such device
03:25:51     INFO -  08-19 10:10:08.580    45    45 I Gonk    : Setting nice for pid 517 to 18
03:25:51     INFO -  08-19 10:10:08.580    45    45 I Gonk    : Changed nice for pid 517 from 0 to 18.
03:25:51     INFO -  08-19 10:10:08.740    45   121 I VolumeManager: SetSharingMode for volume sdcard to 1 canBeShared = 1
03:25:51     INFO -  08-19 10:10:08.740    45   121 E AutoMounter: Error reading file '/sys/devices/virtual/switch/usb_configuration/state': No such file or directory
03:25:51     INFO -  08-19 10:10:08.740    45   121 I AutoMounter: UpdateState: umsAvail:0 umsEnabled:0 mode:0 usbCablePluggedIn:0 tryToShare:0
03:25:51     INFO -  08-19 10:10:08.740    45   121 I AutoMounter: UpdateState: Volume sdcard is Idle and inserted
03:25:51     INFO -  08-19 10:10:08.740    45   121 I AutoMounter: UpdateState: Mounting sdcard
03:25:51     INFO -  08-19 10:10:08.740    34    69 D VoldCmdListener: volume mount sdcard
03:25:51     INFO -  08-19 10:10:08.740    34    69 I Vold    : /dev/block/vold/179:0 being considered for volume sdcard
03:25:51     INFO -  08-19 10:10:08.740    34    69 D Vold    : Volume sdcard state changing 1 (Idle-Unmounted) -> 3 (Checking)
03:25:51     INFO -  08-19 10:10:08.740    34    69 W Vold    : Skipping fs checks
03:25:51     INFO -  08-19 10:10:08.750    45   121 I VolumeManager: Volume sdcard: changing state from Idle to Checking (3 observers)
03:25:51     INFO -  08-19 10:10:08.750    34    69 E Vold    : /dev/block/vold/179:0 failed to mount via VFAT (Invalid argument)
03:25:51     INFO -  08-19 10:10:08.750    34    69 E Vold    : Volume sdcard found no suitable devices for mounting :(
03:25:51     INFO -  08-19 10:10:08.750    34    69 D Vold    : Volume sdcard state changing 3 (Checking) -> 1 (Idle-Unmounted)
03:25:51     INFO -  08-19 10:10:08.750    45   121 I VolumeManager: Volume sdcard: changing state from Checking to Idle (3 observers)
03:25:51     INFO -  08-19 10:10:08.750    34    69 W Vold    : Returning OperationFailed - no handler for errno 22
03:25:51     INFO -  08-19 10:10:08.750    45   121 E AutoMounter: Command 'volume mount sdcard' failed: 400 'volume operation failed (Invalid argument)'
03:25:51     INFO -  08-19 10:10:09.530    45    45 I GeckoDump: Crash reporter : exception: [Exception... "Component returned failure code: 0xc1f30001 (NS_ERROR_NOT_INITIALIZED) [nsICrashReporter.annotateCrashReport]"  nsresult: "0xc1f30001 (NS_ERROR_NOT_INITIALIZED)"  location: "JS frame :: chrome://browser/content/shell.js :: shell_start/< :: line 240"  data: no]
03:25:51     INFO -  08-19 10:10:10.870    45    45 I Gecko   : 1376907010864	Marionette	INFO	loaded marionette-listener.js
03:25:51     INFO -  08-19 10:10:10.880    45    45 I Gecko   : 1376907010882	Marionette	INFO	sendToClient: {"from":"0","value":"6-b2g"}, {2bec7cca-c825-4897-9ec5-c3c4a0c2544c}, {2bec7cca-c825-4897-9ec5-c3c4a0c2544c}
03:25:51     INFO -  08-19 10:10:11.000    45    45 I Gecko   : ###################################### forms.js loaded
03:25:51     INFO -  08-19 10:10:11.070    45    45 I Gecko   : ############################### browserElementPanning.js loaded
03:25:51     INFO -  08-19 10:10:11.150    45    45 I Gecko   : ######################## BrowserElementChildPreload.js loaded
03:25:51     INFO -  08-19 10:10:12.139    45    45 I Gecko   : 1376907012129	Marionette	TRACE	Got: {"to": "0", "session": "6-b2g", "type": "setContext", "value": "chrome"}
03:25:51     INFO -  08-19 10:10:14.460    45    45 I Gecko   : 1376907014456	Marionette	DEBUG	Got request: setContext, data: {"to":"0","session":"6-b2g","type":"setContext","value":"chrome"}, id: {ee7560ed-8388-4d5b-9fec-58f1f29f7a20}
03:25:51     INFO -  08-19 10:10:14.490    45    45 I Gecko   : 1376907014465	Marionette	INFO	sendToClient: {"from":"0","ok":true}, {ee7560ed-8388-4d5b-9fec-58f1f29f7a20}, {ee7560ed-8388-4d5b-9fec-58f1f29f7a20}
03:25:51     INFO -  08-19 10:10:15.660    45    45 I Gecko   : 1376907015661	Marionette	TRACE	Got: {"to": "0", "session": "6-b2g", "type": "setScriptTimeout", "value": 45000}
03:25:51     INFO -  08-19 10:10:15.790    45    45 I Gecko   : 1376907015764	Marionette	INFO	sendToClient: {"from":"0","ok":true}, {0287f5b6-73ba-48a0-8bff-855c80938109}, {0287f5b6-73ba-48a0-8bff-855c80938109}
03:25:51     INFO -  08-19 10:10:17.050    45    45 I Gecko   : MobileConnection initialized
03:25:51     INFO -  08-19 10:10:17.610    45    45 I Gecko   : ###################################### forms.js loaded
03:25:51     INFO -  08-19 10:10:17.640    45    45 I Gecko   : ############################### browserElementPanning.js loaded
03:25:51     INFO -  08-19 10:10:17.710    45    45 I Gecko   : ######################## BrowserElementChildPreload.js loaded
03:25:51     INFO -  08-19 10:10:21.110    45    45 I Gecko   : 1376907021088	Marionette	TRACE	Got: {"specialPowers": false, "scriptTimeout": null, "newSandbox": true, "args": [], "value": "\nwaitFor(\n    function() { marionetteScriptFinished(true); },\n    function() { return isSystemMessageListenerReady(); }\n);\n            ", "filename": "emulator.py", "to": "0", "session": "6-b2g", "line": 269, "type": "executeAsyncScript"}
03:25:51     INFO -  08-19 10:10:21.320    45   131 E WifiHW  : Cannot open "/system/etc/wifi/wpa_supplicant.conf": No such file or directory
03:25:51     INFO -  08-19 10:10:21.320    45   131 E WifiHW  : Wi-Fi will not be enabled
03:25:51     INFO -  08-19 10:10:21.860    45    45 I Gecko   : 1376907021855	Marionette	DEBUG	Got request: executeWithCallback, data: {"specialPowers":false,"scriptTimeout":null,"newSandbox":true,"args":[],"value":"\nwaitFor(\n    function() { marionetteScriptFinished(true); },\n    function() { return isSystemMessageListenerReady(); }\n);\n            ","filename":"emulator.py","to":"0","session":"6-b2g","line":269,"type":"executeAsyncScript"}, id: {c8f7218a-8a14-4042-83d3-ada21d540eab}
03:25:51  WARNING -  08-19 10:10:22.650    45    45 E GeckoConsole: [JavaScript Error: "callback is undefined" {file: "jar:file:///system/b2g/omni.ja!/components/RILContentHelper.js" line: 1691}]
03:25:51     INFO -  08-19 10:10:26.480    45    45 I GeckoDump: XXX FIXME : Got a mozContentEvent: system-message-listener-ready
03:25:51     INFO -  08-19 10:10:26.580    45    45 I Gecko   : 1376907026573	Marionette	INFO	sendToClient: {"from":"0","value":true}, {c8f7218a-8a14-4042-83d3-ada21d540eab}, {c8f7218a-8a14-4042-83d3-ada21d540eab}
03:25:51     INFO -  08-19 10:10:28.230    45    45 I Gecko   : 1376907028217	Marionette	TRACE	Got: {"to": "0", "session": "6-b2g", "type": "setContext", "value": "content"}
03:25:51     INFO -  08-19 10:10:28.440    45    45 I Gecko   : 1376907028433	Marionette	DEBUG	Got request: setContext, data: {"to":"0","session":"6-b2g","type":"setContext","value":"content"}, id: {40fc5676-69d3-403c-b104-a198da11d71b}
03:25:51     INFO -  08-19 10:10:28.450    45    45 I Gecko   : 1376907028441	Marionette	INFO	sendToClient: {"from":"0","ok":true}, {40fc5676-69d3-403c-b104-a198da11d71b}, {40fc5676-69d3-403c-b104-a198da11d71b}
03:25:51     INFO -  08-19 10:10:28.630    45    45 I Gecko   : 1376907028625	Marionette	TRACE	Got: {"to": "0", "session": "6-b2g", "type": "deleteSession"}
03:25:51     INFO -  08-19 10:10:28.740    45    45 I Gecko   : 1376907028737	Marionette	INFO	sendToClient: {"from":"0","ok":true}, {d049e913-ecd4-4d0e-8530-c2adccb34544}, {d049e913-ecd4-4d0e-8530-c2adccb34544}
03:25:51     INFO -  08-19 10:10:28.830    45   130 I Gecko   : RIL Worker[0]: ICC I/O Error code null EF id = 6fae command = c0(6a/82)
03:25:51     INFO -  08-19 10:10:29.170    45    45 I Gecko   : 1376907029169	Marionette	DEBUG	accepted connection on 127.0.0.1:58353
03:25:51     INFO -  08-19 10:10:29.590    45    45 I Gecko   : 1376907029583	Marionette	TRACE	Got: {"to": "root", "type": "getMarionetteID"}
03:25:51     INFO -  08-19 10:10:30.210    45    45 I Gecko   : 1376907030168	Marionette	TRACE	Got: {"to": "0", "type": "newSession"}
03:25:51     INFO -  08-19 10:10:30.290    45    45 I Gecko   : 1376907030275	Marionette	INFO	could not load listener into content for page: chrome://browser/content/shell.xul
03:25:51     INFO -  08-19 10:10:30.430    45    45 I Gecko   : 1376907030428	Marionette	INFO	sendToClient: {"from":"0","value":"6-b2g"}, {3c29dcdf-1b9f-4217-8c4a-8ef9d3d7f634}, {3c29dcdf-1b9f-4217-8c4a-8ef9d3d7f634}
03:25:51     INFO -  08-19 10:10:30.870    45    45 I Gecko   : 1376907030867	Marionette	TRACE	Got: {"to": "0", "session": "6-b2g", "type": "setContext", "value": "chrome"}
03:25:51     INFO -  08-19 10:10:30.900    45    45 I Gecko   : 1376907030894	Marionette	DEBUG	Got request: setContext, data: {"to":"0","session":"6-b2g","type":"setContext","value":"chrome"}, id: {2d96fe8c-05ff-4984-ad97-e3e5b29c0988}
03:25:51     INFO -  08-19 10:10:30.900    45    45 I Gecko   : 1376907030902	Marionette	INFO	sendToClient: {"from":"0","ok":true}, {2d96fe8c-05ff-4984-ad97-e3e5b29c0988}, {2d96fe8c-05ff-4984-ad97-e3e5b29c0988}
03:25:51     INFO -  08-19 10:10:30.970    45    45 I Gecko   : 1376907030965	Marionette	TRACE	Got: {"specialPowers": false, "scriptTimeout": null, "newSandbox": true, "args": ["app.update.staging.enabled", false], "value": "\n            Components.utils.import(\"resource://gre/modules/Services.jsm\");\n            let argtype = typeof(arguments[1]);\n            switch(argtype) {\n                case 'boolean':\n                    Services.prefs.setBoolPref(arguments[0], arguments[1]);\n                    break;\n                case 'number':\n                    Services.prefs.setIntPref(arguments[0], arguments[1]);\n                    break;\n                default:\n                    Services.prefs.setCharPref(arguments[0], arguments[1]);\n            }\n            ", "filename": "emulator.py", "to": "0", "session": "6-b2g", "line": 372, "type": "executeScript"}
03:25:51     INFO -  08-19 10:10:31.000    45    45 I Gecko   : 1376907030995	Marionette	DEBUG	Got request: execute, data: {"specialPowers":false,"scriptTimeout":null,"newSandbox":true,"args":["app.update.staging.enabled",false],"value":"\n            Components.utils.import(\"resource://gre/modules/Services.jsm\");\n            let argtype = typeof(arguments[1]);\n            switch(argtype) {\n                case 'boolean':\n                    Services.prefs.setBoolPref(arguments[0], arguments[1]);\n                    break;\n                case 'number':\n                    Services.prefs.setIntPref(arguments[0], arguments[1]);\n                    break;\n                default:\n                    Services.prefs.setCharPref(arguments[0], arguments[1]);\n            }\n            ","filename":"emulator.py","to":"0","session":"6-b2g","line":372,"type":"executeScript"}, id: {f5d6b51e-720f-437c-92ca-95ec5c3bb983}
03:25:51     INFO -  08-19 10:10:31.030    45    45 I Gecko   : 1376907031029	Marionette	INFO	sendToClient: {"from":"0","value":null}, {f5d6b51e-720f-437c-92ca-95ec5c3bb983}, {f5d6b51e-720f-437c-92ca-95ec5c3bb983}
03:25:51     INFO -  08-19 10:10:31.100    45    45 I Gecko   : 1376907031085	Marionette	TRACE	Got: {"specialPowers": false, "scriptTimeout": null, "newSandbox": true, "args": ["app.update.enabled", false], "value": "\n            Components.utils.import(\"resource://gre/modules/Services.jsm\");\n            let argtype = typeof(arguments[1]);\n            switch(argtype) {\n                case 'boolean':\n                    Services.prefs.setBoolPref(arguments[0], arguments[1]);\n                    break;\n                case 'number':\n                    Services.prefs.setIntPref(arguments[0], arguments[1]);\n                    break;\n                default:\n                    Services.prefs.setCharPref(arguments[0], arguments[1]);\n            }\n            ", "filename": "emulator.py", "to": "0", "session": "6-b2g", "line": 372, "type": "executeScript"}
03:25:51     INFO -  08-19 10:10:31.120    45    45 I Gecko   : 1376907031121	Marionette	DEBUG	Got request: execute, data: {"specialPowers":false,"scriptTimeout":null,"newSandbox":true,"args":["app.update.enabled",false],"value":"\n            Components.utils.import(\"resource://gre/modules/Services.jsm\");\n            let argtype = typeof(arguments[1]);\n            switch(argtype) {\n                case 'boolean':\n                    Services.prefs.setBoolPref(arguments[0], arguments[1]);\n                    break;\n                case 'number':\n                    Services.prefs.setIntPref(arguments[0], arguments[1]);\n                    break;\n                default:\n                    Services.prefs.setCharPref(arguments[0], arguments[1]);\n            }\n            ","filename":"emulator.py","to":"0","session":"6-b2g","line":372,"type":"executeScript"}, id: {91e67cfa-2dfd-48d3-9dd8-7ba8135d8804}
03:25:51     INFO -  08-19 10:10:31.160    45    45 I Gecko   : 1376907031155	Marionette	INFO	sendToClient: {"from":"0","value":null}, {91e67cfa-2dfd-48d3-9dd8-7ba8135d8804}, {91e67cfa-2dfd-48d3-9dd8-7ba8135d8804}
03:25:51     INFO -  08-19 10:10:31.230    45    45 I Gecko   : 1376907031231	Marionette	TRACE	Got: {"specialPowers": false, "scriptTimeout": null, "newSandbox": true, "args": ["app.update.service.enabled", false], "value": "\n            Components.utils.import(\"resource://gre/modules/Services.jsm\");\n            let argtype = typeof(arguments[1]);\n            switch(argtype) {\n                case 'boolean':\n                    Services.prefs.setBoolPref(arguments[0], arguments[1]);\n                    break;\n                case 'number':\n                    Services.prefs.setIntPref(arguments[0], arguments[1]);\n                    break;\n                default:\n                    Services.prefs.setCharPref(arguments[0], arguments[1]);\n            }\n            ", "filename": "emulator.py", "to": "0", "session": "6-b2g", "line": 372, "type": "executeScript"}
03:25:51     INFO -  08-19 10:10:31.280    45    45 I Gecko   : 1376907031263	Marionette	DEBUG	Got request: execute, data: {"specialPowers":false,"scriptTimeout":null,"newSandbox":true,"args":["app.update.service.enabled",false],"value":"\n            Components.utils.import(\"resource://gre/modules/Services.jsm\");\n            let argtype = typeof(arguments[1]);\n            switch(argtype) {\n                case 'boolean':\n                    Services.prefs.setBoolPref(arguments[0], arguments[1]);\n                    break;\n                case 'number':\n                    Services.prefs.setIntPref(arguments[0], arguments[1]);\n                    break;\n                default:\n                    Services.prefs.setCharPref(arguments[0], arguments[1]);\n            }\n            ","filename":"emulator.py","to":"0","session":"6-b2g","line":372,"type":"executeScript"}, id: {df768905-2d2c-42d0-9cdd-b85dd1b828ee}
03:25:51     INFO -  08-19 10:10:31.322    45    45 I Gecko   : 1376907031316	Marionette	INFO	sendToClient: {"from":"0","value":null}, {df768905-2d2c-42d0-9cdd-b85dd1b828ee}, {df768905-2d2c-42d0-9cdd-b85dd1b828ee}
03:25:51     INFO -  08-19 10:10:31.380    45    45 I Gecko   : 1376907031377	Marionette	TRACE	Got: {"to": "0", "session": "6-b2g", "type": "deleteSession"}
03:25:51     INFO -  08-19 10:10:31.410    45    45 I Gecko   : 1376907031404	Marionette	INFO	sendToClient: {"from":"0","ok":true}, {5a5e9e1a-dbb7-45de-8b15-6e5aa49494cd}, {5a5e9e1a-dbb7-45de-8b15-6e5aa49494cd}
03:25:51     INFO -  08-19 10:10:32.032    45    45 I GeckoDump: XXX FIXME : Got a mozContentEvent: accessibility-screenreader
}
(In reply to TBPL Robot from comment #136)
> philor
> https://tbpl.mozilla.org/php/getParsedLog.php?id=30231131&tree=Mozilla-
> Inbound
> b2g_emulator_vm mozilla-inbound opt test mochitest-5 on 2013-11-06 13:50:57
> revision: 1c5f04ca36d8
> slave: tst-linux64-ec2-431
> 
> timed out after 1000 seconds of no output
> Return code: 9

This shows the OOM Message Logger getting fired up just after B2G startup....weird.
I may have reproduced this locally a few times. When working on b2g emulator reftests, sometimes my whole computer would just freeze up immediately after the emulator is launched. Unfortunately I had to hard reset it every time this happened, so debugging was difficult. I couldn't even use sysreq commands to reboot, so I figured it might be a kernel bug.. or this could be a totally separate issue. Is it possible to see whether the slaves get restarted after this happens?

I'm using Fedora 19, 64bit.
This isn't that same problem, because here the mozharness script continues to run, and that's running on the slave.