Permalink
Browse files

Improve -verbose:jni.

The old output just told you what functions were being called and made no
attempt to show you their arguments. The new output was sufficient to debug
an actual problem with an app we don't have the source to.

Still to do:
0. an easier way for third-party developers to enable this.
1. the primitive type arguments to SetIntField and so forth.
2. return values.

A few examples of the new output...

A decoded jclass:
  JNI: libcore.io.Posix.readBytes called IsInstanceOf((JNIEnv*)0x9618470, 0x28100015, java.lang.Class<byte[]>)

A decoded jfieldID:
  JNI: libcore.io.Posix.ioctlInt called GetIntField((JNIEnv*)0x9618470, 0x5cb00011, java.io.FileDescriptor.descriptor)

A decoded jmethodID (the FileDescriptor constructor):
  JNI: libcore.io.Posix.open called NewObject((JNIEnv*)0x9780480, java.lang.Class<java.io.FileDescriptor>, java.io.FileDescriptor.<init>()V, ...)

A const char*:
  JNI: libcore.io.Posix.getsockoptLinger called NewStringUTF((JNIEnv*)0x9618470, "getsockopt")

A jint release mode:
  JNI: libcore.io.Posix.writeBytes called ReleaseByteArrayElements((JNIEnv*)0x9780480, 0x2700009, (void*) 0xf5f623c4, JNI_ABORT)

The -verbose:jni option now turns on a bit more output about JNI_OnLoad calls
but no longer causes any logging of calls to JNIEnv or JavaVM functions. The
old -Xjnitrace: option has been extended to enable this new tracing for the
native methods that it covers. They go very well together for debugging
purposes.

I've also made us a bit more verbose if we fail to initialize. In the longer
term I think we want to just abort if we hit any failure during startup, but
my extra logging will save us a bit of time next time we have one of these
failures (this one was caused for me by only having one half of the finalizer
watchdog change; I was missing the libcore side).

(Cherry pick of 6734b8224fb869c94e42e704ec03f2ce8483af2b from dalvik-dev.)

Change-Id: I69b7620b20620e9f06576da244520d9d83f89ab8
  • Loading branch information...
1 parent 2e31bb7 commit 5719d5c79558ffdbbb863ddcf61836221aba922d @enh enh committed Jun 22, 2011
Showing with 708 additions and 461 deletions.
  1. +529 −383 vm/CheckJni.cpp
  2. +103 −65 vm/Init.cpp
  3. +2 −2 vm/Init.h
  4. +16 −3 vm/Jni.cpp
  5. +29 −1 vm/Misc.cpp
  6. +18 −0 vm/Misc.h
  7. +6 −2 vm/Native.cpp
  8. +5 −5 vm/interp/Stack.cpp
View

Large diffs are not rendered by default.

