Add method tracing JVMTI callbacks

Add MethodEntryHook and MethodExitHook callbacks and associated
capabilities.

Split --jvmti-stress option in run-test into --jvmti-trace-stress and
--jvmti-redefine-stress to test each different component.

NB 3 differences from RI found:
  1) RI will call methodExitHook again if the method exit hook throws
     an exception. This can easily cause an infinite loop and the test
     is specifically tweaked to prevent this from happening on the RI.
  2) RI always includes the method being exited in the stack trace of
     errors thrown in the hooks. In ART we will not include the method
     if it is native. This is due to the way we call native methods
     and would be extremely difficult to change.
  3) The RI will allow exceptions thrown in the MethodEnterHook to be
     caught by the entered method in some situations. This occurs with
     the tryCatchExit test in 989. In ART this does not happen.

Bug: 34414073
Test: ./test.py --host -j40
Test: ART_TEST_FULL=true DEXTER_BINARY="/path/to/dexter" \
      ./test/testrunner/testrunner.py --host -j40 -t 988
Test: ART_TEST_FULL=true DEXTER_BINARY="/path/to/dexter" \
      ./test/testrunner/testrunner.py --host -j40 -t 989
Test: lunch aosp_angler-userdebug; \
      m -j40 droid build-art && \
      fastboot -w flashall && \
      ./test.py --target -j4

Change-Id: Iab229353fae23c2ea27c2b698c831627a9f861b1
diff --git a/test/ti-stress/stress.cc b/test/ti-stress/stress.cc
index e8e3cc7..497db1c 100644
--- a/test/ti-stress/stress.cc
+++ b/test/ti-stress/stress.cc
@@ -20,6 +20,7 @@
 #include <fstream>
 #include <stdio.h>
 #include <sstream>
+#include <strstream>
 
 #include "jvmti.h"
 #include "exec_utils.h"
@@ -35,6 +36,8 @@
   std::string out_temp_dex;
   std::string in_temp_dex;
   bool vm_class_loader_initialized;
+  bool trace_stress;
+  bool redefine_stress;
 };
 
 static void WriteToFile(const std::string& fname, jint data_len, const unsigned char* data) {
@@ -95,7 +98,6 @@
   if (thread == nullptr) {
     info.name = const_cast<char*>("<NULLPTR>");
   } else if (jvmtienv->GetThreadInfo(thread, &info) != JVMTI_ERROR_NONE) {
-    LOG(WARNING) << "Unable to get thread info!";
     info.name = const_cast<char*>("<UNKNOWN THREAD>");
   }
   char *fname, *fsig, *fgen;
@@ -115,8 +117,8 @@
     env->DeleteLocalRef(klass);
     return;
   }
-  LOG(INFO) << "Loading native method \"" << cname << "->" << fname << fsig << "\". Thread is "
-            << info.name;
+  LOG(INFO) << "Loading native method \"" << cname << "->" << fname << fsig << "\". Thread is \""
+            << info.name << "\"";
   jvmtienv->Deallocate(reinterpret_cast<unsigned char*>(cname));
   jvmtienv->Deallocate(reinterpret_cast<unsigned char*>(cgen));
   jvmtienv->Deallocate(reinterpret_cast<unsigned char*>(fname));
@@ -126,6 +128,151 @@
   return;
 }
 
