Closed Bug 1608370 Opened 5 years ago Closed 5 years ago

No startup/shutdown profile written for Marionette based test jobs

Categories

(Remote Protocol :: Marionette, defect, P1)

defect

Tracking

(firefox74 fixed)

RESOLVED FIXED
mozilla74
Tracking Status
firefox74 --- fixed

People

(Reporter: whimboo, Assigned: whimboo)

References

Details

(Whiteboard: [puppeteer-beta-mvp])

Attachments

(1 file)

I tried to create a Gecko profile for a locally build artifact build by running some marionette tests. After the tests have been finished I expected the profile to be written to the file as specified but that file is not present on disk. Here an example command which at least demonstrates the problem on my MBP:

$ MOZ_PROFILER_STARTUP=1 MOZ_PROFILER_SHUTDOWN=/code/gecko/profile.json mach test testing/marionette/harness/marionette_harness/tests/unit/test_pagesource.py

I also tried it for browser chrome tests under /remote/tests/browser but the same behavior is visible. Finally I started Firefox via MOZ_PROFILER_STARTUP=1 MOZ_PROFILER_SHUTDOWN=/code/gecko/profile.json mach run, and manually quit Firefox. Now the profile is written to disk.

Not sure what specific code path triggers the write of the profile but it would be great to get it always working.

Afaik MOZ_PROFILER_SHUTDOWN expects a filename, not a full path, the file will be written in $(pwd)/<filename>

That said, enough people have been confused by this (myself included), that it's probably a good idea to see if we could change the behavior to make that variable accept a path.

No, it needs an absolute path. If only a filename is specified, I don't know where the file gets saved. It's at least not in the current working directory.

But as said above... this problem is not related to the path format.

If I run MOZ_PROFILER_STARTUP=1 MOZ_PROFILER_SHUTDOWN=mp.json ./mach test browser/base/content/test/pageinfo/browser_pageinfo_image_info.js, I get the profile in ./obj-artifact/_tests/testing/mochitest/mp.json which seems to be the folder the mochitest harness sets as the current directory.

From looking at the output of running your marionette command on my local artifact build on OSX, I suspect the marionette harness changes the current directory to a temporary folder that gets deleted at the end of the run. If I was I running this on Linux, I would use strace to verify this assumption.

We do std::ofstream stream; stream.open(aFilename);, with aFilename being the contents of MOZ_PROFILER_SHUTDOWN:
https://searchfox.org/mozilla-central/rev/d4d6f81e0ab479cde192453bae83d5e3edfb39d6/tools/profiler/core/platform.cpp#3948
An absolute path should work; a relative path would be relative to the "current directory" where the ./mach command is run.

(Weekend here, I'll come back to this next week...)

Priority: -- → P1

Update:
I've tried running MOZ_LOG=prof:5 MOZ_PROFILER_STARTUP=1 MOZ_PROFILER_SHUTDOWN="profile_marionette_20200113.json" mach marionette-test -vv --gecko-log - testing/marionette/harness/marionette_harness/tests/unit/test_pagesource.py
MOZ_LOG=prof:5 and --gecko-log - output the profiler's logging to stdout.

I could see normal logs during startup, including "profiler_init" (called from main()), "profiler_locked_start" (showing the profiler is turned on); and other runtime logs.
And I added a bit of logging to a local build, and I could verify that "MOZ_PROFILER_SHUTDOWN" contained the filename from the command line.

However at the end there were none of the expected end-of-life logs; I would have expected "profiler_stop", or at the very least "profiler_shutdown", which is called by the destructor of AutoProfilerInit (the object that called "profiler_init" when created in the main())!?
"profiler_shutdown" is where we would store the shutdown profile.

So at the moment I'm thinking that maybe Marionette just kills Firefox when its tests are finished?

Henrik:
I don't know much about Marionette, so I may be wrong of course, but could you please let me know what you think about my theory above?
Is there some way you/I could attach a debugger to the target Firefox, and know what happens after the marionette test ends?

Flags: needinfo?(hskupin)

Ok, this seems to be indeed a problem with Marionette and how the test harness closes Firefox. Even we can safely shutdown Firefox it's not done but a kill is triggered via mozrunner. I will have a look and we surely have to get Marionette to safely quit Firefox after the last test has been ran.

With a temporary fix I can also get the browser chrome tests under /remote to create a profile.json file on disk.

Assignee: nobody → hskupin
Status: NEW → ASSIGNED
Component: Gecko Profiler → Marionette
Flags: needinfo?(hskupin)
Product: Core → Testing
Summary: No startup/shutdown profile written if Firefox isn't launched via `mach run` → No startup/shutdown profile written for Marionette based test jobs
Whiteboard: [puppeteer-beta-mvp]
Blocks: 1577713

This forces a safe shutdown of the application after the last
test if the process is still up and running. Because the
testcase class already deleted the session a new one needs
to be created.

A more elegant solution might be possible but would involve
a fair amount of refactoring, which at this point is not
worse our time.

Blocks: 1596390
Pushed by hskupin@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/9d1a99b3b507 [marionette] No startup/shutdown profile written for Marionette based test jobs. r=marionette-reviewers,ato
Status: ASSIGNED → RESOLVED
Closed: 5 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla74
Product: Testing → Remote Protocol
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: