Add streaming method profiling support.
The goal is to allow DDMS to start/stop method profiling in apps that
don't have permission to write to /sdcard. Instead of writing the
profiling data to disk and then pulling it off, we just blast the whole
thing straight from memory.
This includes:
- New method tracing start call (startMethodTracingDdms).
- Rearrangement of existing VMDebug method tracing calls for sanity.
- Addition of "vector" chunk send function, with corresponding
update to the JDWP transport function.
- Reshuffled the method trace start interlock, which seemed racy.
- Post new method-trace-profiling-streaming feature to DDMS.
Also:
- Added an internal exception-throw function that allows a printf
format string, so we can put useful detail into exception messages.
For bug 2160407.
diff --git a/libcore/dalvik/src/main/java/dalvik/system/VMDebug.java b/libcore/dalvik/src/main/java/dalvik/system/VMDebug.java
index c5c3aa9..cfae706 100644
--- a/libcore/dalvik/src/main/java/dalvik/system/VMDebug.java
+++ b/libcore/dalvik/src/main/java/dalvik/system/VMDebug.java
@@ -156,7 +156,12 @@
*/
public static void startMethodTracing(String traceFileName,
int bufferSize, int flags) {
- startMethodTracing(traceFileName, null, bufferSize, flags);
+
+ if (traceFileName == null) {
+ throw new NullPointerException();
+ }
+
+ startMethodTracingNative(traceFileName, null, bufferSize, flags);
}
/**
@@ -168,7 +173,33 @@
* this and find it would be useful.
* @hide
*/
- public static native void startMethodTracing(String traceFileName,
+ public static void startMethodTracing(String traceFileName,
+ FileDescriptor fd, int bufferSize, int flags)
+ {
+ if (traceFileName == null || fd == null) {
+ throw new NullPointerException();
+ }
+
+ startMethodTracingNative(traceFileName, fd, bufferSize, flags);
+ }
+
+ /**
+ * Starts method tracing without a backing file. When stopMethodTracing
+ * is called, the result is sent directly to DDMS. (If DDMS is not
+ * attached when tracing ends, the profiling data will be discarded.)
+ *
+ * @hide
+ */
+ public static void startMethodTracingDdms(int bufferSize, int flags) {
+ startMethodTracingNative(null, null, bufferSize, flags);
+ }
+
+ /**
+ * Implements all startMethodTracing variants.
+ *
+ * @hide
+ */
+ private static native void startMethodTracingNative(String traceFileName,
FileDescriptor fd, int bufferSize, int flags);
/**
diff --git a/vm/Debugger.c b/vm/Debugger.c
index 67a83a3..be6fa66 100644
--- a/vm/Debugger.c
+++ b/vm/Debugger.c
@@ -3024,7 +3024,18 @@
/*
* Send up a JDWP event packet with a DDM chunk in it.
*/
-void dvmDbgDdmSendChunk(int type, int len, const u1* buf)
+void dvmDbgDdmSendChunk(int type, size_t len, const u1* buf)
+{
+ assert(buf != NULL);
+ struct iovec vec[1] = { {(void*)buf, len} };
+ dvmDbgDdmSendChunkV(type, vec, 1);
+}
+
+/*
+ * Send up a JDWP event packet with a DDM chunk in it. The chunk is
+ * concatenated from multiple source buffers.
+ */
+void dvmDbgDdmSendChunkV(int type, const struct iovec* iov, int iovcnt)
{
if (gDvm.jdwpState == NULL) {
LOGV("Debugger thread not active, ignoring DDM send (t=0x%08x l=%d)\n",
@@ -3032,6 +3043,6 @@
return;
}
- dvmJdwpDdmSendChunk(gDvm.jdwpState, type, len, buf);
+ dvmJdwpDdmSendChunkV(gDvm.jdwpState, type, iov, iovcnt);
}
diff --git a/vm/Debugger.h b/vm/Debugger.h
index 1eea04c..04477fb 100644
--- a/vm/Debugger.h
+++ b/vm/Debugger.h
@@ -301,7 +301,8 @@
int* pReplyLen);
void dvmDbgDdmConnected(void);
void dvmDbgDdmDisconnected(void);
-void dvmDbgDdmSendChunk(int type, int len, const u1* buf);
+void dvmDbgDdmSendChunk(int type, size_t len, const u1* buf);
+void dvmDbgDdmSendChunkV(int type, const struct iovec* iov, int iovcnt);
#define CHUNK_TYPE(_name) \
((_name)[0] << 24 | (_name)[1] << 16 | (_name)[2] << 8 | (_name)[3])
diff --git a/vm/Exception.c b/vm/Exception.c
index 808b0b2..477f16f 100644
--- a/vm/Exception.c
+++ b/vm/Exception.c
@@ -181,6 +181,18 @@
/*
+ * Format the message into a small buffer and pass it along.
+ */
+void dvmThrowExceptionFmtV(const char* exceptionDescriptor, const char* fmt,
+ va_list args)
+{
+ char msgBuf[512];
+
+ vsnprintf(msgBuf, sizeof(msgBuf), fmt, args);
+ dvmThrowChainedException(exceptionDescriptor, msgBuf, NULL);
+}
+
+/*
* Create a Throwable and throw an exception in the current thread (where
* "throwing" just means "set the thread's exception pointer").
*
diff --git a/vm/Exception.h b/vm/Exception.h
index 4044345..f53c0bf 100644
--- a/vm/Exception.h
+++ b/vm/Exception.h
@@ -35,6 +35,20 @@
}
/*
+ * Like dvmThrowChainedException, but takes printf-style args for the message.
+ */
+void dvmThrowExceptionFmtV(const char* exceptionDescriptor, const char* fmt,
+ va_list args);
+INLINE void dvmThrowExceptionFmt(const char* exceptionDescriptor,
+ const char* fmt, ...)
+{
+ va_list args;
+ va_start(args, fmt);
+ dvmThrowExceptionFmtV(exceptionDescriptor, fmt, args);
+ va_end(args);
+}
+
+/*
* Throw an exception in the current thread, by class object.
*/
void dvmThrowChainedExceptionByClass(ClassObject* exceptionClass,
diff --git a/vm/Profile.c b/vm/Profile.c
index 393440c..dcfad71 100644
--- a/vm/Profile.c
+++ b/vm/Profile.c
@@ -31,6 +31,8 @@
#include <errno.h>
#include <fcntl.h>
+#include <cutils/open_memstream.h>
+
#ifdef HAVE_ANDROID_OS
# define UPDATE_MAGIC_PAGE 1
#endif
@@ -319,27 +321,30 @@
}
/*
- * Start method tracing. This opens the file (if an already open fd has not
- * been supplied) and allocates the buffer.
- * If any of these fail, we throw an exception and return.
+ * Start method tracing. Method tracing is global to the VM (i.e. we
+ * trace all threads).
*
- * Method tracing is global to the VM.
+ * This opens the output file (if an already open fd has not been supplied,
+ * and we're not going direct to DDMS) and allocates the data buffer.
+ *
+ * On failure, we throw an exception and return.
*/
void dvmMethodTraceStart(const char* traceFileName, int traceFd, int bufferSize,
- int flags)
+ int flags, bool directToDdms)
{
MethodTraceState* state = &gDvm.methodTrace;
assert(bufferSize > 0);
- if (state->traceEnabled != 0) {
+ dvmLockMutex(&state->startStopLock);
+ while (state->traceEnabled != 0) {
LOGI("TRACE start requested, but already in progress; stopping\n");
+ dvmUnlockMutex(&state->startStopLock);
dvmMethodTraceStop();
+ dvmLockMutex(&state->startStopLock);
}
updateActiveProfilers(1);
- LOGI("TRACE STARTED: '%s' %dKB\n",
- traceFileName, bufferSize / 1024);
- dvmLockMutex(&state->startStopLock);
+ LOGI("TRACE STARTED: '%s' %dKB\n", traceFileName, bufferSize / 1024);
/*
* Allocate storage and open files.
@@ -352,19 +357,25 @@
dvmThrowException("Ljava/lang/InternalError;", "buffer alloc failed");
goto fail;
}
- if (traceFd < 0) {
- state->traceFile = fopen(traceFileName, "w");
- } else {
- state->traceFile = fdopen(traceFd, "w");
- }
- if (state->traceFile == NULL) {
- LOGE("Unable to open trace file '%s': %s\n",
- traceFileName, strerror(errno));
- dvmThrowException("Ljava/lang/RuntimeException;", "file open failed");
- goto fail;
+ if (!directToDdms) {
+ if (traceFd < 0) {
+ state->traceFile = fopen(traceFileName, "w");
+ } else {
+ state->traceFile = fdopen(traceFd, "w");
+ }
+ if (state->traceFile == NULL) {
+ int err = errno;
+ LOGE("Unable to open trace file '%s': %s\n",
+ traceFileName, strerror(err));
+ dvmThrowExceptionFmt("Ljava/lang/RuntimeException;",
+ "Unable to open trace file '%s': %s",
+ traceFileName, strerror(err));
+ goto fail;
+ }
}
memset(state->buf, (char)FILL_PATTERN, bufferSize);
+ state->directToDdms = directToDdms;
state->bufferSize = bufferSize;
state->overflow = false;
@@ -569,6 +580,19 @@
markTouchedMethods(finalCurOffset);
+ char* memStreamPtr;
+ size_t memStreamSize;
+ if (state->directToDdms) {
+ assert(state->traceFile == NULL);
+ state->traceFile = open_memstream(&memStreamPtr, &memStreamSize);
+ if (state->traceFile == NULL) {
+ /* not expected */
+ LOGE("Unable to open memstream\n");
+ dvmAbort();
+ }
+ }
+ assert(state->traceFile != NULL);
+
fprintf(state->traceFile, "%cversion\n", TOKEN_CHAR);
fprintf(state->traceFile, "%d\n", TRACE_VERSION);
fprintf(state->traceFile, "data-file-overflow=%s\n",
@@ -597,18 +621,36 @@
dumpMethodList(state->traceFile);
fprintf(state->traceFile, "%cend\n", TOKEN_CHAR);
- if (fwrite(state->buf, finalCurOffset, 1, state->traceFile) != 1) {
- LOGE("trace fwrite(%d) failed, errno=%d\n", finalCurOffset, errno);
- dvmThrowException("Ljava/lang/RuntimeException;", "data write failed");
- goto bail;
+ if (state->directToDdms) {
+ /*
+ * Data is in two places: memStreamPtr and state->buf. Send
+ * the whole thing to DDMS, wrapped in an MPSE packet.
+ */
+ fflush(state->traceFile);
+
+ struct iovec iov[2];
+ iov[0].iov_base = memStreamPtr;
+ iov[0].iov_len = memStreamSize;
+ iov[1].iov_base = state->buf;
+ iov[1].iov_len = finalCurOffset;
+ dvmDbgDdmSendChunkV(CHUNK_TYPE("MPSE"), iov, 2);
+ } else {
+ /* append the profiling data */
+ if (fwrite(state->buf, finalCurOffset, 1, state->traceFile) != 1) {
+ int err = errno;
+ LOGE("trace fwrite(%d) failed, errno=%d\n", finalCurOffset, err);
+ dvmThrowExceptionFmt("Ljava/lang/RuntimeException;",
+ "Trace data write failed: %s", strerror(err));
+ }
}
-bail:
+ /* done! */
free(state->buf);
state->buf = NULL;
fclose(state->traceFile);
state->traceFile = NULL;
+ /* wake any threads that were waiting for profiling to complete */
int cc = pthread_cond_broadcast(&state->threadExitCond);
assert(cc == 0);
dvmUnlockMutex(&state->startStopLock);
diff --git a/vm/Profile.h b/vm/Profile.h
index d5dbea2..7cac150 100644
--- a/vm/Profile.h
+++ b/vm/Profile.h
@@ -39,7 +39,6 @@
/*
* Method trace state. This is currently global. In theory we could make
* most of this per-thread.
- *
*/
typedef struct MethodTraceState {
/* these are set during VM init */
@@ -50,6 +49,7 @@
pthread_mutex_t startStopLock;
pthread_cond_t threadExitCond;
FILE* traceFile;
+ bool directToDdms;
int bufferSize;
int flags;
@@ -97,7 +97,7 @@
* Start/stop method tracing.
*/
void dvmMethodTraceStart(const char* traceFileName, int traceFd, int bufferSize,
- int flags);
+ int flags, bool directToDdms);
bool dvmIsMethodTraceActive(void);
void dvmMethodTraceStop(void);
diff --git a/vm/jdwp/Jdwp.h b/vm/jdwp/Jdwp.h
index 0a72a06..7313579 100644
--- a/vm/jdwp/Jdwp.h
+++ b/vm/jdwp/Jdwp.h
@@ -232,6 +232,7 @@
/*
* Send up a chunk of DDM data.
*/
-void dvmJdwpDdmSendChunk(JdwpState* state, int type, int len, const u1* buf);
+void dvmJdwpDdmSendChunkV(JdwpState* state, int type, const struct iovec* iov,
+ int iovcnt);
#endif /*_DALVIK_JDWP_JDWP*/
diff --git a/vm/jdwp/JdwpAdb.c b/vm/jdwp/JdwpAdb.c
index cbb5e9d..6ec9f10 100644
--- a/vm/jdwp/JdwpAdb.c
+++ b/vm/jdwp/JdwpAdb.c
@@ -695,35 +695,28 @@
}
/*
- * Send a request that was split into two buffers.
+ * Send a request that was split into multiple buffers.
*
* The entire packet must be sent with a single writev() call to avoid
* threading issues.
*
* Returns "true" if it was sent successfully.
*/
-static bool sendBufferedRequest(JdwpState* state, const void* header,
- size_t headerLen, const void* body, size_t bodyLen)
+static bool sendBufferedRequest(JdwpState* state, const struct iovec* iov,
+ int iovcnt)
{
JdwpNetState* netState = state->netState;
- assert(headerLen > 0);
-
if (netState->clientSock < 0) {
/* can happen with some DDMS events */
LOGV("NOT sending request -- no debugger is attached\n");
return false;
}
- struct iovec iov[2];
- int iovcnt = 1;
- iov[0].iov_base = (void*) header;
- iov[0].iov_len = headerLen;
- if (body != NULL) {
- iovcnt++;
- iov[1].iov_base = (void*) body;
- iov[1].iov_len = bodyLen;
- }
+ size_t expected = 0;
+ int i;
+ for (i = 0; i < iovcnt; i++)
+ expected += iov[i].iov_len;
/*
* TODO: we currently assume the writev() will complete in one
@@ -732,9 +725,9 @@
*/
ssize_t actual;
actual = writev(netState->clientSock, iov, iovcnt);
- if ((size_t)actual != headerLen + bodyLen) {
+ if ((size_t)actual != expected) {
LOGE("Failed sending b-req to debugger: %s (%d of %zu)\n",
- strerror(errno), (int) actual, headerLen+bodyLen);
+ strerror(errno), (int) actual, expected);
return false;
}
diff --git a/vm/jdwp/JdwpEvent.c b/vm/jdwp/JdwpEvent.c
index bf6054d..996d7ad 100644
--- a/vm/jdwp/JdwpEvent.c
+++ b/vm/jdwp/JdwpEvent.c
@@ -1258,19 +1258,39 @@
* other debugger traffic, and can't suspend the VM, so we skip all of
* the fun event token gymnastics.
*/
-void dvmJdwpDdmSendChunk(JdwpState* state, int type, int len, const u1* buf)
+void dvmJdwpDdmSendChunkV(JdwpState* state, int type, const struct iovec* iov,
+ int iovcnt)
{
u1 header[kJDWPHeaderLen + 8];
+ size_t dataLen = 0;
+ int i;
+
+ assert(iov != NULL);
+ assert(iovcnt > 0 && iovcnt < 10);
+
+ /*
+ * "Wrap" the contents of the iovec with a JDWP/DDMS header. We do
+ * this by creating a new copy of the vector with space for the header.
+ */
+ struct iovec wrapiov[iovcnt+1];
+ for (i = 0; i < iovcnt; i++) {
+ wrapiov[i+1].iov_base = iov[i].iov_base;
+ wrapiov[i+1].iov_len = iov[i].iov_len;
+ dataLen += iov[i].iov_len;
+ }
/* form the header (JDWP plus DDMS) */
- set4BE(header, sizeof(header) + len);
+ set4BE(header, sizeof(header) + dataLen);
set4BE(header+4, dvmJdwpNextRequestSerial(state));
set1(header+8, 0); /* flags */
set1(header+9, kJDWPDdmCmdSet);
set1(header+10, kJDWPDdmCmd);
set4BE(header+11, type);
- set4BE(header+15, len);
+ set4BE(header+15, dataLen);
- dvmJdwpSendBufferedRequest(state, header, sizeof(header), buf, len);
+ wrapiov[0].iov_base = header;
+ wrapiov[0].iov_len = sizeof(header);
+
+ dvmJdwpSendBufferedRequest(state, wrapiov, iovcnt+1);
}
diff --git a/vm/jdwp/JdwpPriv.h b/vm/jdwp/JdwpPriv.h
index f5d80f8..87c3fc7 100644
--- a/vm/jdwp/JdwpPriv.h
+++ b/vm/jdwp/JdwpPriv.h
@@ -24,7 +24,9 @@
#include "jdwp/Jdwp.h"
#include "jdwp/JdwpEvent.h"
#include "Debugger.h"
+
#include <pthread.h>
+#include <sys/uio.h>
/*
* JDWP constants.
@@ -59,8 +61,8 @@
bool (*awaitingHandshake)(struct JdwpState* state);
bool (*processIncoming)(struct JdwpState* state);
bool (*sendRequest)(struct JdwpState* state, ExpandBuf* pReq);
- bool (*sendBufferedRequest)(struct JdwpState* state, const void* header,
- size_t headerLen, const void* body, size_t bodyLen);
+ bool (*sendBufferedRequest)(struct JdwpState* state,
+ const struct iovec* iov, int iovcnt);
} JdwpTransport;
const JdwpTransport* dvmJdwpSocketTransport();
@@ -169,11 +171,10 @@
INLINE bool dvmJdwpSendRequest(JdwpState* state, ExpandBuf* pReq) {
return (*state->transport->sendRequest)(state, pReq);
}
-INLINE bool dvmJdwpSendBufferedRequest(JdwpState* state, const void* header,
- size_t headerLen, const void* body, size_t bodyLen)
+INLINE bool dvmJdwpSendBufferedRequest(JdwpState* state,
+ const struct iovec* iov, int iovcnt)
{
- return (*state->transport->sendBufferedRequest)(state, header, headerLen,
- body, bodyLen);
+ return (*state->transport->sendBufferedRequest)(state, iov, iovcnt);
}
#endif /*_DALVIK_JDWP_JDWPPRIV*/
diff --git a/vm/jdwp/JdwpSocket.c b/vm/jdwp/JdwpSocket.c
index a6cbb02..42cd189 100644
--- a/vm/jdwp/JdwpSocket.c
+++ b/vm/jdwp/JdwpSocket.c
@@ -850,35 +850,28 @@
}
/*
- * Send a request that was split into two buffers.
+ * Send a request that was split into multiple buffers.
*
* The entire packet must be sent with a single writev() call to avoid
* threading issues.
*
* Returns "true" if it was sent successfully.
*/
-static bool sendBufferedRequest(JdwpState* state, const void* header,
- size_t headerLen, const void* body, size_t bodyLen)
+static bool sendBufferedRequest(JdwpState* state, const struct iovec* iov,
+ int iovcnt)
{
JdwpNetState* netState = state->netState;
- assert(headerLen > 0);
-
if (netState->clientSock < 0) {
/* can happen with some DDMS events */
LOGV("NOT sending request -- no debugger is attached\n");
return false;
}
- struct iovec iov[2];
- int iovcnt = 1;
- iov[0].iov_base = (void*) header;
- iov[0].iov_len = headerLen;
- if (body != NULL) {
- iovcnt++;
- iov[1].iov_base = (void*) body;
- iov[1].iov_len = bodyLen;
- }
+ size_t expected = 0;
+ int i;
+ for (i = 0; i < iovcnt; i++)
+ expected += iov[i].iov_len;
/*
* TODO: we currently assume the writev() will complete in one
@@ -887,9 +880,9 @@
*/
ssize_t actual;
actual = writev(netState->clientSock, iov, iovcnt);
- if ((size_t)actual != headerLen + bodyLen) {
+ if ((size_t)actual != expected) {
LOGE("Failed sending b-req to debugger: %s (%d of %zu)\n",
- strerror(errno), (int) actual, headerLen+bodyLen);
+ strerror(errno), (int) actual, expected);
return false;
}
diff --git a/vm/native/dalvik_system_VMDebug.c b/vm/native/dalvik_system_VMDebug.c
index d1ecafe..3f0b5fc 100644
--- a/vm/native/dalvik_system_VMDebug.c
+++ b/vm/native/dalvik_system_VMDebug.c
@@ -20,6 +20,8 @@
#include "Dalvik.h"
#include "native/InternalNativePriv.h"
+#include <errno.h>
+
/*
* Convert an array of char* into a String[].
@@ -86,6 +88,7 @@
#ifdef WITH_PROFILER
/* VM responds to DDMS method profiling requests */
features[idx++] = "method-trace-profiling";
+ features[idx++] = "method-trace-profiling-streaming";
#endif
#ifdef WITH_HPROF
/* VM responds to DDMS heap dump requests */
@@ -288,12 +291,16 @@
}
/*
- * static void startMethodTracing(String traceFileName, java.io.FileDescriptor,
- * int bufferSize, int flags)
+ * static void startMethodTracingNative(String traceFileName,
+ * FileDescriptor fd, int bufferSize, int flags)
*
* Start method trace profiling.
+ *
+ * If both "traceFileName" and "fd" are null, the result will be sent
+ * directly to DDMS. (The non-DDMS versions of the calls are expected
+ * to enforce non-NULL filenames.)
*/
-static void Dalvik_dalvik_system_VMDebug_startMethodTracing(const u4* args,
+static void Dalvik_dalvik_system_VMDebug_startMethodTracingNative(const u4* args,
JValue* pResult)
{
#ifdef WITH_PROFILER
@@ -301,32 +308,40 @@
DataObject* traceFd = (DataObject*) args[1];
int bufferSize = args[2];
int flags = args[3];
- char* traceFileName;
if (bufferSize == 0) {
// Default to 8MB per the documentation.
bufferSize = 8 * 1024 * 1024;
}
- if (traceFileStr == NULL || bufferSize < 1024) {
+ if (bufferSize < 1024) {
dvmThrowException("Ljava/lang/IllegalArgumentException;", NULL);
RETURN_VOID();
}
- traceFileName = dvmCreateCstrFromString(traceFileStr);
+ char* traceFileName = NULL;
+ if (traceFileStr != NULL)
+ traceFileName = dvmCreateCstrFromString(traceFileStr);
int fd = -1;
if (traceFd != NULL) {
- InstField* field = dvmFindInstanceField(traceFd->obj.clazz, "descriptor", "I");
+ InstField* field =
+ dvmFindInstanceField(traceFd->obj.clazz, "descriptor", "I");
if (field == NULL) {
dvmThrowException("Ljava/lang/NoSuchFieldException;",
"No FileDescriptor.descriptor field");
RETURN_VOID();
}
fd = dup(dvmGetFieldInt(&traceFd->obj, field->byteOffset));
+ if (fd < 0) {
+ dvmThrowExceptionFmt("Ljava/lang/RuntimeException;",
+ "dup() failed: %s", strerror(errno));
+ RETURN_VOID();
+ }
}
- dvmMethodTraceStart(traceFileName, fd, bufferSize, flags);
+ dvmMethodTraceStart(traceFileName != NULL ? traceFileName : "[DDMS]",
+ fd, bufferSize, flags, (traceFileName == NULL && fd == -1));
free(traceFileName);
#else
// throw exception?
@@ -825,8 +840,8 @@
Dalvik_dalvik_system_VMDebug_startAllocCounting },
{ "stopAllocCounting", "()V",
Dalvik_dalvik_system_VMDebug_stopAllocCounting },
- { "startMethodTracing", "(Ljava/lang/String;Ljava/io/FileDescriptor;II)V",
- Dalvik_dalvik_system_VMDebug_startMethodTracing },
+ { "startMethodTracingNative", "(Ljava/lang/String;Ljava/io/FileDescriptor;II)V",
+ Dalvik_dalvik_system_VMDebug_startMethodTracingNative },
{ "isMethodTracingActive", "()Z",
Dalvik_dalvik_system_VMDebug_isMethodTracingActive },
{ "stopMethodTracing", "()V",