RFR(S) 8204267 - Generate comments in -XX:+PrintInterpreter to link to source code

[Ioi Lam]

Hi Coleen,


Thanks for the review. I have updated the patch according to your 
comments. Here's the diff from the last webrev:

http://ioilinux.us.oracle.com/webrev/jdk12.open/8204267-print-interpreter-comments.v002.delta/


On 7/11/18 10:44 AM, coleen.phillimore at oracle.com wrote:
>
> http://cr.openjdk.java.net/~iklam/jdk12/8204267-print-interpreter-comments.v001/src/hotspot/share/compiler/disassembler.cpp.udiff.html 
>
>
> + Link *link = new (ResourceObj::C_HEAP, mtInternal) Link(file, line);
>
>
> Can you use mtCode here?  Why not make Link inherit from 
> CHeapObj<mtCode> then just say new?
>
Fixed.

> + if (_cached_src_lines != NULL) {
> + for (int i=0; i<_cached_src_lines->length(); i++) {
> + os::free((void*)_cached_src_lines->at(i));
> + }
> + _cached_src_lines->clear();
> + } else {
> + _cached_src_lines = new (ResourceObj::C_HEAP, 
> mtInternal)GrowableArray<const char*>(0, true);
> + }
>
>
> Growable Array has a delete operator that will clear_and_deallocate 
> all the elements and the array itself (which I don't think this does).

We have this function:

template<class E> void GrowableArray<E>::clear_and_deallocate() {
     assert(on_C_heap(),
            "clear_and_deallocate should only be called when on C heap");
     clear();
     if (_data != NULL) {
       for (int i = 0; i < _max; i++) _data[i].~E();
       free_C_heap(_data);
       _data = NULL;
     }
}

My <E> type is currently <const char*>. To take advantage of 
clear_and_deallocate I have to wrap the const char* into something like this

struct {
    const char* _line;
    LineInfo(const char* l) : _line(l) {}
    ~LineInfo() {os::free(_line);}
} LineInfo;

but this adds a tone of boiler plate code and still won't work, because 
GrowableArray<E>::grow will call ~E(), which messes things up.

So I'll just keep the existing code and won't bother.

>   But it looks like you're reusing _cached_src_lines for later 
> iterations.  It's an odd usage.  But you can't resource allocate this?
>

I am worried that we may have be under nested ResourceMarks, and the 
allocated _cached_src_lines may be freed unexpectedly.

> 302 if (_cached_src == NULL || strcmp(_cached_src, file) != 0) {
>
>
> The indentation is wrong, and this would be a nice place for a comment 
> at line 301.
>
I fixed indent and added this comment

         // _cached_src_lines is a single cache of the lines of a source 
file, and we refill this cache
         // every time we need to print a line from a different source 
file. It's not the fastest,
         // but seems bearable.


> http://cr.openjdk.java.net/~iklam/jdk12/8204267-print-interpreter-comments.v001/src/hotspot/share/compiler/disassembler.hpp.udiff.html 
>
>
> I wonder if checking PrintInterpreter for each macro assembler line 
> will slow down generating the interpreter for the normal case. Maybe 
> there is an EnableIf<PrintInterpreter> sort of template trick to make 
> it evaporate?
>
> PrintInterpreter is an option in product mode.
>
I am hoping that __ is slow enough, so doing an extra load-and-test 
won't slow down it too much. I benchmarked "java -Xint -version" and the 
slow down is 0.11% after 1000 runs, so I guess it's acceptable.

If people start complaining, we can do this later ....

   template<class T> inline static T* hook(const char* file, int line, 
T* masm) {
#ifdef ASSERT
     if (PrintInterpreter) {
       _hook(file, line, masm);
     }
#endif
     return masm;
   }

> http://cr.openjdk.java.net/~iklam/jdk12/8204267-print-interpreter-comments.v001/sample.txt 
>
>
>   0x00007f72c498d527: callq  0x00007f72c498d531             ;; 126:   
> __ call_VM(noreg,
>
>
> Should this say what it's calling?
>
>   0x00007f72c498d572: callq  0x00007f72e3df9ea0 = 
> InterpreterRuntime::slow_signature_handler(JavaThread*, Method*, 
> long*, long*)
>
>
> But this says what it's calling but I don't think this is part of your 
> change (or is it?)
>
Yes. When you see a call_VM, you have to scan down and see what it's 
actually calling. It's no ideal, but I don't know how to improve it 
without writing a lot of code ... which I want to avoid.

Thanks
- Ioi

> That's all the comments I have. I wish you did this many years ago also!
> Thanks,
> Coleen
>
> On 7/6/18 5:33 PM, Ioi Lam wrote:
>> Hi,
>>
>>
>> Since there's interest for this patch, I've finished it for the x86 
>> port:
>>
>> https://bugs.openjdk.java.net/browse/JDK-8204267
>> http://cr.openjdk.java.net/~iklam/jdk12/8204267-print-interpreter-comments.v001/ 
>>
>>
>> You can see a sample at
>>
>> http://cr.openjdk.java.net/~iklam/jdk12/8204267-print-interpreter-comments.v001/sample.txt 
>>
>>
>> Incorporating this to other CPU ports should be pretty straight 
>> forward. You just
>> need to do something like:
>>
>> -#define __ _masm->
>> +#define __ Disassembler::hook<MacroAssembler>(__FILE__, __LINE__, 
>> _masm)->
>>
>> I'll leave it to other CPU port maintainers.
>>
>> I am testing with hs_tier{1,2}.
>>
>> Thanks
>>
>> - Ioi
>>
>>
>> On 6/4/18 12:12 AM, Ioi Lam wrote:
>>> Hi Folks,
>>>
>>> I've found it very hard to understand the assembler code printed by 
>>> -XX:+PrintInterpreter. Since the C++ source code that generates the 
>>> interpreter is fairly well documented, it might be a good idea to 
>>> print out the source code along with the assembler code.
>>>
>>> I've done a quick proof-of-concept by hacking the "__" macro that's 
>>> used throughout the CPU-dependent sources.
>>>
>>> Please let me know if you think this is worth doing. If so, I will 
>>> try to finish it up and post a real RFR.
>>>
>>> Thanks
>>> - Ioi
>>>
>>>
>>> https://bugs.openjdk.java.net/browse/JDK-8204267
>>> http://cr.openjdk.java.net/~iklam/misc/8204267-print-interpreter-comments.v00 
>>>
>>> http://cr.openjdk.java.net/~iklam/misc/8204267-print-interpreter-comments.v00/hs_interp.S 
>>>
>>>
>>> Here are some examples (if the mailer screws up the long lines, 
>>> please click the above link):
>>>
>>> ifeq  153 ifeq  [0x00007f830cc93da0, 0x00007f830cc941c0] 1056 bytes
>>>
>>> mov    (%rsp),%eax
>>> add    $0x8,%rsp
>>> test   %eax,%eax           ;; 2353:   __ testl(rax, rax);
>>> jne    0x00007f830cc94177  ;; 2354:   __ jcc(j_not(cc), not_taken);
>>> mov    -0x18(%rbp),%rcx    ;; 2120:   __ get_method(rcx); // rcx 
>>> holds method
>>> mov    -0x28(%rbp),%rax    ;; 2121:   __ profile_taken_branch(rax, 
>>> rbx); // rax holds updated MDP, rbx
>>> test   %rax,%rax
>>> je     0x00007f830cc93dd8
>>> mov    0x8(%rax),%rbx
>>> add    $0x1,%rbx
>>> sbb    $0x0,%rbx
>>> mov    %rbx,0x8(%rax)
>>> add    0x10(%rax),%rax
>>> mov    %rax,-0x28(%rbp)
>>> movswl 0x1(%r13),%edx      ;; 2133:     __ load_signed_short(rdx, 
>>> at_bcp(1));
>>> bswap  %edx                ;; 2135:   __ bswapl(rdx);
>>> sar    $0x10,%edx          ;; 2138:     __ sarl(rdx, 16);
>>> movslq %edx,%rdx           ;; 2140:   LP64_ONLY(__ movl2ptr(rdx, rdx));
>>> add    %rdx,%r13           ;; 2164:   __ addptr(rbcp, rdx);
>>> test   %edx,%edx           ;; 2179:     __ testl(rdx, 
>>> rdx);             // check if forward or backward branch
>>> jns    0x00007f830cc93eec  ;; 2180:     __ jcc(Assembler::positive, 
>>> dispatch); // count only if backward branch
>>> mov    0x18(%rcx),%rax     ;; 2184:     __ movptr(rax, Address(rcx, 
>>> Method::method_counters_offset()));
>>> test   %rax,%rax           ;; 2185:     __ testptr(rax, rax);
>>> jne    0x00007f830cc93ead  ;; 2186:     __ jcc(Assembler::notZero, 
>>> has_counters);
>>> push   %rdx                ;; 2187:     __ push(rdx);
>>> push   %rcx                ;; 2188:     __ push(rcx);
>>> callq  0x00007f830cc93e09  ;; 2189:     __ call_VM(noreg, 
>>> CAST_FROM_FN_PTR(address, InterpreterRuntime::build_method_counters),
>>>
>>
>