Intermittent AttributeError: 'MarionetteTestharnessProtocolPart' object has no attribute 'marionette'

RESOLVED FIXED in Firefox 67

Status

defect
P5
normal
RESOLVED FIXED
8 months ago
5 months ago

People

(Reporter: intermittent-bug-filer, Assigned: jgraham)

Tracking

({intermittent-failure})

Version 3
mozilla67
Points:
---

Firefox Tracking Flags

(firefox67 fixed)

Details

Attachments

(3 attachments)

Filed by: nerli [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=215234551&repo=autoland

https://queue.taskcluster.net/v1/task/VdwKmfbIRNmtRwTWjTa_TQ/runs/0/artifacts/public/logs/live_backing.log

[task 2018-12-03T03:55:07.798Z] 03:55:07 CRITICAL -   File "/builds/worker/workspace/build/tests/web-platform/tests/tools/wptrunner/wptrunner/executors/executormarionette.py", line 127, in <lambda>
[task 2018-12-03T03:55:07.798Z] 03:55:07 CRITICAL -     self.dismiss_alert(lambda: self.marionette.navigate(url))
[task 2018-12-03T03:55:07.798Z] 03:55:07 CRITICAL - AttributeError: 'MarionetteTestharnessProtocolPart' object has no attribute 'marionette'
[task 2018-12-03T03:55:07.799Z] 03:55:07 CRITICAL - 
[task 2018-12-03T03:55:07.800Z] 03:55:07     INFO - Closing logging queue
[task 2018-12-03T03:55:07.800Z] 03:55:07     INFO - queue closed
[task 2018-12-03T03:55:07.800Z] 03:55:07  WARNING - Command left in remote_queue during cleanup: u'stop', ()
[task 2018-12-03T03:55:07.802Z] 03:55:07     INFO - Got 0 unexpected results
[task 2018-12-03T03:55:07.802Z] 03:55:07     INFO - SUITE-END | took 120s
[task 2018-12-03T03:55:07.866Z] 03:55:07     INFO - Closing logging queue
[task 2018-12-03T03:55:07.868Z] 03:55:07     INFO - queue closed
[task 2018-12-03T03:55:07.868Z] 03:55:07  WARNING - All requested tests were skipped
[task 2018-12-03T03:55:07.872Z] 03:55:07 CRITICAL - Test harness output was not a valid structured log message: 
[task 2018-12-03T03:55:07.873Z] 03:55:07 CRITICAL - Traceback (most recent call last):
[task 2018-12-03T03:55:07.873Z] 03:55:07 CRITICAL - Test harness output was not a valid structured log message: 
[task 2018-12-03T03:55:07.874Z] 03:55:07 CRITICAL -   File "/usr/lib/python2.7/multiprocessing/queues.py", line 268, in _feed
[task 2018-12-03T03:55:07.876Z] 03:55:07 CRITICAL - Test harness output was not a valid structured log message: 
[task 2018-12-03T03:55:07.876Z] 03:55:07 CRITICAL -     send(obj)
[task 2018-12-03T03:55:07.876Z] 03:55:07 CRITICAL - Test harness output was not a valid structured log message: 
[task 2018-12-03T03:55:07.876Z] 03:55:07 CRITICAL - IOError: [Errno 32] Broken pipe
[task 2018-12-03T03:55:08.329Z] 03:55:08     INFO - Return code: 0
[task 2018-12-03T03:55:08.330Z] 03:55:08 CRITICAL - # TBPL FAILURE #
[task 2018-12-03T03:55:08.331Z] 03:55:08  WARNING - setting return code to 2
[task 2018-12-03T03:55:08.331Z] 03:55:08     INFO - Running post-action listener: _package_coverage_data
[task 2018-12-03T03:55:08.332Z] 03:55:08     INFO - Running post-action listener: _resource_record_post_action
[task 2018-12-03T03:55:08.332Z] 03:55:08     INFO - Running post-action listener: process_java_coverage_data
[task 2018-12-03T03:55:08.332Z] 03:55:08     INFO - Running post-action listener: stop_device
[task 2018-12-03T03:55:08.332Z] 03:55:08     INFO - [mozharness: 2018-12-03 03:55:08.332304Z] Finished run-tests step (success)
[task 2018-12-03T03:55:08.332Z] 03:55:08     INFO - Running post-run listener: _resource_record_post_run
[task 2018-12-03T03:55:08.382Z] 03:55:08     INFO - Total resource usage - Wall time: 205s; CPU: 11.0%; Read bytes: 17555456; Write bytes: 2437349376; Read time: 9744; Write time: 370332
[task 2018-12-03T03:55:08.382Z] 03:55:08     INFO - TinderboxPrint: CPU usage<br/>10.9%
[task 2018-12-03T03:55:08.382Z] 03:55:08     INFO - TinderboxPrint: I/O read bytes / time<br/>17,555,456 / 9,744
[task 2018-12-03T03:55:08.382Z] 03:55:08     INFO - TinderboxPrint: I/O write bytes / time<br/>2,437,349,376 / 370,332
[task 2018-12-03T03:55:08.382Z] 03:55:08     INFO - TinderboxPrint: CPU idle<br/>716.6 (87.9%)
[task 2018-12-03T03:55:08.382Z] 03:55:08     INFO - TinderboxPrint: CPU iowait<br/>9.1 (1.1%)
[task 2018-12-03T03:55:08.383Z] 03:55:08     INFO - TinderboxPrint: CPU user<br/>83.9 (10.3%)
[task 2018-12-03T03:55:08.383Z] 03:55:08     INFO - TinderboxPrint: Swap in / out<br/>0 / 0
[task 2018-12-03T03:55:08.383Z] 03:55:08     INFO - pull - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2018-12-03T03:55:08.384Z] 03:55:08     INFO - verify-device - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2018-12-03T03:55:08.385Z] 03:55:08     INFO - install - Wall time: 69s; CPU: 25.0%; Read bytes: 0; Write bytes: 1515266048; Read time: 0; Write time: 227928
[task 2018-12-03T03:55:08.387Z] 03:55:08     INFO - run-tests - Wall time: 137s; CPU: 4.0%; Read bytes: 17555456; Write bytes: 922083328; Read time: 9744; Write time: 142404
[task 2018-12-03T03:55:08.447Z] 03:55:08  WARNING - returning nonzero exit status 2
Summary: Intermittent File "/builds/worker/workspace/build/tests/web-platform/tests/tools/wptrunner/wptrunner/executors/executormarionette.py", line 127, in load_runner → Intermittent AttributeError: 'MarionetteTestharnessProtocolPart' object has no attribute 'marionette'
Duplicate of this bug: 1511910

