|
Hi JC,
I would need to see a webrev with the ExceptionCheckingJni
support, new macros, and a few example uses. You don't need to fix
everything. I just want to get a better feel for the changes and
what the implementation would look like.
thanks,
Chris
On 11/1/18 1:03 PM, JC Beyler wrote:
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 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
>>>
>>
>>
>
--
--
--
|
