RFR: 8142976: TraceClassInitialization has been reimplemented with Unified Logging.

Tue Dec 1 16:02:03 UTC 2015

On 12/1/15 10:51 AM, Rachel Protacio wrote:
> Hi,
> On 12/1/2015 6:04 AM, Daniel Fuchs wrote:
>> Hi guys,
>>
>> Is the 'hotspot/test/logging' a new test directory created by
>> this change?
>>
> Appears so. Actually, I've been putting my logging tests in 
> hotspot/test/runtime/logging. Maybe you want to move yours to that 
> folder too, Max? Then we can figure out later if we want to move or 
> rename the folder, but just so they're in the same place for now.

Thanks for noticing this!  I missed that Max's tests should be in 
hotspot/test/runtime/logging rather than hotspot/test/logging.

Max, please change this.

Coleen
>
> Rachel
>> I was wondering whether it could be made clear that these tests
>> are for JVM Unified Logging - not java.util.logging - to help
>> triaging and setting the appropriate component/subcomponent
>> if any of these start failing...
>>
>> best regards,
>>
>> -- daniel
>>
>> On 30/11/15 23:39, Max Ockner wrote:
>>> Here is a new webrev: 
>>> http://cr.openjdk.java.net/~mockner/ulclassinit05/
>>>
>>> 1) The verifier test uses a small snippet to produce verifier errors 
>>> and
>>> a discussion with Harold made it seem like this was the most direct way
>>> to hit most of the error messages.
>>>
>>> 2) In general I do not know where the best home is for the logging
>>> tests. I think we can have a separate discussion about this if people
>>> find it to be a problem.
>>>
>>> 3) You caught a bug in my test! I have addressed this issue.
>>> http://cr.openjdk.java.net/~mockner/ulclassinit05/test/logging/ClassInitializationTest.java.html 
>>>
>>>
>>>
>>> Thanks,
>>> Max
>>>
>>>
>>>
>>> On 11/25/2015 7:51 PM, David Holmes wrote:
>>>> Hi Max,
>>>>
>>>> On 25/11/2015 7:27 AM, Max Ockner wrote:
>>>>> New webrev @ http://cr.openjdk.java.net/~mockner/ulclassinit02/
>>>>> Fixed everything that I said I would fix below.
>>>>
>>>> As a direct conversion of existing logging info this looks fine. The
>>>> overlap with VerboseVerification will have to be dealt with later.
>>>>
>>>> Not sure about the test strategy here in that creating a class that
>>>> fails verification just to check what is logged seem a bit over the
>>>> top and potentially duplicates verifier testing. I wonder if the
>>>> logging test could not in fact run an existing verifier test with
>>>> logging enabled? Which raises the question of whether logging tests
>>>> like this come under logging, or under the subsystem being logged?
>>>>
>>>> In the test EagerInitialization is a develop-only flag, and
>>>> VerboseVerification is diagnostic. It isn't obvious this is being
>>>> handled by the createJavaProcessBuilder calls.
>>>>
>>>> Thanks,
>>>> David
>>>>
>>>>>
>>>>> On 11/24/2015 3:40 PM, Rachel Protacio wrote:
>>>>>> Hi,
>>>>>>
>>>>>> Looks mostly good, just a few comments:
>>>>>>
>>>>>> verifier.cpp
>>>>>> - at line 118 (the first "Verification for" line), it should just be
>>>>>> "print", not "print_cr".
>>>>> Thanks. Fixed, though I wonder how much it matters.
>>>>>> - between lines 194 and 195, I think you need a ResourceMark for the
>>>>>> LogHandle stream.
>>>>> The ResourceMark is defined already, it just isn't part of the diffs
>>>>> because it was already there.
>>>>>> - in the sections starting at lines 179 and 608, I appreciate 
>>>>>> that you
>>>>>> were minimizing the number of lines, but I think it's a bad idea to
>>>>>> have duplicates of the logged strings. Do you think you could define
>>>>>> the strings outside of the logging and pass it to both functions?
>>>>>> Another possible solution would be to make a function to do that 
>>>>>> with
>>>>>> a signature like
>>>>>>     void log_multiple(bool enabled1, outputStream* st1, bool 
>>>>>> enabled2,
>>>>>> outputStream* st2, char* msg);
>>>>>> that could do this in a more formalized manner. A function like this
>>>>>> could be useful for other similar situations as well while we're
>>>>>> converting flags one by one. Or what are your thoughts on that?
>>>>> Two reasons why I don't think we should do that.
>>>>>      (1) We don't want to evaluate format strings unless something is
>>>>> being logged. I guess if you can find a way to avoid doing this while
>>>>> still making the code look nicer then that is OK. I think it would be
>>>>> just as bad to write extra lines of code just to ensure that a short
>>>>> string isn't duplicated.
>>>>>      (2) We do not guarantee that these two messages will always 
>>>>> be the
>>>>> same. A conversation I had with Coleen led me to believe we should 
>>>>> keep
>>>>> the messages separate.
>>>>>> - I think the reordered nesting makes sense.
>>>>>>
>>>>>> ClassInitializationTest.java
>>>>>> - nit: can you move the ");"s from the process builder lines onto 
>>>>>> the
>>>>>> lines before them?
>>>>> OK.
>>>>>>
>>>>>> Thanks,
>>>>>> Rachel
>>>>>>
>>>>>> On 11/24/2015 3:09 PM, Max Ockner wrote:
>>>>>>> Hello,
>>>>>>> Please review my new unified logging code:
>>>>>>>
>>>>>>> Bug: https://bugs.openjdk.java.net/browse/JDK-8142976
>>>>>>> http://cr.openjdk.java.net/~mockner/ulclassinit01/src/share/vm/classfile/verifier.cpp.cdiff.html 
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>> Summary: -XX:+TraceClassInitialization logging has been 
>>>>>>> reimplemented
>>>>>>> using unified logging under the classinit tag.
>>>>>>>
>>>>>>> In the segment with recursive verification (see verifier.cpp) I
>>>>>>> reordered the nested if statement to check 
>>>>>>> was_recursively_verified()
>>>>>>> first. I valued clean code over potentially avoiding a function 
>>>>>>> call
>>>>>>> to was_recursively_verified.
>>>>>>>
>>>>>>> What do you think?
>>>>>>>
>>>>>>> Tested with:
>>>>>>> jtreg hotspot tests
>>>>>>> new jtreg test for classinit tag
>>>>>>> performance testing with refworkload.
>>>>>>>
>>>>>>> Thanks, Max
>>>>>>
>>>>>
>>>
>>
>