Closed
Bug 1454671
Opened 6 years ago
Closed 6 years ago
Combine default log and gecko.log in automation on Android
Categories
(Remote Protocol :: Marionette, defect, P2)
Remote Protocol
Marionette
Tracking
(firefox60 fixed, firefox61 fixed)
RESOLVED
FIXED
mozilla61
People
(Reporter: whimboo, Assigned: whimboo)
References
Details
Attachments
(1 file)
Currently we create two distinct files on Android which make it really hard to correlate the lines between the default log, and gecko.log. To be in sync with desktop we should use `--gecko-log -` to print everything to stdout, and include it in the default log file.
Comment hidden (mozreview-request) |
Assignee | ||
Comment 2•6 years ago
|
||
Hm, we have different levels of logging when we combine that:
> [task 2018-04-17T15:20:11.818Z] 15:20:11 INFO - 04-17 08:20:11.802 I/Gecko ( 744): 1523978411807 Marionette TRACE 19 -> [0,42,"WebDriver:DeleteSession",{}]
> [task 2018-04-17T15:20:11.874Z] 15:20:11 INFO - 04-17 08:20:11.853 I/Gecko ( 744): 1523978411856 Marionette TRACE 19 <- [1,42,null,{}]
> [task 2018-04-17T15:20:11.954Z] 15:20:11 INFO - TEST-PASS | testing/marionette/harness/marionette_harness/tests/unit/test_window_status_chrome.py TestNoSuchWindowContent.test_closed_tab | took 21965ms
All the logging as coming from Gecko get a double formatting applied. James, you have more knowledge in logging than I have, do you have any idea why this could happen? With my patch I just pass `--gecko-log=-` to the `runtests.py` script.
Flags: needinfo?(james)
Comment 3•6 years ago
|
||
I'm not sure I follow. Isn't this double log-level thing normal in mozrunner? I'm probably misunderstanding something.
Flags: needinfo?(james)
Assignee | ||
Comment 4•6 years ago
|
||
Hm, only partly as it seem then. See the following log from a Mn job as run on desktop: https://treeherder.mozilla.org/logviewer.html#?job_id=174275347&repo=autoland&lineNumber=1703-1704 > [task 2018-04-18T08:03:55.527Z] 08:03:55 INFO - 1524038635523 Marionette TRACE 10 <- [1,2,null,{}] > [task 2018-04-18T08:03:55.532Z] 08:03:55 INFO - TEST-PASS | testing/marionette/harness/marionette_harness/tests/unit/test_session.py TestSession.test_new_session_returns_capabilities | took 72ms I wonder what adds the `04-17 08:20:11.802 I/Gecko ( 744): ` on Android.
Assignee | ||
Comment 5•6 years ago
|
||
Oh, it's indeed special-cased for Android. The gecko logging is read via logcat: https://dxr.mozilla.org/mozilla-central/rev/5ded36cb383d3ccafd9b6c231c5120dcdae196a2/testing/marionette/client/marionette_driver/geckoinstance.py#441-449 I think that I don't want to fiddle with this, and leave what I have right now.
Assignee | ||
Updated•6 years ago
|
Attachment #8968544 -
Flags: review?(ato)
Comment 6•6 years ago
|
||
mozreview-review |
Comment on attachment 8968544 [details] Bug 1454671 - Combine default log and gecko.log in automation on Android. https://reviewboard.mozilla.org/r/237228/#review243276
Attachment #8968544 -
Flags: review?(ato) → review+
Pushed by hskupin@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/f3691336c4e4 Combine default log and gecko.log in automation on Android. r=ato
Comment 8•6 years ago
|
||
bugherder |
https://hg.mozilla.org/mozilla-central/rev/f3691336c4e4
Status: ASSIGNED → RESOLVED
Closed: 6 years ago
status-firefox61:
--- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla61
Assignee | ||
Comment 9•6 years ago
|
||
Test-only change which helps in investigating test failures for Mn jobs on Android. Please uplift to mozilla-beta.
status-firefox60:
--- → affected
Whiteboard: [checkin-needed-beta]
Assignee | ||
Comment 10•6 years ago
|
||
Strangely with this change the log level has been decreased from TRACE to INFO, even I didn't touch the `-vv` option. I even cannot see it being used at all on Android before and how we got the trace log:
> /builds/worker/workspace/build/venv/bin/python -u /builds/worker/workspace/build/tests/marionette/harness/marionette_harness/runtests.py --emulator --app=fennec --package=org.mozilla.fennec_aurora --address=localhost:2828 /builds/worker/workspace/build/tests/marionette/tests/testing/marionette/harness/marionette_harness/tests/unit-tests.ini --disable-e10s --gecko-log=/builds/worker/workspace/build/blobber_upload_dir/gecko.log --log-raw=/builds/worker/workspace/build/blobber_upload_dir/marionette_raw.log --log-errorsummary=/builds/worker/workspace/build/blobber_upload_dir/marionette_errorsummary.log --symbols-path=/builds/worker/workspace/build/symbols --startup-timeout=300 --this-chunk 1 --total-chunks 10
I will file a follow-up to officially enable the `-vv` options.
Comment 11•6 years ago
|
||
bugherder uplift |
https://hg.mozilla.org/releases/mozilla-beta/rev/a236a743c796
Whiteboard: [checkin-needed-beta]
Updated•1 year ago
|
Product: Testing → Remote Protocol
You need to log in
before you can comment on or make changes to this bug.
Description
•