1294525 - TinderboxPrint lines are being cut off

Status: RESOLVED FIXED

(Tree Management :: Treeherder, defect, P3)

Description

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

Here is an example:
https://treeherder.mozilla.org/#/jobs?repo=comm-central&selectedJob=43665

Notice the "moz:" value. It should read "moz:720b5d2c84d5". The TinderboxPrint line in the log is:

TinderboxPrint:<a href=https://hg.mozilla.org/mozilla-central/rev/720b5d2c84d5 title='Built from mozilla-central revision 720b5d2c84d5'>moz:720b5d2c84d5</a>

This seems to have regressed two days ago.

Comment 1

[Jonathan French (:jfrench)]

As a contributor I was just poking around based on that timing, perhaps it's related to work in https://github.com/mozilla/treeherder/pull/1666 since it was recently deployed to production. Adding camd for reference. :)

Comment 2

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

Yes, thanks, that does seem to be the problem! The length in that changeset is limited to 125 characters, and that's exactly how many we're getting.

Could we perhaps raise the max to at least 150? That would help with comm-central.

Comment 3

[Jonathan French (:jfrench)]

Cool, I'll let Cameron and Ed decide the best solution for this scenario, or touch base with you on Monday. In case there's something preferable than just a higher limit.

Comment 4

[Cameron Dawson [:camd]]

Talked with emorley in channel and we really don't want to support longer field values.  But what we can do is a better job parsing those urls so they show up in the Job Details panel correctly.

This is where the printlines are generated:
https://dxr.mozilla.org/build-central/source/tools/buildfarm/utils/printbuildrev.py#31-36

And here's the parser we should modify in Treeherder to strip out the parts of the URL and place the ``title``, ``value`` and ``url`` into the right fields here:
https://github.com/mozilla/treeherder/blob/master/treeherder/log_parser/parsers.py#L346-L353

Comment 5

[Cameron Dawson [:camd]]

Some TinderboxPrint examples: 
https://dxr.mozilla.org/mozilla-central/search?q=TinderboxPrint&redirect=false 
https://dxr.mozilla.org/build-central/search?q=TinderboxPrint

Comment 6

[Jonathan French (:jfrench)]

I made an initial attempt to see if I could strip out the pieces. However to see the change in local vagrant ingestion has proven challenging; either ingesting a single push from builds-4h for comm-central (none exist atm), or trying to encourage vagrant to ingest jobs from comm-central in general. I haven't found any other jobs other than comm-central which display the bug. If there are any examples on inbound, or, if I should do something in vagrant other than browse to comm-central and wait for ingestion, let me know.

My local vagrant is happily ingesting jobs, seemingly from inbound. I'll check in on irc also when I get time.

Comment 7

[Jonathan French (:jfrench)]

Attachment: initialFix_screen_grab

Ok, I think I have my local comm-central ingestion sorted. Bill, is this the general appearance in the Details panel that you would expect? I didn't see the "before" state so I defer to you.

Comment 8

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

Comment on attachment 8789585 [details]
initialFix_screen_grab

This looks nice to me.

The reason I filed this is that I have an automated script that parses this line and it broke when the change went in. I would like to see the actual TinderboxPrint line to make sure my regular expression still works before this goes in.

Comment 9

[Jonathan French (:jfrench)]

(In reply to Bill McCloskey (:billm) from comment #8)
> Comment on attachment 8789585 [details]
> initialFix_screen_grab
> 
> I would like to see the actual TinderboxPrint line to make sure my regular expression still works before
> this goes in.

Here's the original log line from the job in that particular screen grab:

TinderboxPrint:<a href=https://hg.mozilla.org/mozilla-central/rev/1a5b53a831e5 title='Built from mozilla-central revision 1a5b53a831e5'>moz:1a5b53a831e5</a>

and here's that actual job on production (with truncated details line in the UI)
https://treeherder.mozilla.org/#/jobs?repo=comm-central&fromchange=4c8dfbee8681cce17a39cdd046cb0b341382814a&selectedJob=44943

Comment 10

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

OK, thanks. That'll work.

Comment 11

[GitHub Autolander Bot]

Attachment: [treeherder] tojon:split-logparser-url > mozilla:master

Comment 12

[Jonathan French (:jfrench)]

Comment on attachment 8790930 [details] [review]
[treeherder] tojon:split-logparser-url > mozilla:master

Ok, here's an initial PR for review at your leisure :camd :)

Comment 13

[Jonathan French (:jfrench)]

Comment on attachment 8790930 [details] [review]
[treeherder] tojon:split-logparser-url > mozilla:master

Have a CI error to fix, pulling review flag.

Comment 14

[Jonathan French (:jfrench)]

It appears some live tinderboxprint lines we need to support (eg. comment #0) have title=', where other lines (eg. treeherder sample data) have title=", which I think is the reason for the CI failure. I can repro locally. Strange since printbuildrev.py in comment #4 uses only double quotes, I thought everything would be one way. I think I need to make the slice match a bit more robust.

Comment 15

[Jonathan French (:jfrench)]

Comment on attachment 8790930 [details] [review]
[treeherder] tojon:split-logparser-url > mozilla:master

Ok, I've updated the way I separate out 'title' so it's independent of markup quoting style, and I updated the affected jobartifact.json test files in tests/sample_data/logs. It now passes CI.

I purged/re-ingested locally the August 28th builds-4h containing a comm-central push (http://builddata.pub.build.mozilla.org/buildjson/builds-2016-08-28.js.gz, 2540c39cc958) and it's still splitting out the job details artifact correctly in the UI with no console errors. I also re-ingested regular inbound with celery and it seems fine also.

Only thing I noticed with the latter, is inbound success jobs all show their log parsing state as in progress locally in my UI. Failures are successfully parsed. Maybe we now prioritize the log parsing, or perhaps my not running concurrency so my DB doesn't constantly time out, just slows the parsing of inbound. My earlier Aug 28th push was all success jobs though, and it parsed them fine.

:camd If this PR is actually useful, I would like to squash before landing, unless you feel otherwise. :)

Comment 16

[Cameron Dawson [:camd]]

Hey Jon, sorry I didn't get to this today, but I'll review early tomorrow.  Thanks for the PR! :)

Comment 17

[Cameron Dawson [:camd]]

Comment on attachment 8790930 [details] [review]
[treeherder] tojon:split-logparser-url > mozilla:master

Clearing the review flag for now.  Would you be up for using that HTML parsing class instead of splits?  Thanks!!

Comment 18

[Jonathan French (:jfrench)]

Comment on attachment 8790930 [details] [review]
[treeherder] tojon:split-logparser-url > mozilla:master

Ok, I think it's ready for another look. I've added comments in the PR.

Comment 19

[Cameron Dawson [:camd]]

Comment on attachment 8790930 [details] [review]
[treeherder] tojon:split-logparser-url > mozilla:master

Looks good!  Should be cool.  :)

Comment 20

[Jonathan French (:jfrench)]

Ok, I've squashed and rebased, so we're ready to go.

Comment 21

[Jonathan French (:jfrench)]

Adding a need-info reminder for autoland, per camd's request in channel.

Comment 22

[Treeherder GitHub Bugbot]

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

https://github.com/mozilla/treeherder/commit/94b44451ac916c946dfe69fbed133037d7b045b7
Bug 1294525 - Break out Tinderbox fields in log parser (#1848)

Comment 23

[Cameron Dawson [:camd]]

Thanks again, Jon.  Merged to master.