Build summary UX

[Erik Joelsson]

On 2014-08-25 02:23, David Holmes wrote:
> On 22/08/2014 1: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.
>
> Can I flag again that getting timings for those parts of the build 
> that are still done in sequence is still very useful. I assume you are 
> not trying to concurrently build langtools and hotspot and jdk(+other 
> source based modules) ? I would like to see timings for hotspot build 
> and for images, profiles etc.
>
Actually, langtools, hotspot and jdk are all built concurrently. There 
are several limitations, like the native libs in jdk have to wait for 
hotspot, java compilation have to wait for the interrim javac. However, 
there is nothing stopping java compilation to start while hotspot is 
being compiled or from compiling java.logging (in jdk) while 
jdk.compiler (in langtools) is being compiled.

 From what I can see, there are very few things happening in sequence, 
or rather there is a complex graph of things happening in sequence, 
concurrently. Sure, I can see what can be done about timings anyway.

/Erik

> Thanks,
> David
>
>> 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.
>>>
>>