To be able to better investigate the problems like on bug 1397201 we should enable the Marionette trace logs. As stated over on that bug it should not give much overhead given that Marionette is only used to install an extension. Right now we miss detailed information during the startup phase, and the patch which I will upload soon will enable those log lines.

The following output would be visible during each startup of Firefox (log lines from Firefox removed): GECKO(24713) | 1509015223093 Marionette DEBUG Received observer notification "profile-after-change" GECKO(24713) | 1509015223254 Marionette DEBUG Received observer notification "command-line-startup" GECKO(24713) | 1509015223254 Marionette INFO Enabled via --marionette GECKO(24713) | 1509015225109 Marionette DEBUG Received observer notification "sessionstore-windows-restored" GECKO(24713) | 1509015226020 Marionette DEBUG New connections are accepted GECKO(24713) | 1509015226021 Marionette INFO Listening on port 2828 GECKO(24713) | 1509015226042 Marionette DEBUG Accepted connection 0 from 127.0.0.1:58336 GECKO(24713) | 1509015226061 Marionette DEBUG Closed connection 0 GECKO(24713) | 1509015226064 Marionette DEBUG Accepted connection 1 from 127.0.0.1:58337 GECKO(24713) | 1509015226081 Marionette TRACE 1 -> [0,1,"newSession",{}] GECKO(24713) | 1509015226125 Marionette DEBUG Register listener.js for window 6 GECKO(24713) | 1509015226170 Marionette TRACE 1 <- [1,1,null,{"sessionId":"7f19ca30-d20f-be4c-9bf6-7d77efd3f6ec","capabilities":{}}] GECKO(24713) | 1509015226224 Marionette TRACE 1 -> [0,2,"addon:install",{"path":"/var/folders/4k/sf4gz5fn3kl9hr3nd7pzbvhc0000gn/T/tmpjp66Yq.zip","temporary":false}] GECKO(24713) | 1509015226436 Marionette TRACE 1 <- [1,2,null,{"value":"special-powers@mozilla.org"}] GECKO(24713) | 1509015226517 Marionette TRACE 1 -> [0,3,"addon:install",{"path":"/var/folders/4k/sf4gz5fn3kl9hr3nd7pzbvhc0000gn/T/tmp0pALHS.zip","temporary":false}] GECKO(24713) | 1509015226670 Marionette TRACE 1 <- [1,3,null,{"value":"mochikit@mozilla.org"}] GECKO(24713) | 1509015226691 Marionette TRACE 1 -> [0,4,"getContext",{}] GECKO(24713) | 1509015226692 Marionette TRACE 1 <- [1,4,null,{"value":"content"}] GECKO(24713) | 1509015226709 Marionette TRACE 1 -> [0,5,"setContext",{"value":"chrome"}] GECKO(24713) | 1509015226710 Marionette TRACE 1 <- [1,5,null,{}] GECKO(24713) | 1509015226719 Marionette TRACE 1 -> [0,6,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[{"testUrl":"http://mochi.test:8888/redirect.html","flavor":"a11y"}],"filename":"runtests.py","script":"/* This Source Code Form is subject to the terms of the Mozilla Public\n * License, v. 2.0. If a copy of the MPL was not distr ... which flavor and url to load.\nlet ev = new CustomEvent('mochitest-load', {'detail': [flavor, url]});\nwin.dispatchEvent(ev);\n","sandbox":"default","line":1716}] GECKO(24713) | [24713, Main Thread] WARNING: Could not get disk status from nsIDiskSpaceWatcher: file /builds/worker/workspace/build/src/uriloader/prefetch/nsOfflineCacheUpdateService.cpp, line 283 GECKO(24713) | 1509015226755 Marionette TRACE 1 <- [1,6,null,{"value":null}] GECKO(24713) | 1509015226820 Marionette TRACE 1 -> [0,7,"setContext",{"value":"content"}] GECKO(24713) | 1509015226821 Marionette TRACE 1 <- [1,7,null,{}] GECKO(24713) | 1509015226860 Marionette TRACE 1 -> [0,8,"deleteSession",{}]

Comment on attachment 8922272 [details] Bug 1411913 - Enable Marionette trace log for mochitest/reftest by default. https://reviewboard.mozilla.org/r/193330/#review198560 please ensure this doesn't break Android or Autophone (check with :bc)

Looks like I missed Android. So I triggered some new jobs in the same try build. Regarding autophone I'm not sure how this is involved here. Is it related to Mochitests and Reftests? Bob, would be great if you could give me some feedback.

Autophone does run some reftest based tests (crash tests and some ogg/webm tests) as well as mochitest based tests, but I don't know how marionette is used underneath the hood. I submitted your try build to autophone for the relevant tests and we should see the results at <https://treeherder.mozilla.org/#/jobs?repo=try&revision=747dba951c77&filter-searchStr=autophone>. I'll loop back when those complete.

We still have some pending but both mochitests and reftests have completed and I haven't seen issues with this. I do see marionette messages in the log cat. All seem well.

Pushed by hskupin@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/fe8fdf1bd074 Enable Marionette trace log for mochitest/reftest by default. r=jmaher