ninja output became less readable on compile failures |
|||||
Issue descriptionSee, e.g.: https://build.chromium.org/p/chromium.linux/builders/Linux%20Builder%20(dbg)(32)/builds/52253/steps/compile/logs/stdio you now have to scroll up a screen or two to get to the actual thing that failed the build. scottmg@ suspects https://github.com/ninja-build/ninja/pull/999 ...
,
Apr 28 2016
That's expected. Ninja now prints commands when they're done, not when they start, and on hitting the error limit ninja just stops scheduling new builds and doesn't interrupt running ones. It's definitely different, but I'm not sure it's a problem. There's already a ton of other junk to scroll past. (I once filled a bug about making that less and we made some progress on that, but then someone added another screenful of stuff at the bottom and I figured nobody but me cares about scrolling up. So this didn't seem so bad to me.) Not sure what to do here... I suggest waiting two weeks and see if you still have problems with this?
,
Apr 28 2016
Aren't you the one who normally complains about every minor degradation like this?
,
Apr 28 2016
I think it's more confusing than all the other junk because it's still part of the ninja run, and it makes it looks like there's no printed error been printed when you get [14293/25496] CXX obj/content/common/common/content_message_generator.o ninja: build stopped: subcommand failed. at the end, especially as -j increases it's less likely a real error will be on screen.
,
Apr 28 2016
Yup. I have at least one data point from the current sheriff today who missed the error because of this.
,
Apr 29 2016
> Aren't you the one who normally complains about every minor degradation like this? Absolutely, as I said I filed a bug about this a while ago ( bug 544330 ), and I dislike this change here too. But as said above, nobody else seemed to mind, so I figured I have to pick my battles and considered this one lost when the send_ts_mon_values stuff showed up at the end of compile output. > I think it's more confusing than all the other junk because it's still part of the ninja run > Yup. I have at least one data point from the current sheriff today who missed the error because of this. Sure, it's different than what we had for a long time, so people are used to that. People who used to scroll to the bottom and then back up will need to adjust. People who cmd-f for "failed: " won't be affected as much. I think this is conceptually not hard to get used to. As said above, I'm personally not super happy about this effect. Like most things, it's a tradeoff between: 1) Build spam is next to the command that produces it (requires printing status when jobs are done) 2) Having build errors at the end of the build output 3) Not interrupting still running commands when the build ends The data I had suggested that several people need 1, nobody but me really cares about 2, and 3 seems strange especially for local builds (where 2 isn't a problem due to overprinting). So I figured that the current behavior is probably the best tradeoff. It's possible that that's wrong, but I'd wait a while to see how annoying this really is. (If there are other alternatives I missed that also allow getting the behavior we want wrt output ordering, I'm glad to hear about them.) In any case, this was a deliberate, intentional change.
,
Apr 29 2016
For " 1) Build spam is next to the command that produces it (requires printing status when jobs are done) " you mean non-error output, right? I guess in that hopefully-unusual case, we could reprint the status line since the spam output is buffered, and that way they could be next to each other? (FWIW, the other junk annoys me too, I didn't see your other bug before but I'd like to move that to a separate step since it doesn't have much to do with 'compile' as far as I'm concerned.)
,
Apr 29 2016
Really I'd like to get rid of compile.py altogether and push more of the logic up into the recipe_modules so that we can get better annotation of the sub-steps like starting goma, links to the logs, etc. Or get compile.py to emit annotations to do that ... +martiniss for thoughts on the latter idea; seems like that should be relatively easy?
,
Apr 29 2016
> you mean non-error output, right? Yes. > hopefully-unusual case In the Android build (which I think is our noisiest build), we have 17 build edges producing 259 lines of noise (https://build.chromium.org/p/chromium/builders/Android/builds/54995/steps/compile/logs/stdio + some vim). 17 build edges is less than I thought, so yes, that's unusual. (Chrome is very good about this, so in other projects it's probably a bit less common.) So yes, printing the status line again in that case is another option. It means that we no longer print every status line exactly once, but maybe that's the better tradeoff -- it seems fairly easy to understand. ccross, would that work for you? (Maybe you suggested that back then and I thought printing lines twice was silly, I don't remember.)
,
Apr 29 2016
This initially bothered me because the buildbot-error extension I had installed -- https://chrome.google.com/webstore/detail/buildbot-error/iehocdgbbocmkdidlbnnfbmbinnahbae -- stopped working a while ago. But it was recently fixed at github. A `git clone https://github.com/martine/buildbot-error` and loading that unpacked at chrome://extensions gave me back buttons on most compile logs. However, it has never worked for Java errors in the Android builders. So it can jump to errors in the linked build in the description, but not the linked build in #c9 (also loading an unpacked extension has downsides, but perhaps evan@ is willing to update the webstore version soon, if he hasn't already)
,
Apr 29 2016
In Android-land, edges producing non-error output is very common, due to a mixture of warnings and tools that print "everything is OK!" type messages. Having the error message scrolled away is super annoying, but its still better than make was (scrolled away and intermixed with other messages). Another alternative is to delay error output until all non-error edges have completed. This is fine for buildbot style builds, since nobody is watching them live. I'd be a little hesitant about enabling it for local builds, because it would mean not seeing the error message until the longest concurrent edge finished, and some edges can be pretty long. I've also seen discussions of printing errors twice, once when they occur and again at the end as a summary, or printing them when they occur but also printing them to an error log file.
,
Apr 29 2016
> Another alternative is to delay error output until all non-error edges have completed. Doing this for buildbot style output sounds like an interesting idea! (I agree it'd suck for local builds since now you have to wait for the 10 minute "building nacl" build step before you see your build error, but on the bots that seems fine.)
,
Apr 29 2016
There is a parallel discussion at https://github.com/ninja-build/ninja/pull/999
,
Apr 29 2016
,
Apr 29 2016
Re: #8, I believe it's possible for compile.py to emit some logs which could show up on the compile step; something like "ninja failure" or whatever. These could be parsed from the ninja output; trivially, you could just look for a line beginning with FAILED <name>, and then capture all that until the next ninja step, although if ninja has a nicer way to expose that data, we should probably use that. We could then put that in a link, ala json.output which we already have on several steps. |
|||||
►
Sign in to add a comment |
|||||
Comment 1 by scottmg@chromium.org
, Apr 28 2016