1068156 - Mozharness should report timestamps propagated from structured logs

Status: RESOLVED INACTIVE

(Release Engineering :: Applications: MozharnessCore, enhancement)

Description

[Chris Manchester (limited bugmail, email directly)]

Mozharness' logging provides its own timestamps. For things like buffered messages dumped on failure in a mochitest these could be pretty far from when the event that caused the log occurred. We should propagate a timestamp from the structured log to mozharness logging, or possibly report them side by side.

Comment 1

[:Gijs (he/him)]

(In reply to Chris Manchester (:chmanchester) from comment #0)
> Mozharness' logging provides its own timestamps. For things like buffered
> messages dumped on failure in a mochitest these could be pretty far from
> when the event that caused the log occurred. We should propagate a timestamp
> from the structured log to mozharness logging, or possibly report them side
> by side.

Could this be prioritized? This keeps biting me occasionally, e.g. right now looking at https://treeherder.mozilla.org/#/jobs?repo=try&revision=7f5f6d2488ac&selectedJob=20460485 I don't know if this is failing because the test gets "stuck" or because it is busy all the way up to the timeout and then hits it.

Comment 2

[Chris Manchester (limited bugmail, email directly)]

I don't know. To properly integrate this with mozharness would be an extensive undertaking, but I think this is primarily a problem for mochitests. To address the mochitest-specific issue, the harness could annotate log messages with their original timestamps as they're taken out of the log buffer.

Comment 3

[Chris Manchester (limited bugmail, email directly)]

(In reply to Chris Manchester (:chmanchester) from comment #2)
> I don't know. To properly integrate this with mozharness would be an
> extensive undertaking, but I think this is primarily a problem for
> mochitests. To address the mochitest-specific issue, the harness could
> annotate log messages with their original timestamps as they're taken out of
> the log buffer.

For reference, this happens here: https://dxr.mozilla.org/mozilla-central/rev/3461f3cae78495f100a0f7d3d2e0b89292d3ec02/testing/mochitest/runtests.py#272