Ed Morley [:emorley] Assignee
	Description • 9 years ago

Buildbot logs are comprised of:
* a header
* many steps, which have "======= FOOO ========" start+end markers

All buildbot non-header log lines currently fall inside these markers, however for the faked up buildbot style logs produced by taskcluster, this is not the case - you can have a start marker for a step, but no corresponding end step.

Unfortunately the log parser currently doesn't know how to handle these log steps, so they aren't visible in the error summary or the log viewer.

	Greg Arndt [:garndt]
	Comment 1 • 9 years ago

There might also be situations where there is no start marker either.  Would there be a way of treating the log as a whole as one step then and fake the start and end?

The situation that could happen is that the task log starts, we check the task payload or scopes to use a feature and that fails, we put something in the log and publish that as the log artifact. However, since this happened outside of the task itself, there is no concept of buildbot step markers within the worker.

	Ed Morley [:emorley] Assignee
	Comment 2 • 9 years ago

I have a fix for this 90% finished, just cleaning it up.

	Ed Morley [:emorley] Assignee
	Comment 3 • 9 years ago

Passing tests (and the resultant text_log_summary is looking good) - just needs some comment/commit message cleanup, and maybe some UI tweaks to handle the dummy steps that have missing duration/start times/end times:
https://github.com/mozilla/treeherder/pull/875

	Ed Morley [:emorley] Assignee
	Comment 4 • 9 years ago

I've split this up into lots of commits to try and make it easier to review. Happy to chat through it on Vidyo if that would help; we could always finish discussing your PR in bug 1182464 at the same time? :-)

	Ed Morley [:emorley] Assignee
	Comment 5 • 9 years ago

The PR now means we support all of:
* There being no step start/end markers at all in the log
* There being step start/end markers in the log, but additional log content falls in-between them
* There being a step at the end of the log, that had a start marker, but no end marker

	Mauro Doglio [:mdoglio]
	Comment 7 • 9 years ago

Comment on attachment 8648766 [details] [review]
Support taskcluster style logs

Wow, the log parser looks much better now. Thanks Ed!

	Treeherder GitHub Bugbot
	Comment 8 • 9 years ago

Commits pushed to master at https://github.com/mozilla/treeherder

https://github.com/mozilla/treeherder/commit/79e7a4ecedd1679b05811347e068460f06ea36d6
Bug 1188444 - Remove check_errors parser option since it's always true

Bug 1060339 made check_errors always be true, since we want to parse all
logs, not just those for failing jobs. As such, we have no use for
check_errors.

https://github.com/mozilla/treeherder/commit/095fc79e628d6b6bf02d6852cf425356db4580c8
Bug 1188444 - Remove support for multiple parsers per ArtifactBuilder

Since we only have one parser per ArtifactBuilder currently, and are not
likely to ever have any more.

https://github.com/mozilla/treeherder/commit/ea546c1536b2e5e777cc820ce6ac6c7a3caf413a
Bug 1188444 - Return earlier when a parser is marked as complete

Once a parser has declared itself complete, there is no need to
increment the line number or trim the line to the max line length.

https://github.com/mozilla/treeherder/commit/1785870769df355fee8dc40a7dd93940bdd912fe
Bug 1188444 - Simplify gathering artifacts in ArtifactBuilderCollection

The artifacts gathering does not need to be run whilst the file handle
is still open, and the talos conditional was unnecessarily verbose.

https://github.com/mozilla/treeherder/commit/4b9035f850cd34340d129f7546d797962e97250f
Bug 1188444 - Rename StepParser regex group from 'result' to 'result_code'

Since the group contains the buildbot result code integer, whereas all
other references to 'result' in the parser are referring to the result
name (eg "success") rather than the code.

https://github.com/mozilla/treeherder/commit/6f29e96bde3cd820bb91f43e82b301231b9b0640
Bug 1188444 - Factor out StepParser code for creating a new step

Since we'll be needing to do so in multiple places in future commits.

