Reland (aosp/2320257). Add JDWP metrics to DDM traffic

Record processing start and duration for each cmd. Flush the content of
the timing buffer when it is full.

At the end of the session, (identified by VM::Exit cmd), also flush.

The timing data is sent over a DDM packet with all
the metrics recorded to allow debugger performance profiling.

Bug: NA
Test: Used the following steps,

mkdir master-art; cd master-art
repo init -u  https://android.googlesource.com/platform/manifest  -b master-art --partial-clone --clone-filter=blob:limit=10M
. build/envsetup.sh
lunch armv8-eng
art/tools/buildbot-build.sh --host
art/tools/run-libjdwp-tests.sh --mode=host --test org.apache.harmony.jpda.tests.jdwp.VirtualMachine_ExitTest#testExit001

Change-Id: Ic6198975710ae11dd00e84549ed51eabf679d6bc

7 files changed, 181 insertions, 1 deletions

diff --git a/src/share/back/VirtualMachineImpl.c b/src/share/back/VirtualMachineImpl.c
index fde53c3e3..1e8b96938 100644
--- a/src/share/back/VirtualMachineImpl.c
+++ b/src/share/back/VirtualMachineImpl.c
@@ -34,6 +34,10 @@
 #include "SDE.h"
 #include "FrameID.h"
 
+// ANDROID-CHANGED: Need to sent metrics before doExit
+#include "timing.h"
+
+
 static char *versionName = "Java Debug Wire Protocol (Reference Implementation)";
 static int majorVersion = 1;  /* JDWP major version */
 static int minorVersion = 8;  /* JDWP minor version */
@@ -613,6 +617,10 @@ resume(PacketInputStream *in, PacketOutputStream *out)
 static jboolean
 doExit(PacketInputStream *in, PacketOutputStream *out)
 {
+    // ANDROID-CHANGED: We are about to exit(). Send ART cmd processing time,
+    // if there are any remaining.
+    timings_flush();
+
     jint exitCode;
 
     exitCode = inStream_readInt(in);
diff --git a/src/share/back/debugInit.c b/src/share/back/debugInit.c
index 2a1bd2172..e31fcf828 100644
--- a/src/share/back/debugInit.c
+++ b/src/share/back/debugInit.c
@@ -43,6 +43,9 @@
 #include "vmDebug.h"
 #include "DDMImpl.h"
 
+// ANDROID-CHANGED: Need to sent metrics before debugInit_exit
+#include "timing.h"
+
 /* How the options get to OnLoad: */
 #define XDEBUG "-Xdebug"
 #define XRUN "-Xrunjdwp"
@@ -1403,6 +1406,10 @@ debugInit_exit(jvmtiError error, const char *msg)
 {
     enum exit_codes { EXIT_NO_ERRORS = 0, EXIT_JVMTI_ERROR = 1, EXIT_TRANSPORT_ERROR = 2 };
 
+    // ANDROID-CHANGED: We are about to exit(). Send ART cmd processing time,
+    // if there are any remaining.
+    timings_flush();
+
     // Prepare to exit. Log error and finish logging
     LOG_MISC(("Exiting with error %s(%d): %s", jvmtiErrorText(error), error,
                                                ((msg == NULL) ? "" : msg)));
diff --git a/src/share/back/debugLoop.c b/src/share/back/debugLoop.c
index 9d3e9b914..e9e0e583b 100644
--- a/src/share/back/debugLoop.c
+++ b/src/share/back/debugLoop.c
@@ -37,6 +37,8 @@
 // ANDROID-CHANGED: Needed for vmDebug_onDisconnect, vmDebug_notifyDebuggerActivityStart &
 // vmDebug_notifyDebuggerActivityEnd.
 #include "vmDebug.h"
+// ANDROID-CHANGED: Needed for sending ART timings
+#include "timing.h"
 
 
 static void JNICALL reader(jvmtiEnv* jvmti_env, JNIEnv* jni_env, void* arg);
@@ -66,6 +68,7 @@ lastCommand(jdwpCmdPacket *cmd)
     }
 }
 