+static std::string GetName(jvmtiEnv* jvmtienv, JNIEnv* jnienv, jobject obj) {
+  jclass klass = jnienv->GetObjectClass(obj);
+  char *cname, *cgen;
+  if (jvmtienv->GetClassSignature(klass, &cname, &cgen) != JVMTI_ERROR_NONE) {
+    LOG(ERROR) << "Unable to get class name!";
+    jnienv->DeleteLocalRef(klass);
+    return "<UNKNOWN>";
+  }
+  std::string name(cname);
+  if (name == "Ljava/lang/String;") {
+    jstring str = reinterpret_cast<jstring>(obj);
+    const char* val = jnienv->GetStringUTFChars(str, nullptr);
+    if (val == nullptr) {
+      name += " (unable to get value)";
+    } else {
+      std::ostringstream oss;
+      oss << name << " (value: \"" << val << "\")";
+      name = oss.str();
+      jnienv->ReleaseStringUTFChars(str, val);
+    }
+  }
+  jvmtienv->Deallocate(reinterpret_cast<unsigned char*>(cname));
+  jvmtienv->Deallocate(reinterpret_cast<unsigned char*>(cgen));
+  jnienv->DeleteLocalRef(klass);
+  return name;
+}
+
+static std::string GetValOf(jvmtiEnv* env, JNIEnv* jnienv, std::string type, jvalue val) {
+  std::ostringstream oss;
+  switch (type[0]) {
+    case '[':
+    case 'L':
+      return val.l != nullptr ? GetName(env, jnienv, val.l) : "null";
+    case 'Z':
+      return val.z == JNI_TRUE ? "true" : "false";
+    case 'B':
+      oss << val.b;
+      return oss.str();
+    case 'C':
+      oss << val.c;
+      return oss.str();
+    case 'S':
+      oss << val.s;
+      return oss.str();
+    case 'I':
+      oss << val.i;
+      return oss.str();
+    case 'J':
+      oss << val.j;
+      return oss.str();
+    case 'F':
+      oss << val.f;
+      return oss.str();
+    case 'D':
+      oss << val.d;
+      return oss.str();
+    case 'V':
+      return "<void>";
+    default:
+      return "<ERROR Found type " + type + ">";
+  }
+}
+
+void JNICALL MethodExitHook(jvmtiEnv* jvmtienv,
+                            JNIEnv* env,
+                            jthread thread,
+                            jmethodID m,
+                            jboolean was_popped_by_exception,
+                            jvalue val) {
+  jvmtiThreadInfo info;
+  if (thread == nullptr) {
+    info.name = const_cast<char*>("<NULLPTR>");
+  } else if (jvmtienv->GetThreadInfo(thread, &info) != JVMTI_ERROR_NONE) {
+    // LOG(WARNING) << "Unable to get thread info!";
+    info.name = const_cast<char*>("<UNKNOWN THREAD>");
+  }
+  char *fname, *fsig, *fgen;
+  char *cname, *cgen;
+  jclass klass = nullptr;
+  if (jvmtienv->GetMethodDeclaringClass(m, &klass) != JVMTI_ERROR_NONE) {
+    LOG(ERROR) << "Unable to get method declaring class!";
+    return;
+  }
+  if (jvmtienv->GetMethodName(m, &fname, &fsig, &fgen) != JVMTI_ERROR_NONE) {
+    LOG(ERROR) << "Unable to get method name!";
+    env->DeleteLocalRef(klass);
+    return;
+  }
+  if (jvmtienv->GetClassSignature(klass, &cname, &cgen) != JVMTI_ERROR_NONE) {
+    LOG(ERROR) << "Unable to get class name!";
+    env->DeleteLocalRef(klass);
+    return;
+  }
+  std::string type(fsig);
+  type = type.substr(type.find(")") + 1);
+  std::string out_val(was_popped_by_exception ? "" : GetValOf(jvmtienv, env, type, val));
+  LOG(INFO) << "Leaving method \"" << cname << "->" << fname << fsig << "\". Thread is \""
+            << info.name << "\"." << std::endl
+            << "    Cause: " << (was_popped_by_exception ? "exception" : "return ")
+            << out_val << ".";
+  jvmtienv->Deallocate(reinterpret_cast<unsigned char*>(cname));
+  jvmtienv->Deallocate(reinterpret_cast<unsigned char*>(cgen));
+  jvmtienv->Deallocate(reinterpret_cast<unsigned char*>(fname));
+  jvmtienv->Deallocate(reinterpret_cast<unsigned char*>(fsig));
+  jvmtienv->Deallocate(reinterpret_cast<unsigned char*>(fgen));
+  env->DeleteLocalRef(klass);
+}
+
+void JNICALL MethodEntryHook(jvmtiEnv* jvmtienv,
+                             JNIEnv* env,
+                             jthread thread,
+                             jmethodID m) {
+  jvmtiThreadInfo info;
+  if (thread == nullptr) {
+    info.name = const_cast<char*>("<NULLPTR>");
+  } else if (jvmtienv->GetThreadInfo(thread, &info) != JVMTI_ERROR_NONE) {
+    info.name = const_cast<char*>("<UNKNOWN THREAD>");
+  }
+  char *fname, *fsig, *fgen;
+  char *cname, *cgen;
+  jclass klass = nullptr;
+  if (jvmtienv->GetMethodDeclaringClass(m, &klass) != JVMTI_ERROR_NONE) {
+    LOG(ERROR) << "Unable to get method declaring class!";
+    return;
+  }
+  if (jvmtienv->GetMethodName(m, &fname, &fsig, &fgen) != JVMTI_ERROR_NONE) {
+    LOG(ERROR) << "Unable to get method name!";
+    env->DeleteLocalRef(klass);
+    return;
+  }
+  if (jvmtienv->GetClassSignature(klass, &cname, &cgen) != JVMTI_ERROR_NONE) {
+    LOG(ERROR) << "Unable to get class name!";
+    env->DeleteLocalRef(klass);
+    return;
+  }
+  LOG(INFO) << "Entering method \"" << cname << "->" << fname << fsig << "\". Thread is \""
+            << info.name << "\"";
+  jvmtienv->Deallocate(reinterpret_cast<unsigned char*>(cname));
+  jvmtienv->Deallocate(reinterpret_cast<unsigned char*>(cgen));
+  jvmtienv->Deallocate(reinterpret_cast<unsigned char*>(fname));
+  jvmtienv->Deallocate(reinterpret_cast<unsigned char*>(fsig));
+  jvmtienv->Deallocate(reinterpret_cast<unsigned char*>(fgen));
+  env->DeleteLocalRef(klass);
+}
+
 // The hook we are using.
 void JNICALL ClassFileLoadHookSecretNoOp(jvmtiEnv* jvmti,
                                          JNIEnv* jni_env ATTRIBUTE_UNUSED,
@@ -163,27 +310,57 @@
   }
 }
 
