|
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
@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).
Jc
On
10/31/18 11:30 AM, serguei.spit...@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
>>>
>>
>>
>
--
--
|