Oops, something went wrong.
View
@@ -1149,35 +1149,54 @@ static void blockSignals()
}
}
+class ScopedShutdown {
+public:
+ ScopedShutdown() : armed_(true) {
+ }
+
+ ~ScopedShutdown() {
+ if (armed_) {
+ dvmShutdown();
+ }
+ }
+
+ void disarm() {
+ armed_ = false;
+ }
+
+private:
+ bool armed_;
+};
+
/*
* VM initialization. Pass in any options provided on the command line.
* Do not pass in the class name or the options for the class.
*
* Returns 0 on success.
*/
-int dvmStartup(int argc, const char* const argv[], bool ignoreUnrecognized,
- JNIEnv* pEnv)
+std::string dvmStartup(int argc, const char* const argv[],
+ bool ignoreUnrecognized, JNIEnv* pEnv)
{
- int i, cc;
+ ScopedShutdown scopedShutdown;
assert(gDvm.initializing);
LOGV("VM init args (%d):", argc);
- for (i = 0; i < argc; i++)
+ for (int i = 0; i < argc; i++) {
LOGV(" %d: '%s'", i, argv[i]);
-
+ }
setCommandLineDefaults();
/*
* Process the option flags (if any).
*/
- cc = processOptions(argc, argv, ignoreUnrecognized);
+ int cc = processOptions(argc, argv, ignoreUnrecognized);
if (cc != 0) {
if (cc < 0) {
dvmFprintf(stderr, "\n");
usage("dalvikvm");
}
- goto fail;
+ return "syntax error";
}
#if WITH_EXTRA_GC_CHECKS > 1
@@ -1202,9 +1221,8 @@ int dvmStartup(int argc, const char* const argv[], bool ignoreUnrecognized,
/* verify system page size */
if (sysconf(_SC_PAGESIZE) != SYSTEM_PAGE_SIZE) {
- LOGE("ERROR: expected page size %d, got %d",
- SYSTEM_PAGE_SIZE, (int) sysconf(_SC_PAGESIZE));
- goto fail;
+ return StringPrintf("expected page size %d, got %d",
+ SYSTEM_PAGE_SIZE, (int) sysconf(_SC_PAGESIZE));
}
/* mterp setup */
@@ -1214,60 +1232,76 @@ int dvmStartup(int argc, const char* const argv[], bool ignoreUnrecognized,
/*
* Initialize components.
*/
- if (!dvmAllocTrackerStartup())
- goto fail;
- if (!dvmGcStartup())
- goto fail;
- if (!dvmThreadStartup())
- goto fail;
- if (!dvmInlineNativeStartup())
- goto fail;
- if (!dvmRegisterMapStartup())
- goto fail;
- if (!dvmInstanceofStartup())
- goto fail;
- if (!dvmClassStartup())
- goto fail;
+ if (!dvmAllocTrackerStartup()) {
+ return "dvmAllocTrackerStartup failed";
+ }
+ if (!dvmGcStartup()) {
+ return "dvmGcStartup failed";
+ }
+ if (!dvmThreadStartup()) {
+ return "dvmThreadStartup failed";
+ }
+ if (!dvmInlineNativeStartup()) {
+ return "dvmInlineNativeStartup";
+ }
+ if (!dvmRegisterMapStartup()) {
+ return "dvmRegisterMapStartup failed";
+ }
+ if (!dvmInstanceofStartup()) {
+ return "dvmInstanceofStartup failed";
+ }
+ if (!dvmClassStartup()) {
+ return "dvmClassStartup failed";
+ }
/*
* At this point, the system is guaranteed to be sufficiently
* initialized that we can look up classes and class members. This
* call populates the gDvm instance with all the class and member
* references that the VM wants to use directly.
*/
- if (!dvmFindRequiredClassesAndMembers())
- goto fail;
+ if (!dvmFindRequiredClassesAndMembers()) {
+ return "dvmFindRequiredClassesAndMembers failed";
+ }
- if (!dvmStringInternStartup())
- goto fail;
- if (!dvmNativeStartup())
- goto fail;
- if (!dvmInternalNativeStartup())
- goto fail;
- if (!dvmJniStartup())
- goto fail;
- if (!dvmProfilingStartup())
- goto fail;
+ if (!dvmStringInternStartup()) {
+ return "dvmStringInternStartup failed";
+ }
+ if (!dvmNativeStartup()) {
+ return "dvmNativeStartup failed";
+ }
+ if (!dvmInternalNativeStartup()) {
+ return "dvmInternalNativeStartup failed";
+ }
+ if (!dvmJniStartup()) {
+ return "dvmJniStartup failed";
+ }
+ if (!dvmProfilingStartup()) {
+ return "dvmProfilingStartup failed";
+ }
/*
* Create a table of methods for which we will substitute an "inline"
* version for performance.
*/
- if (!dvmCreateInlineSubsTable())
- goto fail;
+ if (!dvmCreateInlineSubsTable()) {
+ return "dvmCreateInlineSubsTable failed";
+ }
/*
* Miscellaneous class library validation.
*/
- if (!dvmValidateBoxClasses())
- goto fail;
+ if (!dvmValidateBoxClasses()) {
+ return "dvmValidateBoxClasses failed";
+ }
/*
* Do the last bits of Thread struct initialization we need to allow
* JNI calls to work.
*/
- if (!dvmPrepMainForJni(pEnv))
- goto fail;
+ if (!dvmPrepMainForJni(pEnv)) {
+ return "dvmPrepMainForJni failed";
+ }
/*
* Explicitly initialize java.lang.Class. This doesn't happen
@@ -1276,30 +1310,34 @@ int dvmStartup(int argc, const char* const argv[], bool ignoreUnrecognized,
* which make some calls that throw assertions if the classes they
* operate on aren't initialized.
*/
- if (!dvmInitClass(gDvm.classJavaLangClass))
- goto fail;
+ if (!dvmInitClass(gDvm.classJavaLangClass)) {
+ return "couldn't initialized java.lang.Class";
+ }
/*
* Register the system native methods, which are registered through JNI.
*/
- if (!registerSystemNatives(pEnv))
- goto fail;
+ if (!registerSystemNatives(pEnv)) {
+ return "couldn't register system natives";
+ }
/*
* Do some "late" initialization for the memory allocator. This may
* allocate storage and initialize classes.
*/
- if (!dvmCreateStockExceptions())
- goto fail;
+ if (!dvmCreateStockExceptions()) {
+ return "dvmCreateStockExceptions failed";
+ }
/*
* At this point, the VM is in a pretty good state. Finish prep on
* the main thread (specifically, create a java.lang.Thread object to go
* along with our Thread struct). Note we will probably be executing
* some interpreted class initializer code in here.
*/
- if (!dvmPrepMainThread())
- goto fail;
+ if (!dvmPrepMainThread()) {
+ return "dvmPrepMainThread failed";
+ }
/*
* Make sure we haven't accumulated any tracked references. The main
@@ -1312,22 +1350,26 @@ int dvmStartup(int argc, const char* const argv[], bool ignoreUnrecognized,
}
/* general debugging setup */
- if (!dvmDebuggerStartup())
- goto fail;
+ if (!dvmDebuggerStartup()) {
+ return "dvmDebuggerStartup failed";
+ }
- if (!dvmGcStartupClasses())
- goto fail;
+ if (!dvmGcStartupClasses()) {
+ return "dvmGcStartupClasses failed";
+ }
/*
* Init for either zygote mode or non-zygote mode. The key difference
* is that we don't start any additional threads in Zygote mode.
*/
if (gDvm.zygote) {
- if (!initZygote())
- goto fail;
+ if (!initZygote()) {
+ return "initZygote failed";
+ }
} else {
- if (!dvmInitAfterZygote())
- goto fail;
+ if (!dvmInitAfterZygote()) {
+ return "dvmInitAfterZygote failed";
+ }
}
@@ -1339,16 +1381,12 @@ int dvmStartup(int argc, const char* const argv[], bool ignoreUnrecognized,
#endif
if (dvmCheckException(dvmThreadSelf())) {
- LOGE("Exception pending at end of VM initialization");
dvmLogExceptionStackTrace();
- goto fail;
+ return "Exception pending at end of VM initialization";
}
- return 0;
-
-fail:
- dvmShutdown();
- return 1;
+ scopedShutdown.disarm();
+ return "";
}
/*
View
@@ -23,8 +23,8 @@
/*
* Standard VM initialization, usually invoked through JNI.
*/
-int dvmStartup(int argc, const char* const argv[], bool ignoreUnrecognized,
- JNIEnv* pEnv);
+std::string dvmStartup(int argc, const char* const argv[],
+ bool ignoreUnrecognized, JNIEnv* pEnv);
void dvmShutdown(void);
bool dvmInitAfterZygote(void);
View
@@ -388,6 +388,18 @@ static jobject addLocalReference(JNIEnv* env, Object* obj) {
}
}
+#if 0 // TODO: fix this to understand PushLocalFrame, so we can turn it on.
+ if (gDvmJni.useCheckJni) {
+ size_t entryCount = pRefTable->capacity();
+ if (entryCount > 16) {
+ LOGW("Warning: more than 16 JNI local references: %d (most recent was a %s)", entryCount, obj->clazz->descriptor);
+ pRefTable->dump("JNI local");
+ dvmDumpThread(dvmThreadSelf(), false);
+ //dvmAbort();
+ }
+ }
+#endif
+
return jobj;
}
@@ -3523,13 +3535,14 @@ jint JNI_CreateJavaVM(JavaVM** p_vm, JNIEnv** p_env, void* vm_args) {
/* Initialize VM. */
gDvm.initializing = true;
- int rc = dvmStartup(argc, argv.get(), args->ignoreUnrecognized, (JNIEnv*)pEnv);
+ std::string status =
+ dvmStartup(argc, argv.get(), args->ignoreUnrecognized, (JNIEnv*)pEnv);
gDvm.initializing = false;
- if (rc != 0) {
+ if (!status.empty()) {
free(pEnv);
free(pVM);
- LOGW("CreateJavaVM failed");
+ LOGW("CreateJavaVM failed: %s", status.c_str());
return JNI_ERR;
}
View
@@ -283,6 +283,34 @@ std::string dvmHumanReadableType(const Object* obj)
return result;
}
+std::string dvmHumanReadableField(const Field* field)
+{
+ if (field == NULL) {
+ return "(null)";
+ }
+ std::string result(dvmHumanReadableDescriptor(field->clazz->descriptor));
+ result += '.';
+ result += field->name;
+ return result;
+}
+
+std::string dvmHumanReadableMethod(const Method* method, bool withSignature)
+{
+ if (method == NULL) {
+ return "(null)";
+ }
+ std::string result(dvmHumanReadableDescriptor(method->clazz->descriptor));
+ result += '.';
+ result += method->name;
+ if (withSignature) {
+ // TODO: the types in this aren't human readable!
+ char* signature = dexProtoCopyMethodDescriptor(&method->prototype);
+ result += signature;
+ free(signature);
+ }
+ return result;
+}
+
/*
* Return a newly-allocated string for the "dot version" of the class
* name for the given type descriptor. That is, The initial "L" and
@@ -734,7 +762,7 @@ const char* dvmPathToAbsolutePortion(const char* path) {
}
// From RE2.
-static void StringAppendV(std::string* dst, const char* format, va_list ap) {
+void StringAppendV(std::string* dst, const char* format, va_list ap) {
// First try with a small fixed size buffer
char space[1024];
Oops, something went wrong.

0 comments on commit 5719d5c

Please sign in to comment.