-// Options are ${DEXTER_BINARY},${TEMP_FILE_1},${TEMP_FILE_2}
-static void ReadOptions(StressData* data, char* options) {
-  std::string ops(options);
-  data->dexter_cmd = ops.substr(0, ops.find(','));
-  ops = ops.substr(ops.find(',') + 1);
-  data->in_temp_dex = ops.substr(0, ops.find(','));
-  ops = ops.substr(ops.find(',') + 1);
-  data->out_temp_dex = ops;
+static std::string AdvanceOption(const std::string& ops) {
+  return ops.substr(ops.find(',') + 1);
 }
 
-// We need to make sure that VMClassLoader is initialized before we start redefining anything since
-// it can give (non-fatal) error messages if it's initialized after we've redefined BCP classes.
-// These error messages are expected and no problem but they will mess up our testing
-// infrastructure.
-static void JNICALL EnsureVMClassloaderInitializedCB(jvmtiEnv *jvmti_env,
-                                                     JNIEnv* jni_env,
-                                                     jthread thread ATTRIBUTE_UNUSED) {
+static bool HasNextOption(const std::string& ops) {
+  return ops.find(',') != std::string::npos;
+}
+
+static std::string GetOption(const std::string& in) {
+  return in.substr(0, in.find(','));
+}
+
+// Options are
+// jvmti-stress,[redefine,${DEXTER_BINARY},${TEMP_FILE_1},${TEMP_FILE_2},][trace]
+static void ReadOptions(StressData* data, char* options) {
+  std::string ops(options);
+  CHECK_EQ(GetOption(ops), "jvmti-stress") << "Options should start with jvmti-stress";
+  do {
+    ops = AdvanceOption(ops);
+    std::string cur = GetOption(ops);
+    if (cur == "trace") {
+      data->trace_stress = true;
+    } else if (cur == "redefine") {
+      data->redefine_stress = true;
+      ops = AdvanceOption(ops);
+      data->dexter_cmd = GetOption(ops);
+      ops = AdvanceOption(ops);
+      data->in_temp_dex = GetOption(ops);
+      ops = AdvanceOption(ops);
+      data->out_temp_dex = GetOption(ops);
+    } else {
+      LOG(FATAL) << "Unknown option: " << GetOption(ops);
+    }
+  } while (HasNextOption(ops));
+}
+
+// Do final setup during the VMInit callback. By this time most things are all setup.
+static void JNICALL PerformFinalSetupVMInit(jvmtiEnv *jvmti_env,
+                                            JNIEnv* jni_env,
+                                            jthread thread ATTRIBUTE_UNUSED) {
   // Load the VMClassLoader class. We will get a ClassNotFound exception because we don't have
   // visibility but the class will be loaded behind the scenes.
   LOG(INFO) << "manual load & initialization of class java/lang/VMClassLoader!";
   jclass klass = jni_env->FindClass("java/lang/VMClassLoader");
+  StressData* data = nullptr;
+  CHECK_EQ(jvmti_env->GetEnvironmentLocalStorage(reinterpret_cast<void**>(&data)),
+           JVMTI_ERROR_NONE);
+  // We need to make sure that VMClassLoader is initialized before we start redefining anything
+  // since it can give (non-fatal) error messages if it's initialized after we've redefined BCP
+  // classes. These error messages are expected and no problem but they will mess up our testing
+  // infrastructure.
   if (klass == nullptr) {
     // Probably on RI. Clear the exception so we can continue but don't mark vmclassloader as
     // initialized.
@@ -193,11 +370,20 @@
     // GetMethodID is spec'd to cause the class to be initialized.
     jni_env->GetMethodID(klass, "hashCode", "()I");
     jni_env->DeleteLocalRef(klass);
-    StressData* data = nullptr;
-    CHECK_EQ(jvmti_env->GetEnvironmentLocalStorage(reinterpret_cast<void**>(&data)),
-             JVMTI_ERROR_NONE);
     data->vm_class_loader_initialized = true;
   }
+  if (data->trace_stress) {
+    if (jvmti_env->SetEventNotificationMode(JVMTI_ENABLE,
+                                            JVMTI_EVENT_METHOD_ENTRY,
+                                            nullptr) != JVMTI_ERROR_NONE) {
+      LOG(ERROR) << "Unable to enable JVMTI_EVENT_METHOD_ENTRY event!";
+    }
+    if (jvmti_env->SetEventNotificationMode(JVMTI_ENABLE,
+                                        JVMTI_EVENT_METHOD_EXIT,
+                                        nullptr) != JVMTI_ERROR_NONE) {
+      LOG(ERROR) << "Unable to enable JVMTI_EVENT_METHOD_EXIT event!";
+    }
+  }
 }
 
 extern "C" JNIEXPORT jint JNICALL Agent_OnLoad(JavaVM* vm,
@@ -233,7 +419,9 @@
   memset(&cb, 0, sizeof(cb));
   cb.ClassFileLoadHook = ClassFileLoadHookSecretNoOp;
   cb.NativeMethodBind = doJvmtiMethodBind;
-  cb.VMInit = EnsureVMClassloaderInitializedCB;
+  cb.VMInit = PerformFinalSetupVMInit;
+  cb.MethodEntry = MethodEntryHook;
+  cb.MethodExit = MethodExitHook;
   if (jvmti->SetEventCallbacks(&cb, sizeof(cb)) != JVMTI_ERROR_NONE) {
     LOG(ERROR) << "Unable to set class file load hook cb!";
     return 1;
@@ -250,11 +438,13 @@
     LOG(ERROR) << "Unable to enable JVMTI_EVENT_VM_INIT event!";
     return 1;
   }
-  if (jvmti->SetEventNotificationMode(JVMTI_ENABLE,
-                                      JVMTI_EVENT_CLASS_FILE_LOAD_HOOK,
-                                      nullptr) != JVMTI_ERROR_NONE) {
-    LOG(ERROR) << "Unable to enable CLASS_FILE_LOAD_HOOK event!";
-    return 1;
+  if (data->redefine_stress) {
+    if (jvmti->SetEventNotificationMode(JVMTI_ENABLE,
+                                        JVMTI_EVENT_CLASS_FILE_LOAD_HOOK,
+                                        nullptr) != JVMTI_ERROR_NONE) {
+      LOG(ERROR) << "Unable to enable CLASS_FILE_LOAD_HOOK event!";
+      return 1;
+    }
   }
   return 0;
 }