RFR (M) 8213003: Remove more assignments in ifs for vmTestbase/[a-s]
JC Beyler
jcbeyler at google.com
Thu Nov 1 20:03:10 UTC 2018
Hi Chris,
Thanks for going over my email :)
So I skipped over the tracing part for clarity and striving to be brief.
But if we can accept:
debugeeClass = jni->FindClass(DEBUGEE_CLASS_NAME,
TRACE_JNI_CALL);
and use a mechanism such as
debugeeClass = jni->FindClass(DEBUGEE_CLASS_NAME,
TRACE_JNI_CALL);
it is actually easy to print out things like:
>> JNI FindClass with the following parameters from
test/hotspot/jtreg/vmTestbase/nsk/jvmti/SetTag/settag001/settag001.cpp:69:
>> "nsk/jvmti/SetTag/settag001"
...
<< JNI FindClass from
test/hotspot/jtreg/vmTestbase/nsk/jvmti/SetTag/settag001/settag001.cpp:69:
Before the actual call to the method, allowing to have the full
NSK_*_VERIFY system. The hardest question is do we accept to go from:
if (!NSK_JNI_VERIFY(jni, (debugeeClass =
jni->FindClass(DEBUGEE_CLASS_NAME)) != NULL)) {
nsk_jvmti_setFailStatus();
return;
}
to:
#define TRACE_JNI_CALL __LINE__, __FILE__
...
ExceptionCheckingJniEnvPtr jni_wrapper(jni);
...
debugeeClass = jni->FindClass(DEBUGEE_CLASS_NAME,
TRACE_JNI_CALL);
What I would do if this is accepted is postpone the assignment extraction
and move the code to migrating the NSK*VERIFY macros to using the exception
wrapper and then moving the assignments will be easier and a nop from a
debug printout point of view.
Thanks,
Jc
On Thu, Nov 1, 2018 at 12:01 PM Chris Plummer <chris.plummer at oracle.com>
wrote:
> On 11/1/18 9:53 AM, JC Beyler wrote:
>
> Hi all,
>
> Sorry this is a bit of a long reply to myself but I've tried to see what
> we have, what we could have, is it better. Here is my analysis of how to
> keep the information we currently provide when a test fails at a NSK*VERIFY
> point and how we could maintain the level of detail (and even expand) while
> still cleaning up the macros/assignments.
>
> I've been looking at this and am going to go through examples to provide
> alternatives :). For this, I'll use the SetTag test and will be forcing a
> failure on the line:
>
> if (!NSK_JNI_VERIFY(jni, (debugeeClass =
> jni->FindClass(DEBUGEE_CLASS_NAME)) != NULL)) {
> nsk_jvmti_setFailStatus();
> return;
> }
>
> Without a change and with the verbose system set up for the test, the
> error message is:
>
> The following fake exception stacktrace is for failuire analysis.
> nsk.share.Fake_Exception_for_RULE_Creation: (settag001.cpp:65)
> (debugeeClass = jni->FindClass(DEBUGEE_CLASS_NAME)) != NULL
> at nsk_lvcomplain(nsk_tools.cpp:172)
> # ERROR: settag001.cpp, 65: (debugeeClass =
> jni->FindClass(DEBUGEE_CLASS_NAME)) != NULL
> # verified JNI assertion is FALSE
> # ERROR: agent_tools.cpp, 282: Debuggee status sync aborted because agent
> thread has finished
>
> I think you are missing something here. This appears to be the output from
> nsk_jni_lverify() when the condition indicates failure. However, I don't
> see the verbose tracing from nsk_ltrace(), which I think is more relevant
> because that's were you are likely to want to see the actual JNI or JVMTI
> call being made.
>
> #define NSK_JNI_VERIFY(jni, action) \
> (nsk_ltrace(NSK_TRACE_BEFORE,__FILE__,__LINE__,"%s\n",#action), \
> nsk_jni_lverify(NSK_TRUE,jni,action,__FILE__,__LINE__,"%s\n",#action))
>
>
> (Note the typo for failuire, I created JDK-8213246 to fix it).
>
> With my proposed change to remove the assignment, the code becomes:
> debugeeClass = jni->FindClass(DEBUGEE_CLASS_NAME);
> if (!NSK_JNI_VERIFY(jni, debuggeeClass != NULL)) {
> nsk_jvmti_setFailStatus();
> return;
> }
>
> The following fake exception stacktrace is for failuire analysis.
> nsk.share.Fake_Exception_for_RULE_Creation: (settag001.cpp:66)
> debugeeClass != NULL
> at nsk_lvcomplain(nsk_tools.cpp:172)
> # ERROR: settag001.cpp, 66: debugeeClass != NULL
> # verified JNI assertion is FALSE
> # ERROR: agent_tools.cpp, 282: Debuggee status sync aborted because agent
> thread has finished
> STDERR:
>
> In this case, we do lose that the failure seems to have happened in
> FindClass, we need to look at the code.
>
> I think losing the actual call info in the trace for failures is fine. All
> we really need is the line number info. I don't think anyone is going to be
> trying to debug the root cause based on trace message, which is no
> different than the source that can be viewed given the line number info.
>
> But back to my point above, if you enable tracing, seeing which JVMTI and
> JNI calls are being made in the trace output could be useful. You could
> scan all logs and see what JVMTI and JNI calls were made, and how often.
> Possibly useful for coverage analysis of the tests. However, I don't
> consider this critical, and am not opposed to losing it in order to make
> the code more readable.
>
> In any case, a solution would be to have a wrapper script like
> NSK_JNI_VERIFY, but just for the purpose of tracing, not error checking:
>
> debugeeClass =
> NSK_JNI_WRAPPER(jni->FindClass(DEBUGEE_CLASS_NAME));
> if (!NSK_JNI_VERIFY(jni, debuggeeClass != NULL)) {
> nsk_jvmti_setFailStatus();
> return;
> }
>
> And NSK_JNI_WRAPPER would just to the tracing and execute the passed in
> action.
>
>
> However, the ExceptionJNIWrapper that I implemented a little while ago
> will provide this information:
> FATAL ERROR in native method: FindClass : Return is NULL
>
> As I mentioned above, I don't consider the API that failed to be all that
> useful in error output as long as we have the line number info. At best
> maybe it helps identify two separate failures as being the same if the line
> numbers were to change.
>
>
> which is not sufficient to really figure out where this happened and what
> were the arguments. But we could extend the ExceptionJNIWrapper to have
> each JNI call
> allow two optional arguments and do this:
>
> ...
> // For tracing purposes.
> #define TRACE_JNI_CALL __LINE__, __FILE__
> ...
>
> ExceptionCheckingJniEnvPtr jni_wrapper(jni);
> ...
> debugeeClass = jni->FindClass(DEBUGEE_CLASS_NAME,
> TRACE_JNI_CALL);
>
> Where now the JNI call looks "almost" like non-test code and a real JNI
> call but with just that optional macro added. Then the
> ExceptionCheckingJniEnvPtr can be modified to print out:
>
> FATAL ERROR in native method: JNI method FindClass : Return is NULL from
> test/hotspot/jtreg/vmTestbase/nsk/jvmti/SetTag/settag001/settag001.cpp:69
>
> Which now contains all the same information except what the line looks
> like. I'm not sure that is useful, instead, if we wanted to go one step
> further, we could add prints to all parameters that are passed in the JNI
> methods via the wrapper, which would
> then look like something like:
>
> JNI method FindClass was called from
> test/hotspot/jtreg/vmTestbase/nsk/jvmti/SetTag/settag001/settag001.cpp:69
> with these parameters:
> "nsk/jvmti/SetTag/settag001"
> FATAL ERROR in native method: JNI method FindClass : Return is NULL from
> test/hotspot/jtreg/vmTestbase/nsk/jvmti/SetTag/settag001/settag001.cpp:69
>
> I'm not familiar with you ExceptionJNIWrapper changes. The error output
> above looks fine, but as I mentioned earlier, I'm ok with just the source
> line number info.
>
> thanks,
>
> Chris
>
>
> Let me know what you think.
>
> Thanks,
> Jc
>
>
> On Wed, Oct 31, 2018 at 1:54 PM JC Beyler <jcbeyler at google.com> wrote:
>
>> @Claes: you are right, I did not do a grep such as "if.* =$"; by adding
>> the space instead of the $, I missed a few :)
>>
>> I've been meaning to ask if we could deprecate these anyway. Are these
>> really being used? And if so, are we saying everything here is useful:
>> - Line/File + JNI call?
>>
>> I ask because I'd like to deprecate the NSK_VERIFY macros but the
>> LINE/FILE is a bit annoying to deprecate.
>>
>> I'd rather be able to remove them entirely but we could do an alternative
>> and migrate the NSK_VERIFY to:
>>
>> testedFieldID = jni->GetStaticFieldID(testedClass, FIELD_NAME,
>> FIELD_SIGNATURE);
>> if (!testedFieldID) {
>>
>> where the print out of the jni method and argument values can still be
>> done in the JNI wrapper I added (ExceptionCheckingJniEnv.cpp) so we'd have
>> the printout of the calls but not the line and filename from where the call
>> was done.
>>
>> If lines and filenames are really important, then we could do something
>> like:
>> testedFieldID = NSK_TRACE(jni->GetStaticFieldID(testedClass,
>> FIELD_NAME, FIELD_SIGNATURE));
>> if (!testedFieldID) {
>>
>> Which would add a line for which line/file is doing the JNI call. The
>> verify part can go into the wrapper I was talking about
>> (ExceptionCheckingJniEnv.cpp).
>>
>> Thanks,
>> Jc
>>
>>
>> On Wed, Oct 31, 2018 at 11:52 AM Chris Plummer <chris.plummer at oracle.com>
>> wrote:
>>
>>> On 10/31/18 11:30 AM, serguei.spitsyn at oracle.com wrote:
>>> > It prints the FILE/LINE which is enough to identify the error point.
>>> Yes, but it also prints the JNI calls.
>>> > But I agree that doing the assignments within the NSK_JNI_VERIFY was
>>> > intentional as it gives more context.
>>> > From the other hand it make the code ugly and less readable.
>>> > Not sure, what direction is better to go.
>>> Agreed. Somewhat of a tossup now as to whether or not this change should
>>> be done. I'm fine either way.
>>>
>>> Chris
>>> >
>>> > Thanks,
>>> > Serguei
>>> >
>>> >
>>> > On 10/31/18 11:21, Chris Plummer wrote:
>>> >> Hi Claes,
>>> >>
>>> >> It's good that you brought this up. NSK_JNI_VERIFY is always "on",
>>> >> but moving the assignment outside of it does slightly change the
>>> >> behavior of the macro (although the code still executes "correctly"):
>>> >>
>>> >> /**
>>> >> * Execute action with JNI call, check result for true and
>>> >> * pending exception and complain error if required.
>>> >> * Also trace action execution if tracing mode enabled.
>>> >> */
>>> >> #define NSK_JNI_VERIFY(jni, action) \
>>> >> (nsk_ltrace(NSK_TRACE_BEFORE,__FILE__,__LINE__,"%s\n",#action), \
>>> >> nsk_jni_lverify(NSK_TRUE,jni,action,__FILE__,__LINE__,"%s\n",#action))
>>> >>
>>> >> So you will no longer see the JNI call in the trace or error output.
>>> >> You will just see the comparison to the JNI result, which gives no
>>> >> context as to the source of the result. So I'm now starting to think
>>> >> that doing the assignments within the NSK_JNI_VERIFY was intentional
>>> >> so we would see the JNI call in the trace output.
>>> >>
>>> >> Chris
>>> >>
>>> >> On 10/31/18 3:16 AM, Claes Redestad wrote:
>>> >>> Hi,
>>> >>>
>>> >>> here's a case that your script seems to miss:
>>> >>>
>>> >>>
>>> http://cr.openjdk.java.net/%7Ejcbeyler/8213003/webrev.00/test/hotspot/jtreg/vmTestbase/nsk/jvmti/GetClassLoaderClasses/clsldrclss002/clsldrclss002.cpp.udiff.html
>>> >>>
>>> >>>
>>> >>> if (!NSK_JNI_VERIFY(jni, (testedFieldID =
>>> >>> jni->GetStaticFieldID(testedClass, FIELD_NAME,
>>> >>> FIELD_SIGNATURE)) != NULL))
>>> >>>
>>> >>> I'd note that with some of your changes here you're unconditionally
>>> >>> executing logic outside of NSK_JNI_VERIFY macros. Does care need be
>>> >>> taken to wrap the code blocks in equivalent macros/ifdefs? Or are
>>> >>> the NSK_JNI_VERIFY macros always-on in these tests (and essentially
>>> >>> pointless)?
>>> >>>
>>> >>> /Claes
>>> >>>
>>> >>> On 2018-10-31 05:42, JC Beyler wrote:
>>> >>>> Hi all,
>>> >>>>
>>> >>>> I worked on updating my script and handling more assignments so I
>>> >>>> redid a second pass on the same files to get all the cases. Now, on
>>> >>>> those files the regex "if.* = " no longer shows any cases we would
>>> >>>> want to fix.
>>> >>>>
>>> >>>> Could I get a review for this webrev:
>>> >>>> Webrev: http://cr.openjdk.java.net/~jcbeyler/8213003/webrev.00/
>>> >>>> Bug: https://bugs.openjdk.java.net/browse/JDK-8213003
>>> >>>>
>>> >>>> I tested this on my dev machine by passing all the tests that were
>>> >>>> modified.
>>> >>>>
>>> >>>> Thanks!
>>> >>>> Jc
>>> >>>
>>> >>
>>> >>
>>> >
>>>
>>>
>>>
>>
>> --
>>
>> Thanks,
>> Jc
>>
>
>
> --
>
> Thanks,
> Jc
>
>
>
--
Thanks,
Jc
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mail.openjdk.java.net/pipermail/serviceability-dev/attachments/20181101/ca17060f/attachment-0001.html>
More information about the serviceability-dev
mailing list