+
 void
 debugLoop_initialize(void)
 {
@@ -124,6 +127,11 @@ debugLoop_run(void)
             PacketOutputStream out;
             CommandHandler func;
 
+            // ANDROID-CHANGED: To be able to send cmd processing time
+            // periodically, we notify the timing system of when they
+            // start. This "startCmd" MUST be paired by a "endCmd".
+            timings_startCmd(cmd->id, cmd->cmdSet, cmd->cmd);
+
             /* Should reply be sent to sender.
              * For error handling, assume yes, since
              * only VM/exit does not reply
@@ -194,6 +202,10 @@ debugLoop_run(void)
             outStream_destroy(&out);
 
             shouldListen = !lastCommand(cmd);
+
+            // ANDROID-CHANGED: Let the timing system know that the cmd
+            // was fully processed. This may trigger a flush.
+            timings_endCmd();
         }
     }
     threadControl_onDisconnect();
diff --git a/src/share/back/timing.c b/src/share/back/timing.c
new file mode 100644
index 000000000..f49a30f63
--- /dev/null
+++ b/src/share/back/timing.c
@@ -0,0 +1,104 @@
+/*
+ * Copyright (c) 1998, 2004, Oracle and/or its affiliates. All rights reserved.
+ * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
+ *
+ * This code is free software; you can redistribute it and/or modify it
+ * under the terms of the GNU General Public License version 2 only, as
+ * published by the Free Software Foundation.  Oracle designates this
+ * particular file as subject to the "Classpath" exception as provided
+ * by Oracle in the LICENSE file that accompanied this code.
+ *
+ * This code is distributed in the hope that it will be useful, but WITHOUT
+ * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
+ * FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
+ * version 2 for more details (a copy is included in the LICENSE file that
+ * accompanied this code).
+ *
+ * You should have received a copy of the GNU General Public License version
+ * 2 along with this work; if not, write to the Free Software Foundation,
+ * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
+ *
+ * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
+ * or visit www.oracle.com if you need additional information or have any
+ * questions.
+ */
+
+#include "timing.h"
+
+#include "error_messages.h"
+#include "JDWP.h"
+#include "outStream.h"
+#include "util.h"
+
+// ANDROID-CHANGED: This whole file
+
+// This system stores cmd processing timing and sends them to the debugger
+// to generate profiling stats.
+
+typedef struct Timing {
+    jlong start_ns;
+    jlong duration_ns;
+    jint id;
+    jint cmd_set;
+    jint cmd;
+} Timing;
+
+static const jint MAX_TIMINGS = 500;
+static Timing timings[MAX_TIMINGS];
+static jint numTimings;
+
+void timings_startCmd(jint id, jint cmd_set, jint cmd) {
+  timings[numTimings].id = id;
+  timings[numTimings].cmd_set = cmd_set;
+  timings[numTimings].cmd = cmd;
+  timings[numTimings].start_ns = nsTime();
+}
+
+void timings_endCmd() {
+  timings[numTimings].duration_ns = nsTime() - timings[numTimings].start_ns;
+  numTimings++;
+
+  if (numTimings == MAX_TIMINGS) {
+    timings_flush();
+  }
+}
+
+// Return the size of the ARTT chunk
+static jint getChunkSize() {
+  jint size = 0;
+  size += sizeof(jint); // version
+  size += sizeof(jint); // num timing entries.
+
+  size += numTimings *  (sizeof(jint) * 3 + sizeof(jlong) * 2); // entries
+  return size;
+}
+
+void timings_flush() {
+   // Don't even waste a packet if we know it will contain no payload.
+   if (numTimings == 0) {
+    return;
+   }
+
+   PacketOutputStream packet;
+
+   outStream_initCommand(&packet, uniqueID(), 0, JDWP_COMMAND_SET(DDM),  JDWP_COMMAND(DDM, Chunk));
+
+   outStream_writeInt(&packet, 'A' << 24 | 'R' << 16 | 'T' << 8 | 'T');// DDM chunk type
+   outStream_writeInt(&packet,  getChunkSize()); // DDM chunk length
+
+   outStream_writeInt(&packet, 1); //version
+   outStream_writeInt(&packet, numTimings); // num timing entries
+
+   for(int i=0 ; i < numTimings ; i++) {
+     outStream_writeInt(&packet, timings[i].id);
+     outStream_writeInt(&packet, timings[i].cmd_set);
+     outStream_writeInt(&packet, timings[i].cmd);
+     outStream_writeLong(&packet, timings[i].start_ns);
+     outStream_writeLong(&packet, timings[i].duration_ns);
+   }
+   outStream_sendCommand(&packet);
+   outStream_destroy(&packet);
+
+   numTimings = 0;
+}
+
diff --git a/src/share/back/timing.h b/src/share/back/timing.h
new file mode 100644
index 000000000..478572f90
--- /dev/null
+++ b/src/share/back/timing.h
@@ -0,0 +1,40 @@
+/*
+ * Copyright (c) 1998, 2004, Oracle and/or its affiliates. All rights reserved.
+ * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
+ *
+ * This code is free software; you can redistribute it and/or modify it
+ * under the terms of the GNU General Public License version 2 only, as
+ * published by the Free Software Foundation.  Oracle designates this
+ * particular file as subject to the "Classpath" exception as provided
+ * by Oracle in the LICENSE file that accompanied this code.
+ *
+ * This code is distributed in the hope that it will be useful, but WITHOUT
+ * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
+ * FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
+ * version 2 for more details (a copy is included in the LICENSE file that
+ * accompanied this code).
+ *
+ * You should have received a copy of the GNU General Public License version
+ * 2 along with this work; if not, write to the Free Software Foundation,
+ * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
+ *
+ * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
+ * or visit www.oracle.com if you need additional information or have any
+ * questions.
+ */
+
+#ifndef JDWP_ART_METRICS_H
+#define JDWP_ART_METRICS_H
+
+// ANDROID-CHANGED: This whole file
+
+#include <jni.h>
+
+// Currently none of these methods are synchronized since they are only called
+// in the debugLoop thread. If we need to call this from multiple threads in the
+// future, we should add a Lock!
+void timings_startCmd(jint id, jint cmd_set, jint cmd);
+void timings_endCmd();
+void timings_flush();
+
+#endif
\ No newline at end of file
diff --git a/src/share/back/util.c b/src/share/back/util.c
index dcd195d23..8aa62f125 100644
--- a/src/share/back/util.c
+++ b/src/share/back/util.c
@@ -50,10 +50,18 @@ static jvmtiError (JNICALL *ext_RawMonitorExitNoSuspend) (jvmtiEnv* env, jrawMon
 jlong
 milliTime(void)
 {
+    return nsTime() / 1000000L;
+}
+
+// ANDROID-CHANGED: Implement a helper to get the current time in nanoseconds according to
+// CLOCK_MONOTONIC.
+jlong
+nsTime(void)
+{
   struct timespec now;
   memset(&now, 0, sizeof(now));
   (void)clock_gettime(CLOCK_MONOTONIC, &now);
-  return ((jlong)now.tv_sec) * 1000LL + ((jlong)now.tv_nsec) / 1000000LL;
+  return ((jlong)now.tv_sec) * 1000000000LL + ((jlong)now.tv_nsec);
 }
 
 /* Save an object reference for use later (create a NewGlobalRef) */
diff --git a/src/share/back/util.h b/src/share/back/util.h
index b02ad7b3c..d0b517d7c 100644
--- a/src/share/back/util.h
+++ b/src/share/back/util.h
@@ -343,6 +343,7 @@ jvmtiError objectReferrers(jobject obj, ObjectBatch *referrers, int maxObjects);
 
 // ANDROID-CHANGED: Helper function to get current time in milliseconds on CLOCK_MONOTONIC
 jlong milliTime(void);
+jlong nsTime(void);
 
 /*
  * Command handling helpers shared among multiple command sets