From e12350faf7ede07ebc7242dc55be2b4a3a86b532 Mon Sep 17 00:00:00 2001 From: Greg Hackmann Date: Mon, 1 Dec 2014 14:31:21 -0800 Subject: Trace SQLite operations Inefficient SQLite use can have non-obvious effects on performance. For example, insert and update operations can trigger a surprising number of fsync() calls, especially if they're not grouped together into transactions. Add tracepoints around SQLite operations, to make it easier to pinpoint their effects on the rest of the system. Change-Id: I30cc3d02eca264e46dcc09ca7512a32519543834 Signed-off-by: Greg Hackmann --- .../android/database/sqlite/SQLiteConnection.java | 22 ++++++++++++++++++++++ core/java/android/os/Trace.java | 2 ++ 2 files changed, 24 insertions(+) diff --git a/core/java/android/database/sqlite/SQLiteConnection.java b/core/java/android/database/sqlite/SQLiteConnection.java index 3cda39ae9aad..a762f593692d 100644 --- a/core/java/android/database/sqlite/SQLiteConnection.java +++ b/core/java/android/database/sqlite/SQLiteConnection.java @@ -26,6 +26,7 @@ import android.database.sqlite.SQLiteDebug.DbStats; import android.os.CancellationSignal; import android.os.OperationCanceledException; import android.os.ParcelFileDescriptor; +import android.os.Trace; import android.util.Log; import android.util.LruCache; import android.util.Printer; @@ -1330,6 +1331,10 @@ public final class SQLiteConnection implements CancellationSignal.OnCancelListen } } operation.mCookie = newOperationCookieLocked(index); + if (Trace.isTagEnabled(Trace.TRACE_TAG_DATABASE)) { + Trace.asyncTraceBegin(Trace.TRACE_TAG_DATABASE, operation.getTraceMethodName(), + operation.mCookie); + } mIndex = index; return operation.mCookie; } @@ -1367,6 +1372,10 @@ public final class SQLiteConnection implements CancellationSignal.OnCancelListen private boolean endOperationDeferLogLocked(int cookie) { final Operation operation = getOperationLocked(cookie); if (operation != null) { + if (Trace.isTagEnabled(Trace.TRACE_TAG_DATABASE)) { + Trace.asyncTraceEnd(Trace.TRACE_TAG_DATABASE, operation.getTraceMethodName(), + operation.mCookie); + } operation.mEndTime = System.currentTimeMillis(); operation.mFinished = true; return SQLiteDebug.DEBUG_LOG_SLOW_QUERIES && SQLiteDebug.shouldLogSlowQuery( @@ -1439,6 +1448,12 @@ public final class SQLiteConnection implements CancellationSignal.OnCancelListen } private static final class Operation { + // Trim all SQL statements to 256 characters inside the trace marker. + // This limit gives plenty of context while leaving space for other + // entries in the trace buffer (and ensures atrace doesn't truncate the + // marker for us, potentially losing metadata in the process). + private static final int MAX_TRACE_METHOD_NAME_LEN = 256; + public long mStartTime; public long mEndTime; public String mKind; @@ -1492,6 +1507,13 @@ public final class SQLiteConnection implements CancellationSignal.OnCancelListen return mException != null ? "failed" : "succeeded"; } + private String getTraceMethodName() { + String methodName = mKind + " " + mSql; + if (methodName.length() > MAX_TRACE_METHOD_NAME_LEN) + return methodName.substring(0, MAX_TRACE_METHOD_NAME_LEN); + return methodName; + } + private String getFormattedStartTime() { // Note: SimpleDateFormat is not thread-safe, cannot be compile-time created, and is // relatively expensive to create during preloading. This method is only used diff --git a/core/java/android/os/Trace.java b/core/java/android/os/Trace.java index 7529c5294541..9e8103ae3c0c 100644 --- a/core/java/android/os/Trace.java +++ b/core/java/android/os/Trace.java @@ -79,6 +79,8 @@ public final class Trace { public static final long TRACE_TAG_PACKAGE_MANAGER = 1L << 18; /** @hide */ public static final long TRACE_TAG_SYSTEM_SERVER = 1L << 19; + /** @hide */ + public static final long TRACE_TAG_DATABASE = 1L << 20; private static final long TRACE_TAG_NOT_READY = 1L << 63; private static final int MAX_SECTION_NAME_LEN = 127; -- cgit v1.2.3-59-g8ed1b