https://github.com/mozilla/treeherder/commit/6f37d74e9f88b5ca8e0f296882b5b1909cccdbc7
Bug 1188444 - Factor out the StepParser code for ending a log step

Since we'll be needing to do so in multiple places in future commits.

https://github.com/mozilla/treeherder/commit/59a136bee4a61c9ea7d03a7d5a6173ebd12f5aaa
Bug 1188444 - Use clearer names for tracking StepParser states

https://github.com/mozilla/treeherder/commit/1629de13978c2d7e035da6071874f2ec0d396124
Bug 1188444 - Make parser set_duration() handle missing start/end times

To support Taskcluster logs (where not all content is contained within
valid step marker lines) later commits will add a concept of dummy
unnamed steps, for which we will not have a start or finish time.
StepParser's set_duration() therefore needs to gracefully handle these
properties not being set.

https://github.com/mozilla/treeherder/commit/227ad71ce4135c667b05fe8fb28a163baa8e797e
Bug 1188444 - Add more detailed comments for StepParser

https://github.com/mozilla/treeherder/commit/3276a91fca2f4ee8d256080dbc9fbf3447e32a62
Bug 1188444 - Use a single regex for both start and finish step markers

To save matching against the line twice.

https://github.com/mozilla/treeherder/commit/b076c047f39e600eb8108a7a669532877a1f509f
Bug 1188444 - Handle the common StepParser parser case first

Normal log lines (ie not step marker lines) are the most common. Handle
this case first to improve performance and simplify the later
conditionals.

https://github.com/mozilla/treeherder/commit/11c1dfeaf17bb072882205e2a51fa7bbd902b9c5
Bug 1188444 - Add parser support for log content between step markers

Previously log content was only parsed if it occurred between the
Buildbot step marker lines, since for Buildbot logs, no lines ever exist
outside of them. However for Taskcluster logs (which try to emulate the
Buildbot log format so they can use our parser, since they haven't yet
migrated to submitting error summaries directly to our API) this is not
the case - log lines can fall between steps.

To support this we have to create dummy unnamed steps to hold this
content (since there is no step marker line, we're missing much of the
step information so have to use generic/null values for step name,
start/finish timestamp and step result). We must then skip the buildbot
job metadata header lines, as well as whitespace-only lines to prevent
them from creating unwanted dummy steps.

https://github.com/mozilla/treeherder/commit/f6b58a1f9dad610dcde289f215949fd8e28877f1
Bug 1188444 - Save the last step in a log even if no finish marker seen

Log steps are updated/marked as finished whenever a finish marker is
seen (or the next start marker is encountered). In the case of logs
where the finish marker is missing for the very last step, we previously
did not update the result/finish time/duration/all_errors for that step,
causing any errors within it to be missing from the error summary. This
occurs frequently for Taskcluster infrastructure failures.

Each parser can now specify tasks that should be run at the end of
parsing, by overriding ParserBase.finish_parse(). The StepParser uses
this to save/update the final step if the final finish marker was
missing from the log.

https://github.com/mozilla/treeherder/commit/3d21e5bbb24b4e0ff2ffd47575be654496fa7162
Bug 1188444 - Add tests for parsing steps/errors from Taskcluster logs

This test checks that:
* log content that falls in-between two step markers is captured in a
  dummy unnamed step.
* if the final step is missing the "step finish" marker, we still save/
  update the step and append any step errors to all_errors.

https://github.com/mozilla/treeherder/commit/b00d8caa3bdef5e77a37c1613eeaf23a22a3eb4b
Bug 1188444 - Log viewer: Handle missing duration or start/finish time

Taskcluster logs are often missing step metadata for some of the log
content, so generic placeholder steps have to be created by the log
parser, that can be missing one or more of start time, finish time or
duration.

	Ed Morley [:emorley] Assignee
	Comment 9 • 9 years ago

Before: https://treeherder.allizom.org/logviewer.html#?job_id=10138081&repo=try
After: https://treeherder.allizom.org/logviewer.html#?job_id=10140320&repo=try