Build summary UX

[Erik Joelsson]

On 2014-08-22 01:35, Jonathan Gibbons wrote:
> I like the new finer grained parallelism in general (builds are 
> faster), but I do find the default output more confusing because it is 
> harder to see the warning messages go rushing past.
>
I agree that this is a problem. It can be partially mitigated with using 
gnu make 4.0 and setting --with-output-sync=recurse to configure. We 
have discussed introducing another build mode that would add additional, 
artificial, dependencies that would enforce a stricter order between 
targets or tasks.
> Of course, a good solution would be to work on addressing the warnings 
> so that there are no warning messages being generated when all is well.
>
That would certainly help as well. Another easy fix would be to get the 
hotspot build to tune down a bit on warn logging level.

/Erik
> -- Jon
>
> On 08/21/2014 08:39 AM, Erik Joelsson wrote:
>> Hello Aleksey,
>>
>> As I have tried to explain a couple of times now: The jdk8 build 
>> built each repository in sequence (much like the jdk7 build did). 
>> Because of this it made sense to add messages about which repository 
>> was being built and measure the time each took. The new jdk9 build is 
>> not repository oriented, but instead builds modules. To increase 
>> concurrency, I dropped the sequential, non parallel, execution model 
>> at the top level so there are a larger number of build targets being 
>> built at the same time, based on finer grained dependencies. What I'm 
>> trying to say here is that those Starting/Finished messages simply do 
>> not exist anymore.
>>
>> I can understand people wanting more details on what took how much 
>> time to build, but the timings need to make sense to be useful. If 
>> target A starts executing, and then the last recipe of that target 
>> gets to wait while all of target B gets executed, then the time for 
>> target A will look much longer than it actually was. Perhaps this 
>> information would still be useful, I doubt it, but could perhaps be 
>> swayed by good arguments. We would also need to figure out a proper 
>> granularity for grouping timings, and if it should be grouped by 
>> modules or by tasks.
>>
>> I think that verbosity at the default warn level is correct in not 
>> printing more than it currently does. If something was recompiled, 
>> you would see messages about it. I can't help but wonder why you need 
>> more text to say "nothing happened"? This sounds like an issue with 
>> not trusting the build (which I can identify with, it's new so is 
>> likely to be buggy). When setting LOG=info, I agree that there should 
>> be more status messages about which targets were actually considered. 
>> The step up to LOG=debug prints far too much to be useful in that 
>> regard. Again, we need to think about the granularity of the targets 
>> we would want to print info about here, and if it should be module or 
>> task oriented.
>>
>> /Erik
>>
>> On 2014-08-21 17:02, Aleksey Shipilev wrote:
>>> Hi,
>>>
>>> The recent update of jdk9/jdk9 build scripts had significantly
>>> deteriorated the usability of the build summary. This what was printed
>>> before:
>>>
>>> ------- 8< 
>>> -------------------------------------------------------------
>>>
>>> Building OpenJDK for target 'default' in configuration
>>> 'linux-x86_64-normal-server-release'
>>>
>>> ## Starting langtools
>>> ## Finished langtools (build time 00:00:00)
>>>
>>> ## Starting hotspot
>>> ## Finished hotspot (build time 00:00:00)
>>>
>>> ## Starting corba
>>> ## Finished corba (build time 00:00:00)
>>>
>>> ## Starting jaxp
>>> ## Finished jaxp (build time 00:00:01)
>>>
>>> ## Starting jaxws
>>> ## Finished jaxws (build time 00:00:00)
>>>
>>> ## Starting jdk
>>> ## Finished jdk (build time 00:00:01)
>>>
>>> ----- Build times -------
>>> Start 2014-08-21 18:35:48
>>> End   2014-08-21 18:35:50
>>> 00:00:00 corba
>>> 00:00:00 hotspot
>>> 00:00:01 jaxp
>>> 00:00:00 jaxws
>>> 00:00:01 jdk
>>> 00:00:00 langtools
>>> 00:00:02 TOTAL
>>> -------------------------
>>> Finished building OpenJDK for target 'default'
>>>
>>> ------- 8< 
>>> -------------------------------------------------------------
>>>
>>> ...and this is what's printed now:
>>>
>>> ------- 8< 
>>> -------------------------------------------------------------
>>>
>>> Running make as '/usr/bin/make -s VERBOSE=-s LOG_LEVEL=warn -R -I
>>> /home/shade/trunks/mb-try/make/common -s
>>> SPEC=/home/shade/trunks/mb-try//build/linux-x86_64-normal-server-release/spec.gmk' 
>>>
>>> Building OpenJDK for target 'default' in configuration
>>> 'linux-x86_64-normal-server-release'
>>>
>>> ----- Build times -------
>>> Start 2014-08-21 18:59:07
>>> End   2014-08-21 18:59:09
>>>
>>> 00:00:02 TOTAL
>>> -------------------------
>>>
>>> Finished building OpenJDK for target 'default'
>>>
>>> ------- 8< 
>>> -------------------------------------------------------------
>>>
>>> I have no idea whether the modules of interest were actually built, and
>>> this disables me from checking whether the build system picked up my
>>> previous changes. Can we please have the "Starting"/"Finishing" and the
>>> verbose summary back?
>>>
>>> Thanks,
>>> -Aleksey.
>>>
>>
>