I am somehow being hit by this failure. The environment I am using is Linux x64 just setup today with ./mach bootstrap for "GeckoView/Firefox for Android". The revision is https://hg.mozilla.org/mozilla-central/rev/666abafd77b1 .

Also note that ./mach mochitest or other ./mach command works fine.

(In reply to Intermittent Failures Robot from comment #7)

7 failures in 2627 pushes (0.003 failures/push) were associated with this bug in the last 7 days.

I reviewed the logs and logcats from a few recent failures.

Logs typically show something like:

[task 2019-01-13T10:56:05.485Z] 10:56:05 INFO - adb launch_application: am start -W -n org.mozilla.fennec_aurora/org.mozilla.gecko.BrowserApp -a android.intent.action.VIEW --es env9 MOZ_PROCESS_LOG=/tmp/tmphip5jCpidlog --es env8 MOZ_CRASHREPORTER_NO_REPORT=1 --es args "-no-remote -profile /sdcard/tests/profile --marionette about:blank" --es env3 STYLO_THREADS=4 --es env2 MOZ_HIDE_RESULTS_TABLE=1 --es env1 R_LOG_VERBOSE=1 --es env0 MOZ_CRASHREPORTER=1 --es env7 MOZ_DISABLE_NONLOCAL_CONNECTIONS=1 --es env6 R_LOG_DESTINATION=stderr --es env5 MOZ_CRASHREPORTER_SHUTDOWN=1 --es env4 MOZ_LOG=signaling:3,mtransport:4,DataChannel:4,jsep:4,MediaPipelineFactory:4 --es env10 R_LOG_LEVEL=6
[task 2019-01-13T10:56:17.673Z] 10:56:17 INFO - STDOUT: timed out waiting for 'org.mozilla.fennec_aurora' process to start
[task 2019-01-13T10:56:17.787Z] 10:56:17 INFO - Starting runner
[task 2019-01-13T10:58:17.824Z] 10:58:17 WARNING - Timed out waiting for browser to start
[task 2019-01-13T10:58:18.267Z] 10:58:18 CRITICAL - Loading initial page http://web-platform.test:8000/testharness_runner.html failed. Ensure that the there are no other programs bound to this port and that your firewall rules or network setup does not prevent access.\eTraceback (most recent call last):
[task 2019-01-13T10:58:18.267Z] 10:58:18 CRITICAL - File "/builds/worker/workspace/build/tests/web-platform/tests/tools/wptrunner/wptrunner/executors/executormarionette.py", line 131, in load_runner
[task 2019-01-13T10:58:18.268Z] 10:58:18 CRITICAL - self.dismiss_alert(lambda: self.marionette.navigate(url))
[task 2019-01-13T10:58:18.268Z] 10:58:18 CRITICAL - File "/builds/worker/workspace/build/tests/web-platform/tests/tools/wptrunner/wptrunner/executors/executormarionette.py", line 179, in dismiss_alert
[task 2019-01-13T10:58:18.268Z] 10:58:18 CRITICAL - f()
[task 2019-01-13T10:58:18.268Z] 10:58:18 CRITICAL - File "/builds/worker/workspace/build/tests/web-platform/tests/tools/wptrunner/wptrunner/executors/executormarionette.py", line 131, in <lambda>
[task 2019-01-13T10:58:18.269Z] 10:58:18 CRITICAL - self.dismiss_alert(lambda: self.marionette.navigate(url))
[task 2019-01-13T10:58:18.269Z] 10:58:18 CRITICAL - AttributeError: 'MarionetteTestharnessProtocolPart' object has no attribute 'marionette'

It seems like Fennec failed to launch, that was detected but the harness continued bravely forward only to trigger a python error; we should probably avoid the python AttributeError in cases like this (but I haven't investigated).

Logcats show Fennec failing to startup fully, but that is preceded by a crash of com.android.internal.os.RuntimeInit, possibly during Fennec installation, but more likely when the harness is trying to grant permissions. I noticed:

Unknown permission com.samsung.android.providers.context.permission.WRITE_USE_APP_FEATURE_SURVEY in package org.mozilla.fennec_aurora

just before that - related? If so, I'd expect this issue to disappear when we switch wpt to geckoview (only fennec tries to use that permission).

(In reply to Hiroyuki Ikezoe (:hiro) from comment #8)

I am somehow being hit by this failure. The environment I am using is Linux x64 just setup today with ./mach bootstrap for "GeckoView/Firefox for Android". The revision is https://hg.mozilla.org/mozilla-central/rev/666abafd77b1 .

Also note that ./mach mochitest or other ./mach command works fine.

This bug seems to be a low-frequency issue in continuous integration. But this error message can indicate a variety of issues. If you can reproduce reliably in your environment, I would check logcat to see if fennec is being launched okay. If more investigation is needed, it would be best to file a new bug with your logcat attached.

See Also: → 1521624

Thank you gbrown, I filed bug 1521624 with logs.

No longer blocks: 1501562

In the case that startup failed we may not have a marionette session during teardown

Depends on D19486

The previous setup was broken because subclasses could run code after the cinnection failed assuming
that the connection had succeeded. Unwinding the stack and sending the failure messages at the
top level avoid this pitfall.

Depends on D19487

Pushed by james@hoppipolla.co.uk:
https://hg.mozilla.org/integration/autoland/rev/0bdbfacae180
Fixup launching Chrome from ./mach wpt, r=whimboo
https://hg.mozilla.org/integration/autoland/rev/f754cb84d092
Ensure that marionette has a session when we try to use it during teardown, r=whimboo
https://hg.mozilla.org/integration/autoland/rev/4cf8e31cb261
Bail out of startup if we are unable to connect to wpt, r=whimboo
Created web-platform-tests PR https://github.com/web-platform-tests/wpt/pull/15382 for changes under testing/web-platform/tests
Upstream PR merged
You need to log in before you can comment on or make changes to this bug.