RFR: 8141564: Convert TraceItables and PrintVtables to Unified Logging

Tue Dec 8 18:46:48 UTC 2015

Hi,

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?
Oh, good catch. Thank you - this is fixed now.
>
> 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.
Great. Thanks again, Karen and Coleen! Will commit the change.
Rachel
> 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