RFR: 8141564: Convert TraceItables and PrintVtables to Unified Logging

Rachel Protacio rachel.protacio at oracle.com
Thu Jan 7 17:12:25 UTC 2016 

Great, thanks, Coleen!
Rachel

On 1/6/2016 5:14 PM, Coleen Phillimore wrote:
>
> I remember this change!  This came out very nice.  I agree that 
> @ignore'ing the test until we figure out what's wrong with these tests 
> on Windows is a good thing to do.
>
> Thanks,
> Coleen
>
> On 1/6/16 4:31 PM, Rachel Protacio wrote:
>> Hi,
>>
>> When I tried to commit this change, the ItablesTest was failing on 
>> windows, so I've been trying to get to the bottom of that failure. As 
>> other logging tests have recently proved themselves flaky on windows 
>> as well, it seems to be a deeper issue. As such, I have added the 
>> problem to https://bugs.openjdk.java.net/browse/JDK-8146435 for more 
>> thorough investigation and ignored the ItablesTest for the time being.
>>
>> Here's my new webrev 
>> http://cr.openjdk.java.net/~rprotacio/8141564.03/ which only differs 
>> from the previously approved code via the @ignore line. The code 
>> passes JPRT.
>>
>> Thank you!
>> Rachel
>>
>> On 12/8/2015 12:28 PM, Karen Kinnear wrote:
>>> Rachel,
>>>
>>> Thank you for the updates.
>>> Can you please sanity check one thing for me - the log_tables 
>>> boolean “overrides” appears to
>>> be set correctly in the callers, to mean “yes, this overrides”.
>>> In log_vtables, is it possible the choice of what to print is reversed?
>>>
>>> And perhaps add a check to your tests for example that “NOT 
>>> overriding” catches the right case?
>>>
>>> And yes please on the assertion (I have seen null method bugs in 
>>> development and this code is an early
>>> opportunity to catch that problem).
>>>
>>> I don’t need to see an updated web rev and you don’t need to rerun 
>>> all the tests to fix
>>> the printed string.
>>>
>>> thanks,
>>> Karen
>>>
>>>> On Dec 7, 2015, at 1:37 PM, Coleen Phillimore 
>>>> <coleen.phillimore at oracle.com> wrote:
>>>>
>>>>
>>>>
>>>> On 12/4/15 6:00 PM, Rachel Protacio wrote:
>>>>> Hi, Karen,
>>>>>
>>>>> Thanks for the review. Updated webrev: 
>>>>> http://cr.openjdk.java.net/~rprotacio/8141564.02/
>>>>>
>>>>> Since I never listed the tests I ran even the first time, here are 
>>>>> all of them:
>>>>>
>>>>> * jtreg
>>>>> * JPRT
>>>>> * jck vm, lang, & api/java_lang
>>>>> * rbt quick and non-colo (which now includes defmeth)
>>>>> * invoke*
>>>>>
>>>>> Replies inline.
>>>>>
>>>>> On 12/3/2015 4:56 PM, Karen Kinnear wrote:
>>>>>> Rachel,
>>>>>>
>>>>>> Thank you so much for doing (and redoing) this.
>>>>>>
>>>>>> Couple of questions/comments.
>>>>>>
>>>>>> 1. thank you so much for the transitive overriding test - not 
>>>>>> easy to figure out how to generate one!
>>>>>>
>>>>> Lois walked me through doing that one :)
>>>>>> 2. I missed the list of what you have tested for the first web 
>>>>>> rev and the other tests for this one
>>>>>> I will assume in parallel with the code review you are running 
>>>>>> (without tracing)
>>>>>> vm quick & nocolo, jck vm & lang
>>>>>> defmeth, invoke*
>>>>> Yeah, I totally forgot to email what tests I had run. Sorry about 
>>>>> that! And just learned how to run the jck tests.
>>>>>> There might be value in running your new tests with old tracing 
>>>>>> vs. new and eyeballing the files - to see if they
>>>>>> get essentially the same information.
>>>>>>
>>>>> Yup!
>>>>>> 3. klassVtable.cpp lines 154-156 …
>>>>>> Would it make any sense to do if !klass()->is_array_klass() and 
>>>>>> then just use the log_develop_debug and
>>>>>> not do the extra develop_log_is_enabled check? No big deal.
>>>>>>
>>>>> That makes sense. Changed as suggested.
>>>>>> 4. thank you so much for extracting the print_linkage_flags - I 
>>>>>> should have done that earlier - the information
>>>>>> just grew incrementally.
>>>>>>
>>>>>> 5. klassVtable.cpp line 1047 -
>>>>>>    I think you want an if (m != NULL) here  before dereferencing 
>>>>>> to print_linkage_flags.
>>>>>>    I see we miss that check for other dereferences -feel free to 
>>>>>> add small checks.
>>>>>>    Don’t completely skip logic paragraphs except for printing ones.
>>>>> Well, when I was making my change, we saw that it wouldn't be 
>>>>> possible for m to be null at that point in the code. There are 
>>>>> multiple places above it where it is dereferenced already, not to 
>>>>> mention the fact that it is theoretically initialized to be a 
>>>>> valid method. Would you like to me to add an assert after the 
>>>>> declaration
>>>>>     assert(m != NULL, "methods can never be null");
>>>>> just to be safe?
>>>> In the code here:
>>>> http://cr.openjdk.java.net/~rprotacio/8141564.02/src/share/vm/oops/klassVtable.cpp.udiff.html 
>>>> <http://cr.openjdk.java.net/~rprotacio/8141564.02/src/share/vm/oops/klassVtable.cpp.udiff.html> 
>>>>
>>>>
>>>> Yes, Method* m = method->at(i); can never return NULL or else the 
>>>> whole VM would crash everywhere.  I suspect the logging code here 
>>>> was copied from other instances where 'm' could be null.   This 
>>>> line would crash first:
>>>>
>>>> if (interface_method_needs_itable_index(m)) {
>>>>
>>>>
>>>> Can you clean up this line also to not check for NULL:
>>>>
>>>> const char* sig = (m != NULL) ? m->name_and_sig_as_C_string() : 
>>>> "<NULL>";
>>>>
>>>>
>>>> And add the assert if Karen agrees if it's needed.
>>>>
>>>> The rest of the changes look good.   I don't need to see another 
>>>> revision.
>>>>
>>>> Thanks,
>>>> Coleen
>>>>>>     Thank you for leaving the null check in fill_in_miranda and 
>>>>>> print_method_at.
>>>>>>
>>>>>> 6. log_vtables
>>>>>> The logic in update_inherited_vtables is quite complex.
>>>>>> So the value of allocate_new is not really the right conditional 
>>>>>> to pass in to determine if there
>>>>>> was an override.
>>>>>>    The first paragraph applies both for allocate_new=true and 
>>>>>> allocate_new=false (see !target_method()->is_package_private())
>>>>>>    so they would have allocate_new = true AND be overriding.
>>>>>>
>>>>>> So, perhaps you could add a boolean that says “overrides” or 
>>>>>> “overriding” or whatever : default it to false, and set it to 
>>>>>> true right after the put_method_at line (that iswhere the 
>>>>>> override occurs) and set it to false in the “else” clause?
>>>>>> And pass that argument in to log_vtables ? And remove the 
>>>>>> allocate_new comment from log_vtables as well?
>>>>>>
>>>>> Done, too.
>>>>>
>>>>> Thanks!!
>>>>> Rachel
>>>>>> And the comment in the “else” is not accurate since I put the 
>>>>>> package_private fix in - so removing
>>>>>> it was a good idea.
>>>>>>
>>>>>> many thanks,
>>>>>> Karen
>>>>>>
>>>>>>> On Dec 3, 2015, at 2:23 PM, Rachel Protacio 
>>>>>>> <rachel.protacio at oracle.com <mailto:rachel.protacio at oracle.com> 
>>>>>>> <mailto:rachel.protacio at oracle.com 
>>>>>>> <mailto:rachel.protacio at oracle.com>>> wrote:
>>>>>>>
>>>>>>> Hi,
>>>>>>> Thanks for the comments! Updated 
>>>>>>> webrev:http://cr.openjdk.java.net/~rprotacio/8141564.01/ 
>>>>>>> <http://cr.openjdk.java.net/~rprotacio/8141564.01/><http://cr.openjdk.java.net/%7Erprotacio/8141564.01/ 
>>>>>>> <http://cr.openjdk.java.net/%7Erprotacio/8141564.01/>>(Builds 
>>>>>>> and passes logging jtreg tests.)
>>>>>>>
>>>>>>> Replies inline.
>>>>>>>
>>>>>>> On 12/2/2015 2:34 PM, Coleen Phillimore wrote:
>>>>>>>> Rachel, There are a lot of changes here.  I have several 
>>>>>>>> comments and more suggested cleanup that should be done with 
>>>>>>>> this work.
>>>>>>>>
>>>>>>>> Inhttp://cr.openjdk.java.net/~rprotacio/8141564/src/share/vm/interpreter/linkResolver.cpp.udiff.html 
>>>>>>>> <inhttp://cr.openjdk.java.net/~rprotacio/8141564/src/share/vm/interpreter/linkResolver.cpp.udiff.html><http://cr.openjdk.java.net/%7Erprotacio/8141564/src/share/vm/interpreter/linkResolver.cpp.udiff.html 
>>>>>>>> <http://cr.openjdk.java.net/%7Erprotacio/8141564/src/share/vm/interpreter/linkResolver.cpp.udiff.html>> 
>>>>>>>>
>>>>>>>>
>>>>>>>> I did the original refactoring for trace_method_resolution. 
>>>>>>>> What I think would be better is to make it an internal static 
>>>>>>>> function in linkResolver.cpp and not defined in the 
>>>>>>>> linkResolver.hpp.  Make the call unconditional and pass vtable 
>>>>>>>> index in the last parameter as a default parameter with default 
>>>>>>>> value -1 so the last line in the function is the tty->cr() that 
>>>>>>>> I had outside the function call (that was pretty icky). And put 
>>>>>>>> all the ResourceMark and logstream logic inside the 
>>>>>>>> trace_method_resolution function.  It would never print to tty 
>>>>>>>> so doesn't need an outputStream parameter for other callers.
>>>>>>>>
>>>>>>>> So there would be only the one line 
>>>>>>>> trace_method_resolution(params) in the regular code.
>>>>>>> Thanks for the advice! I still have to call the function from 
>>>>>>> within the conditional because it's develop level only and 
>>>>>>> because I need to specify in the call whether it's for itables 
>>>>>>> or vtables. Otherwise, I've followed your suggestions.
>>>>>>>> http://cr.openjdk.java.net/~rprotacio/8141564/src/share/vm/logging/logTag.hpp.udiff.html 
>>>>>>>> <http://cr.openjdk.java.net/~rprotacio/8141564/src/share/vm/logging/logTag.hpp.udiff.html><http://cr.openjdk.java.net/%7Erprotacio/8141564/src/share/vm/logging/logTag.hpp.udiff.html 
>>>>>>>> <http://cr.openjdk.java.net/%7Erprotacio/8141564/src/share/vm/logging/logTag.hpp.udiff.html>> 
>>>>>>>>
>>>>>>>>
>>>>>>>> Can you put these tags near each other?
>>>>>>>>
>>>>>>> I have them sorted alphabetically, which I think is more useful 
>>>>>>> in the long run.
>>>>>>>> http://cr.openjdk.java.net/~rprotacio/8141564/src/share/vm/oops/klassVtable.cpp.udiff.html 
>>>>>>>> <http://cr.openjdk.java.net/~rprotacio/8141564/src/share/vm/oops/klassVtable.cpp.udiff.html><http://cr.openjdk.java.net/%7Erprotacio/8141564/src/share/vm/oops/klassVtable.cpp.udiff.html 
>>>>>>>> <http://cr.openjdk.java.net/%7Erprotacio/8141564/src/share/vm/oops/klassVtable.cpp.udiff.html>> 
>>>>>>>>
>>>>>>>>
>>>>>>>> One of the things that Markus Gronlund's made me think that we 
>>>>>>>> should do with his cleanup is to stop declaring functions as 
>>>>>>>> members of classes if they don't need external linkage. From 
>>>>>>>> his RFR(L): 8140485: Class load and creation clean up:
>>>>>>>>
>>>>>>>> "Comment: In my opinion, we should attempt to break the pattern 
>>>>>>>> of having private functions declared in header files when the 
>>>>>>>> private function does not need to reach inside "this"."
>>>>>>>>
>>>>>>>> I think the function log_vtables should follow this and be 
>>>>>>>> declared as a static internal function in klassVtable.cpp above 
>>>>>>>> the function where it's used.
>>>>>>>>
>>>>>>>> It's true that you don't see this very much in the hotspot 
>>>>>>>> sources.
>>>>>>>>
>>>>>>>> The refactoring of log_vtables is good and very much appreciated.
>>>>>>>>
>>>>>>>> In each of the logging blocks of code, there are about 6 lines 
>>>>>>>> that are about the same, that print the access flags and 
>>>>>>>> whether it's a default or overpass method. (Karen and Lois 
>>>>>>>> should give you a TOI about what that means!)  Can you add a 
>>>>>>>> method to method.hpp that's something like 
>>>>>>>> print_flags(outputStream* st) and move this printing there, and 
>>>>>>>> make those blocks call your new function?  That would shorten 
>>>>>>>> many of these logging blocks of code and would be nice.  You 
>>>>>>>> could call this from the linkResolver.cpp 
>>>>>>>> trace_method_resolution() function too.
>>>>>>> Done.
>>>>>>>> http://cr.openjdk.java.net/~rprotacio/8141564/test/runtime/logging/p1/A.java.html 
>>>>>>>> <http://cr.openjdk.java.net/~rprotacio/8141564/test/runtime/logging/p1/A.java.html><http://cr.openjdk.java.net/%7Erprotacio/8141564/test/runtime/logging/p1/A.java.html 
>>>>>>>> <http://cr.openjdk.java.net/%7Erprotacio/8141564/test/runtime/logging/p1/A.java.html>> 
>>>>>>>>
>>>>>>>>
>>>>>>>> These classes have missing copyrights.
>>>>>>> Fixed.
>>>>>>> Thanks!
>>>>>>> Rachel
>>>>>>>> Thanks!
>>>>>>>> Coleen
>>>>>>>>
>>>>>>>>
>>>>>>>> On 12/1/15 5:58 PM, Rachel Protacio wrote:
>>>>>>>>> Hi,
>>>>>>>>>
>>>>>>>>> Please review this changeset that converts -XX:+TraceItables 
>>>>>>>>> and -XX:+PrintVtables flags to -Xlog:itables and -Xlog:vtables.
>>>>>>>>>
>>>>>>>>> Open webrev: http://cr.openjdk.java.net/~rprotacio/8141564/ 
>>>>>>>>> <http://cr.openjdk.java.net/~rprotacio/8141564/> 
>>>>>>>>> <http://cr.openjdk.java.net/%7Erprotacio/8141564/ 
>>>>>>>>> <http://cr.openjdk.java.net/%7Erprotacio/8141564/>>
>>>>>>>>> Bug: https://bugs.openjdk.java.net/browse/JDK-8141564 
>>>>>>>>> <https://bugs.openjdk.java.net/browse/JDK-8141564>
>>>>>>>>>
>>>>>>>>> In case it's not clear, the changes in oops/klassVtable.cpp 
>>>>>>>>> around 462-498 are a refactoring of the duplicate code from a 
>>>>>>>>> conditional to a function with a boolean argument.
>>>>>>>>>
>>>>>>>>> Thank you,
>>>>>>>>> Rachel
>>
>

More information about the hotspot-runtime-dev mailing list