Henrik Skupin [:whimboo][⌚️UTC+1] Reporter
	Description • 7 years ago

Here an example log from try which no longer contains any logging for test start and test end.

https://treeherder.mozilla.org/#/jobs?repo=try&revision=ee37349175ba&selectedJob=107706358

https://public-artifacts.taskcluster.net/eJCSZVsRT0y3W1g0Dhab-A/0/public/test_info//gecko.log

David, you modified / removed this code. Can you please have a look? In the current state it will be impossible to trace down failures. :(

	Henrik Skupin [:whimboo][⌚️UTC+1] Reporter
	Comment 1 • 7 years ago

Wait. I think it's actually not a regression but a change in Andreas' patch for bug 1370863. We should not strip off those messages. Andreas, please check that.

	Andreas Tolfsen ❲:ato❳
	Comment 2 • 7 years ago

(In reply to Henrik Skupin (:whimboo) from comment #1)

> Wait. I think it's actually not a regression but a change in
> Andreas' patch for bug 1370863. We should not strip off those
> messages. Andreas, please check that.

I’m not sure I would consider it a regression as such.  You can look
at the combined logs instead of the gecko.log file directly.

Actually, I consider the fact that we don’t log the test name in the
server a benefit, as it is pointless extra chatter.

	Andreas Tolfsen ❲:ato❳
	Comment 3 • 7 years ago

(In reply to Andreas Tolfsen ‹:ato› from comment #2)

> (In reply to Henrik Skupin (:whimboo) from comment #1)
> 
> > Wait. I think it's actually not a regression but a change in
> > Andreas' patch for bug 1370863. We should not strip off those
> > messages. Andreas, please check that.
> 
> I’m not sure I would consider it a regression as such.  You can look
> at the combined logs instead of the gecko.log file directly.
> 
> Actually, I consider the fact that we don’t log the test name in the
> server a benefit, as it is pointless extra chatter.

Actually you there are no such thing as “the combined logs” for the
Mn job because it does not use structured logging.

Logging the test name on the server for the sole reason that it should
appear in gecko.log seems pointless when the same effect could be
attained by forwarding the Gecko stdout/stderr to a structured log, like
wptrunner does.

Because moving the Marionette harness to structured logging is probably
a sizable piece of work, I’m open to hearing ideas for how we can make
the test names appear in gecko.log _without_ adding explicit server
logging commands back to the server.

	Andreas Tolfsen ❲:ato❳
	Comment 4 • 7 years ago

(In reply to Andreas Tolfsen ‹:ato› from comment #3)

> Because moving the Marionette harness to structured logging is
> probably a sizable piece of work, I’m open to hearing ideas for
> how we can make the test names appear in gecko.log _without_ adding
> explicit server logging commands back to the server.

For example, it might be possible to use something like dump() in an
injected script because I think this is available to due to a preference
set in geckoinstance.py.

It could even be possible to use a no-op in the script, because all we
care about is that it appears in the log, which it will because we log
by default with trace-level.

	Henrik Skupin [:whimboo][⌚️UTC+1] Reporter
	Comment 5 • 7 years ago

I don't mind which way we actually choose to get those lines logged, it just has to get fixed before we stop server logging!

	Andreas Tolfsen ❲:ato❳
	Comment 6 • 7 years ago

The linked logs in comment #0 are from the head of tree with the patches
associated with https://bugzilla.mozilla.org/show_bug.cgi?id=1370863
applied on top.  As such, the lack of logging test names in gecko.log is
a result of those patches and not a problem currently manifesting itself
on HEAD.