843658 - mozharness tests should use RequestSortingBuildFactory

Status: RESOLVED FIXED

(Release Engineering :: Applications: MozharnessCore, defect)

Description

[Phil Ringnalda (:philor)]

https://tbpl.mozilla.org/php/getParsedLog.php?id=19950102&full=1&branch=mozilla-inbound made it noticeable because one of the changes includes a string that tbpl parses as being an error, but the real confusion comes in because that test run isn't on that push, it's on the push before it.

I started to say that I was confident we actually did run on the build we said we did, and that the build we said we ran on was actually on the rev it said it was on, but then it turned out I wasn't, and I wound up running back through the ftp URL we downloaded from, to the build log, to be sure it really did build on f815f2ba316a and not the later push of 6a7390c7b44c.

Now I'm reasonably confident we did build what we said we would, and that we tested what we said we built, and only completely baffled by how sourcestamp doesn't appear to do what it appears to do, unless it's just completely meaningless for test jobs or completely meaningless for the way we use buildbot. In any case, that's not adding value to test logs.

Comment 1

[Aki Sasaki (not active)]

Which sourcestamp are you talking about?

If you're talking about

06:14:39     INFO -     "sourcestamp": {
06:14:39     INFO -         "repository": "", 
06:14:39     INFO -         "hasPatch": false, 
06:14:39     INFO -         "project": "", 
06:14:39     INFO -         "branch": "mozilla-inbound-linux-opt-unittest", 
06:14:39     INFO -         "changes": [
...
06:14:39     INFO -                 "revision": "f815f2ba316a"
06:14:39     INFO -             }
06:14:39     INFO -         ], 
06:14:39     INFO -         "revision": "f815f2ba316a"
06:14:39     INFO -     }

?

This is just us dumping buildprops.json, from buildbot.  This is useful for anyone who wants to see a) internals or b) wants to replicate the test run locally.

This might be confusing because it contains three changes, due to queue collapsing / coalescing.  However, the revision is outside the "changes" list.


If that's what this bug is about, I'm leaning towards WONTFIXing.
If it's not what this bug is about, could you let me know what you're referring to?  (I did a log search for the above two changeset revisions and didn't find anything else).

Comment 2

[Phil Ringnalda (:philor)]

That's what it's about, yes, the fact that the log has a list of changes which include things which are in the build being tested, and other things which are not in the build being tested, as well as the fact that dumping commit messages into the log will result in false positives in tbpl error parsing, because commit messages that include the text of an error are quite common.

I know we're moving toward a log style that puts absolutely every single thing which can possibly be logged into the log just in case someone sometime might want to see it, but this is a classic example of why it's not an unquestionable good thing to log everything.

Comment 3

[Aki Sasaki (not active)]

Happy to remove it once we upload from test jobs, at which point we can put buildprops.json in the upload directory and point to it rather than dumping it the log.

Removing it before than will make it very difficult to run tests in staging, or locally.

Comment 4

[Aki Sasaki (not active)]

I still don't understand why having additional info is a bad thing.
I would guess parsing this and assuming anything that looks like a changeset is critical info would be the bug here.

However, a workaround could be:

a) add a string (kind of like TinderboxPrint, but the opposite, maybe TbplIgnore ?) that, if found, stops all tbpl parsing for that line
b) either prepend TbplIgnore to all of the json, or print the entire json string on one line with a TbplIgnore prepended.  The latter would make the buildprops.json very hard to read for humans, and would make the log extremely wide, but would still allow a human to copy/paste it and use the info later.

Comment 5

[Phil Ringnalda (:philor)]

No, although providing too much information is a bad thing (which I would illustrate by starting this and every comment I make in this bug with a description of when and how I started doing Mozilla work, what I did up to now, what I do now, how I do it, and why, just in case it turned out to be useful to someone, but I don't have time for that), that's not the core of this bug.

The core of this bug is that the log in comment 0 lists a changeset which was not included in the build being tested. That sourcestamp lists three revisions: one is the revision on which the build was done, one is the revision before the one on which the build was done, and one was the revision after the one on which the build was done, a revision which has absolutely nothing whatsoever to do with the test being run or the build on which the test was run.

The information contained in printing that out is "the buildprops for a test contain a completely unused variable whose value includes distracting and meaningless things, things which will confuse people reading them in logs, and cause them to make mistaken arguments about what was actually tested."

Comment 6

[Aki Sasaki (not active)]

Ok, if your complaint is that the changeset wasn't included, that's a bug in the coalescing/scheduling for the job and it's a buildbot bug which I don't know how to deal with.  Mozharness is just printing ScriptFactory's buildprops.json for repeatability.

Comment 7

[Phil Ringnalda (:philor)]

Coalescing and scheduling and sendchange are mostly mysteries to me, but I'm not sure where coalescing comes into it.

It's not the case that we did builds on both f815f2ba316a and 6a7390c7b44c, scheduled reftest-no-accel on both of them, and then only ran it on the build from the later push, 6a7390c7b44c, which is what I understood coalescing to be.

Instead, it's the case that we did builds on both pushes, scheduled tests on both pushes, ran tests on both pushes, but the test run on the build from the earlier push had a (unused by anything in any way) sourcestamp which included the later push.

Comment 8

[Chris AtLee [:catlee]]

Hmm...Could this be bug 555664 rearing its head again? I bet the new mozharness factories aren't using that sorting function we added back then.

Comment 9

[Aki Sasaki (not active)]

Hm, maybe.
So should ScriptFactory inherit RequestSortingBuildFactory ?

Comment 10

[Chris AtLee [:catlee]]

Attachment: ues RequestSortingBuildFactory for ScriptFactory

should Just Work™, right?

Comment 11

[Armen [:armenzg]]

Live in production.