Closed Bug 1892044 Opened 1 month ago Closed 1 month ago

Perma [tier 2] "Automation Error: Received unexpected exception while running application | NameError: name 'e' is not defined" because psutil cannot be imported

Categories

(Testing :: mozperftest, defect, P5)

Product:
Testing
Component:
mozperftest
Type:
defect
Points:
2

Tracking

(firefox-esr115 unaffected, firefox125 unaffected, firefox126 unaffected, firefox127 fixed)

Status:
RESOLVED FIXED
Milestone:
127 Branch
Tracking Flags:
Tracking Status
firefox-esr115 --- unaffected
firefox125 --- unaffected
firefox126 --- unaffected
firefox127 --- fixed

People

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

References

(Regression)

Details

(Keywords: intermittent-failure, regression, Whiteboard: [webdriver:m11])

Attachments

(2 files)

Bug 1892044 - [mochitest] Fix for "NameError: name 'e' is not defined"
48 bytes, text/x-phabricator-request
Details | Review
Bug 1892044 - [mozperftest] Remove "--no-deps" argument for installing Python requirements file.
48 bytes, text/x-phabricator-request
Details | Review

Filed by: pstanciu [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=454864859&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/Uc_5aNRyTfSvCovSPfougA/runs/0/artifacts/public/logs/live_backing.log

[task 2024-04-17T14:38:23.389Z] Successfully built geckoprocesstypes mozterm manifestparser mozcrash mozdebug mozdevice mozfile mozgeckoprofiler mozhttpd mozinfo mozInstall mozleak mozlog moznetwork mozpower mozprocess mozprofile mozproxy mozrunner mozserve mozscreenshot moztest mozversion wptserve certifi h2 hyperframe hpack mod-pywebsocket marionette-driver marionette-harness
[task 2024-04-17T14:38:23.389Z] Installing collected packages: wptserve, mozversion, moztest, mozterm, mozserve, mozscreenshot, mozrunner, mozproxy, mozprofile, mozprocess, mozpower, moznetwork, mozlog, mozleak, mozInstall, mozinfo, mozhttpd, mozgeckoprofiler, mozfile, mozdevice, mozdebug, mozcrash, marionette-harness, marionette-driver, manifestparser, geckoprocesstypes, certifi, mod-pywebsocket, hyperframe, hpack, h2
[task 2024-04-17T14:38:23.883Z]   Attempting uninstall: certifi
[task 2024-04-17T14:38:23.884Z]     Found existing installation: certifi 2022.12.7
[task 2024-04-17T14:38:23.885Z]     Not uninstalling certifi at /opt/worker/tasks/task_171335947016070/fetches/third_party/python/certifi, outside environment /Users/cltbld/.mozbuild/srcdirs/fetches-30ab06ad0eb9/_virtualenvs/common
[task 2024-04-17T14:38:23.885Z]     Can't uninstall 'certifi'. No files were found to uninstall.
[task 2024-04-17T14:38:24.026Z] Successfully installed certifi-2018.4.16 geckoprocesstypes-1.0 h2-4.1.0 hpack-4.0.0 hyperframe-6.0.1 manifestparser-2.4.0 marionette-driver-3.4.0 marionette-harness-5.0.2 mod-pywebsocket-3.0.2 mozInstall-2.1.0 mozcrash-2.2.0 mozdebug-0.3.0 mozdevice-4.1.1 mozfile-3.0.0 mozgeckoprofiler-1.0.0 mozhttpd-0.7.1 mozinfo-1.2.3 mozleak-1.0.0 mozlog-8.0.0 moznetwork-1.1.0 mozpower-1.1.2 mozprocess-1.3.1 mozprofile-2.6.1 mozproxy-1.0 mozrunner-8.3.0 mozscreenshot-1.0.0 mozserve-0.1 mozterm-1.0.0 moztest-1.1.0 mozversion-2.4.0 wptserve-4.0
[task 2024-04-17T14:38:24.106Z]  0:26.05 Running macos:run
[task 2024-04-17T14:38:24.106Z]  0:26.05 Mounting /opt/worker/tasks/task_171335947016070/fetches/target.dmg
[task 2024-04-17T14:38:59.900Z]  1:01.85 Using /opt/worker/tasks/task_171335947016070/fetches/target/Contents/MacOS/firefox for mochitest-binary
[task 2024-04-17T14:38:59.900Z]  1:01.85 Running profile:run
[task 2024-04-17T14:38:59.901Z]  1:01.85 Created profile at /var/folders/sp/25wcjhls5pq54ql8fsdz2f3w000014/T/tmpp8utf17d.mozrunner
[task 2024-04-17T14:38:59.901Z]  1:01.85 Running mochitest:run
[task 2024-04-17T14:39:00.671Z] Traceback (most recent call last):
[task 2024-04-17T14:39:00.671Z]   File "/opt/worker/tasks/task_171335947016070/fetches/mochitest/runtests.py", line 3782, in doTests
[task 2024-04-17T14:39:00.671Z]     ret, _ = self.runApp(
[task 2024-04-17T14:39:00.671Z]   File "/opt/worker/tasks/task_171335947016070/fetches/mochitest/runtests.py", line 2899, in runApp
[task 2024-04-17T14:39:00.671Z]     self.marionette = Marionette(**marionette_args)
[task 2024-04-17T14:39:00.671Z]   File "/opt/worker/tasks/task_171335947016070/fetches/mochitest/runtests.py", line 65, in reraise
[task 2024-04-17T14:39:00.671Z]     raise (e)  # noqa
[task 2024-04-17T14:39:00.671Z] NameError: name 'e' is not defined
[task 2024-04-17T14:39:00.671Z] Creating local state directory: /Users/cltbld/.mozbuild/srcdirs/fetches-30ab06ad0eb9
[task 2024-04-17T14:39:00.671Z] Setting up mochitest python paths...
[task 2024-04-17T14:39:00.671Z] These variables are available in the mozinfo environment and can be used to skip tests conditionally:
[task 2024-04-17T14:39:00.671Z]     a11y_checks: False
[task 2024-04-17T14:39:00.671Z]     apple_catalina: True
[task 2024-04-17T14:39:00.671Z]     apple_silicon: False
[task 2024-04-17T14:39:00.671Z]     appname: firefox
[task 2024-04-17T14:39:00.671Z]     arch: x86_64
[task 2024-04-17T14:39:00.671Z]     artifact: False
[task 2024-04-17T14:39:00.671Z]     asan: False
[task 2024-04-17T14:39:00.671Z]     automation: True
[task 2024-04-17T14:39:00.671Z]     bin_suffix: 
[task 2024-04-17T14:39:00.671Z]     bits: 64
[task 2024-04-17T14:39:00.671Z]     buildapp: browser
[task 2024-04-17T14:39:00.671Z]     buildtype: pgo
[task 2024-04-17T14:39:00.671Z]     buildtype_guess: pgo
[task 2024-04-17T14:39:00.671Z]     cc_type: clang
[task 2024-04-17T14:39:00.671Z]     ccov: False
[task 2024-04-17T14:39:00.671Z]     condprof: False
[task 2024-04-17T14:39:00.671Z]     crashreporter: True
[task 2024-04-17T14:39:00.671Z]     datareporting: True
[task 2024-04-17T14:39:00.671Z]     debug: False
[task 2024-04-17T14:39:00.671Z]     devedition: False
[task 2024-04-17T14:39:00.671Z]     display: None
[task 2024-04-17T14:39:00.671Z]     domstreams: True
[task 2024-04-17T14:39:00.671Z]     e10s: True
[task 2024-04-17T14:39:00.671Z]     early_beta_or_earlier: True
[task 2024-04-17T14:39:00.671Z]     fission: True
[task 2024-04-17T14:39:00.671Z]     has_sandbox: True
[task 2024-04-17T14:39:00.671Z]     headless: False
[task 2024-04-17T14:39:00.671Z]     healthreport: True
[task 2024-04-17T14:39:00.671Z]     http2: False
[task 2024-04-17T14:39:00.671Z]     http3: False
[task 2024-04-17T14:39:00.671Z]     is_ubuntu: False
[task 2024-04-17T14:39:00.671Z]     isolated_process: False
[task 2024-04-17T14:39:00.671Z]     mda_gpu: False
[task 2024-04-17T14:39:00.671Z]     mozconfig: /builds/worker/checkouts/gecko/.mozconfig
[task 2024-04-17T14:39:00.671Z]     msix: False
[task 2024-04-17T14:39:00.671Z]     nightly_build: True
[task 2024-04-17T14:39:00.671Z]     normandy: True
[task 2024-04-17T14:39:00.671Z]     official: True
[task 2024-04-17T14:39:00.671Z]     os: mac
[task 2024-04-17T14:39:00.671Z]     os_version: 10.15
[task 2024-04-17T14:39:00.671Z]     pgo: True
[task 2024-04-17T14:39:00.671Z]     platform_guess: macosx64
[task 2024-04-17T14:39:00.671Z]     processor: x86_64
[task 2024-04-17T14:39:00.671Z]     release_or_beta: False
[task 2024-04-17T14:39:00.671Z]     require_signing: False
[task 2024-04-17T14:39:00.671Z]     serviceworker_e10s: True
[task 2024-04-17T14:39:00.671Z]     sessionHistoryInParent: True
[task 2024-04-17T14:39:00.671Z]     socketprocess_e10s: False
[task 2024-04-17T14:39:00.671Z]     socketprocess_networking: False
[task 2024-04-17T14:39:00.671Z]     stylo: True
[task 2024-04-17T14:39:00.671Z]     swgl: False
[task 2024-04-17T14:39:00.671Z]     sync: True
[task 2024-04-17T14:39:00.671Z]     telemetry: False
[task 2024-04-17T14:39:00.671Z]     tests_enabled: True
[task 2024-04-17T14:39:00.671Z]     toolkit: cocoa
[task 2024-04-17T14:39:00.671Z]     topobjdir: /builds/worker/workspace/obj-build
[task 2024-04-17T14:39:00.671Z]     topsrcdir: /builds/worker/checkouts/gecko
[task 2024-04-17T14:39:00.671Z]     tsan: False
[task 2024-04-17T14:39:00.671Z]     ubsan: False
[task 2024-04-17T14:39:00.671Z]     updater: True
[task 2024-04-17T14:39:00.671Z]     verify: False
[task 2024-04-17T14:39:00.671Z]     verify_fission: False
[task 2024-04-17T14:39:00.671Z]     version: OS X 10.15.7
[task 2024-04-17T14:39:00.671Z]     webgl_ipc: False
[task 2024-04-17T14:39:00.671Z]     win10_2009: False
[task 2024-04-17T14:39:00.671Z]     win11_2009: False
[task 2024-04-17T14:39:00.671Z]     wmfme: 0
[task 2024-04-17T14:39:00.671Z]     xorigin: False
[task 2024-04-17T14:39:00.671Z] Checking for ssltunnel processes...
[task 2024-04-17T14:39:00.671Z] Checking for xpcshell processes...
[task 2024-04-17T14:39:00.671Z] SUITE-START | Running 1 tests
[task 2024-04-17T14:39:00.671Z] Running manifest: perftest.toml
[task 2024-04-17T14:39:00.671Z] PID 3903 | pk12util: PKCS12 IMPORT SUCCESSFUL
[task 2024-04-17T14:39:00.671Z] MochitestServer : launching ['/opt/worker/tasks/task_171335947016070/fetches/bin/xpcshell', '-g', '/opt/worker/tasks/task_171335947016070/fetches/target/Contents/Resources', '-e', "const _PROFILE_PATH = '/var/folders/sp/25wcjhls5pq54ql8fsdz2f3w000014/T/tmpc62h8t38.mozrunner'; const _SERVER_PORT = '8888'; const _SERVER_ADDR = '127.0.0.1'; const _TEST_PREFIX = undefined; const _DISPLAY_RESULTS = false; const _HTTPD_PATH = '/opt/worker/tasks/task_171335947016070/fetches/bin/components';", '-f', '/opt/worker/tasks/task_171335947016070/fetches/mochitest/server.js']
[task 2024-04-17T14:39:00.671Z] runtests.py | Server pid: 3910
[task 2024-04-17T14:39:00.671Z] runtests.py | Websocket server pid: 3912
[task 2024-04-17T14:39:00.671Z] runtests.py | SSL tunnel pid: 3913
[task 2024-04-17T14:39:00.672Z] use http3 server: 0
[task 2024-04-17T14:39:00.672Z] runtests.py | Running with scheme: http
[task 2024-04-17T14:39:00.672Z] runtests.py | Running with e10s: True
[task 2024-04-17T14:39:00.672Z] runtests.py | Running with fission: True
[task 2024-04-17T14:39:00.672Z] runtests.py | Running with cross-origin iframes: False
[task 2024-04-17T14:39:00.672Z] runtests.py | Running with serviceworker_e10s: True
[task 2024-04-17T14:39:00.672Z] runtests.py | Running with socketprocess_e10s: False
[task 2024-04-17T14:39:00.672Z] runtests.py | Running tests: start.
[task 2024-04-17T14:39:00.672Z] Application command: /opt/worker/tasks/task_171335947016070/fetches/target/Contents/MacOS/firefox -marionette -foreground -profile /var/folders/sp/25wcjhls5pq54ql8fsdz2f3w000014/T/tmpc62h8t38.mozrunner
[task 2024-04-17T14:39:00.672Z] runtests.py | Application pid: 3914
[task 2024-04-17T14:39:00.672Z] TEST-INFO | started process GECKO(3914)
[task 2024-04-17T14:39:00.672Z] Automation Error: Received unexpected exception while running application
[task 2024-04-17T14:39:00.672Z] Stopping web server
[task 2024-04-17T14:39:00.672Z] Server shut down.
[task 2024-04-17T14:39:00.672Z] Web server killed.
[task 2024-04-17T14:39:00.672Z] Stopping web socket server
[task 2024-04-17T14:39:00.672Z] Stopping ssltunnel
[task 2024-04-17T14:39:00.672Z] runtests.py | Running tests: end.
[task 2024-04-17T14:39:00.672Z] Buffered messages finished
[task 2024-04-17T14:39:00.672Z] 0 INFO TEST-START | Shutdown
[task 2024-04-17T14:39:00.672Z] 1 INFO Passed:  0
[task 2024-04-17T14:39:00.672Z] 2 INFO Failed:  0
[task 2024-04-17T14:39:00.672Z] 3 INFO Todo:    0
[task 2024-04-17T14:39:00.672Z] 4 INFO Mode:    e10s
[task 2024-04-17T14:39:00.672Z] 5 INFO SimpleTest FINISHED
[task 2024-04-17T14:39:00.672Z] Buffered messages finished
[task 2024-04-17T14:39:00.672Z] SUITE-END | took 0s
[task 2024-04-17T14:39:00.672Z] Traceback (most recent call last):
[task 2024-04-17T14:39:00.672Z]   File "python/mozperftest/mozperftest/runner.py", line 299, in <module>
[task 2024-04-17T14:39:00.672Z]     sys.exit(main())
[task 2024-04-17T14:39:00.672Z]   File "python/mozperftest/mozperftest/runner.py", line 295, in main
[task 2024-04-17T14:39:00.672Z]     run_tests(mach_cmd, args, user_args)
[task 2024-04-17T14:39:00.672Z]   File "python/mozperftest/mozperftest/runner.py", line 188, in run_tests
[task 2024-04-17T14:39:00.672Z]     e.run(metadata)
[task 2024-04-17T14:39:00.672Z]   File "/opt/worker/tasks/task_171335947016070/fetches/python/mozperftest/mozperftest/environment.py", line 92, in run
[task 2024-04-17T14:39:00.672Z]     metadata = testlayer(syslayer(metadata))
[task 2024-04-17T14:39:00.672Z]   File "/opt/worker/tasks/task_171335947016070/fetches/python/mozperftest/mozperftest/layers.py", line 157, in __call__
[task 2024-04-17T14:39:00.672Z]     metadata = layer(metadata)
[task 2024-04-17T14:39:00.672Z]   File "/opt/worker/tasks/task_171335947016070/fetches/python/mozperftest/mozperftest/layers.py", line 69, in __call__
[task 2024-04-17T14:39:00.672Z]     metadata = self.run(metadata)
[task 2024-04-17T14:39:00.672Z]   File "/opt/worker/tasks/task_171335947016070/fetches/python/mozperftest/mozperftest/test/mochitest.py", line 192, in run
[task 2024-04-17T14:39:00.672Z]     raise MochitestTestFailure("Test failed to run")
[task 2024-04-17T14:39:00.672Z] mozperftest.test.mochitest.MochitestTestFailure: Test failed to run
[taskcluster 2024-04-17T14:39:00.824Z]    Exit Code: 1
[taskcluster 2024-04-17T14:39:00.824Z]    User Time: 46.487259s
[taskcluster 2024-04-17T14:39:00.824Z]  Kernel Time: 18.938789s
[taskcluster 2024-04-17T14:39:00.824Z]    Wall Time: 2m8.29072s
[taskcluster 2024-04-17T14:39:00.824Z]       Result: FAILED
[taskcluster 2024-04-17T14:39:00.825Z] === Task Finished ===
[taskcluster 2024-04-17T14:39:00.825Z] Task Duration: 2m8.293885s
[taskcluster 2024-04-17T14:39:00.942Z] Uploading link artifact public/logs/live.log to artifact public/logs/live_backing.log with expiry 2025-04-17T11:51:49.354Z
[taskcluster:error] exit status 1

Hello,
this happened also yesterday, link , but was backed out

:whimboo, since you are the author of the regressor, bug 1884401, could you take a look?

For more information, please visit BugBot documentation.

Flags: needinfo?(hskupin)

@whimboo, could you take another look at this perma preftest failure?
it isn't fixed after the landing of bug 1884401

Flags: needinfo?(hskupin)
Flags: needinfo?(hskupin)

I'm running the following mozperf test locally but it works without issues:

mach perftest dom/serviceworkers/test/performance/test_caching.html --flavor mochitest

As it looks like there might be some issues with the import of Marionette. I will have to create try pushes to get this investigated.

The code that re-raises the Marionette import error after a delay (when Marionette gets actually used) is broken. As such we do not get a really helpful error message. I fixed that locally and pushed a try build:

https://treeherder.mozilla.org/jobs?repo=try&revision=b7eca35d5df6647d51446baa681f0a4a9d2eef91

Nevertheless I assume that the problem here is the import of psutil via marionette.py -> geckoinstance.py. With my changes on bug 1884401 the required dependency has been added to the requirements.txt file which is used within setup.py for Marionette driver:

https://searchfox.org/mozilla-central/source/testing/marionette/client/requirements.txt

So I assume that mozperftest does not correctly install Marionette driver and as such the out of tree dependency is missed. Whereby the package is getting built correctly:

https://treeherder.mozilla.org/logviewer?job_id=454892461&repo=autoland&lineNumber=362-364

Greg, how does mozperf install Python deps in CI?

Component: Marionette Client and Harness → mozperftest
Flags: needinfo?(hskupin) → needinfo?(gmierz2)

Set release status flags based on info from the regressing bug 1884401

status-firefox125: --- → unaffected
status-firefox126: --- → unaffected
status-firefox127: --- → affected
status-firefox-esr115: --- → unaffected

There's a couple places that these can get installed. For the mochitest tests, we install marionette reqs using the testing/config/marionette_requirements.txt file: https://searchfox.org/mozilla-central/source/python/mozperftest/mozperftest/test/mochitest.py#105

Flags: needinfo?(gmierz2)

For now I've added psutil to this config file. Lets see if that works:
https://treeherder.mozilla.org/jobs?repo=try&revision=8763ec4e619fe634015d5fa0f340536082584b67

But because only mozperftest is affected and no other mochitest suite I would rather at it to the 2nd location what Greg pointed out. That would handle it specifically for mozperftest only. If that works a follow-up bug might be worth to figure out why it doesn't work.

I pushed another try build with the --no-deps argument removed which most likely causes that:
https://treeherder.mozilla.org/jobs?repo=try&revision=e0697f35db2c74b0688674d82e84b51d9742ca20

Not sure why this is needed Maybe Greg can give more details.

Attachment #9397430 - Attachment description: Bug 1892044 - [mochitest] Fix delayed exception for Marionette import errors. → Bug 1892044 - [mochitest] Fix for "NameError: name 'e' is not defined"
Assignee: nobody → hskupin
Status: NEW → ASSIGNED
Points: --- → 2
Summary: Perma [tier 2] Automation Error: Received unexpected exception while running application | NameError: name 'e' is not defined → Perma [tier 2] "Automation Error: Received unexpected exception while running application | NameError: name 'e' is not defined" because psutil cannot be imported
Whiteboard: [webdriver:m11]
Pushed by hskupin@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/a09ae43a0aad
[mochitest] Fix for "NameError: name 'e' is not defined" r=sparky
https://hg.mozilla.org/integration/autoland/rev/3e097fca93b9
[mozperftest] Remove "--no-deps" argument for installing Python requirements file. r=sparky

https://hg.mozilla.org/mozilla-central/rev/a09ae43a0aad
https://hg.mozilla.org/mozilla-central/rev/3e097fca93b9

Status: ASSIGNED → RESOLVED
Closed: 1 month ago
status-firefox127: affected → fixed
Resolution: --- → FIXED
Target Milestone: --- → 127 Branch
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: