Dump total execution time per connection pool

Test: dumpsys dbinfo system
Bug: 64262688
Change-Id: I3e094240a2fdb27089b90a78a0dc26822e3c66e8

2 files changed, 24 insertions, 10 deletions

diff --git a/core/java/android/database/sqlite/SQLiteConnection.java b/core/java/android/database/sqlite/SQLiteConnection.java
index f894f0536b52..c28583ea867a 100644
--- a/core/java/android/database/sqlite/SQLiteConnection.java
+++ b/core/java/android/database/sqlite/SQLiteConnection.java
@@ -104,7 +104,7 @@ public final class SQLiteConnection implements CancellationSignal.OnCancelListen
     private PreparedStatement mPreparedStatementPool;
 
     // The recent operations log.
-    private final OperationLog mRecentOperations = new OperationLog();
+    private final OperationLog mRecentOperations;
 
     // The native SQLiteConnection pointer.  (FOR INTERNAL USE ONLY)
     private long mConnectionPtr;
@@ -162,6 +162,7 @@ public final class SQLiteConnection implements CancellationSignal.OnCancelListen
             SQLiteDatabaseConfiguration configuration,
             int connectionId, boolean primaryConnection) {
         mPool = pool;
+        mRecentOperations = new OperationLog(mPool);
         mConfiguration = new SQLiteDatabaseConfiguration(configuration);
         mConnectionId = connectionId;
         mIsPrimaryConnection = primaryConnection;
@@ -1298,6 +1299,11 @@ public final class SQLiteConnection implements CancellationSignal.OnCancelListen
         private final Operation[] mOperations = new Operation[MAX_RECENT_OPERATIONS];
         private int mIndex;
         private int mGeneration;
+        private final SQLiteConnectionPool mPool;
+
+        OperationLog(SQLiteConnectionPool pool) {
+            mPool = pool;
+        }
 
         public int beginOperation(String kind, String sql, Object[] bindArgs) {
             synchronized (mOperations) {
@@ -1381,8 +1387,10 @@ public final class SQLiteConnection implements CancellationSignal.OnCancelListen
                 }
                 operation.mEndTime = SystemClock.uptimeMillis();
                 operation.mFinished = true;
+                final long execTime = operation.mEndTime - operation.mStartTime;
+                mPool.onStatementExecuted(execTime);
                 return SQLiteDebug.DEBUG_LOG_SLOW_QUERIES && SQLiteDebug.shouldLogSlowQuery(
-                                operation.mEndTime - operation.mStartTime);
+                        execTime);
             }
             return false;
         }
@@ -1426,11 +1434,16 @@ public final class SQLiteConnection implements CancellationSignal.OnCancelListen
                 int index = mIndex;
                 Operation operation = mOperations[index];
                 if (operation != null) {
+                    // Note: SimpleDateFormat is not thread-safe, cannot be compile-time created,
+                    // and is relatively expensive to create during preloading. This method is only
+                    // used when dumping a connection, which is a rare (mainly error) case.
+                    SimpleDateFormat opDF = new SimpleDateFormat("yyyy-MM-dd HH:mm:ss.SSS");
                     int n = 0;
                     do {
                         StringBuilder msg = new StringBuilder();
                         msg.append("    ").append(n).append(": [");
-                        msg.append(operation.getFormattedStartTime());
+                        String formattedStartTime = opDF.format(new Date(operation.mStartWallTime));
+                        msg.append(formattedStartTime);
                         msg.append("] ");
                         operation.describe(msg, verbose);
                         printer.println(msg.toString());
@@ -1518,12 +1531,5 @@ public final class SQLiteConnection implements CancellationSignal.OnCancelListen
             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
-            //       when dumping a connection, which is a rare (mainly error) case. So:
-            //       DO NOT CACHE.
-            return new SimpleDateFormat("yyyy-MM-dd HH:mm:ss.SSS").format(new Date(mStartWallTime));
-        }
     }
 }
diff --git a/core/java/android/database/sqlite/SQLiteConnectionPool.java b/core/java/android/database/sqlite/SQLiteConnectionPool.java
index b66bf18fca1d..8b0fef4fe2bc 100644
--- a/core/java/android/database/sqlite/SQLiteConnectionPool.java
+++ b/core/java/android/database/sqlite/SQLiteConnectionPool.java
@@ -37,6 +37,7 @@ import java.util.ArrayList;
 import java.util.Map;
 import java.util.WeakHashMap;
 import java.util.concurrent.atomic.AtomicBoolean;
+import java.util.concurrent.atomic.AtomicLong;
 import java.util.concurrent.locks.LockSupport;
 
 /**
@@ -102,6 +103,8 @@ public final class SQLiteConnectionPool implements Closeable {
     @GuardedBy("mLock")
     private IdleConnectionHandler mIdleConnectionHandler;
 
+    private final AtomicLong mTotalExecutionTimeCounter = new AtomicLong(0);
+
     // Describes what should happen to an acquired connection when it is returned to the pool.
     enum AcquiredConnectionStatus {
         // The connection should be returned to the pool as usual.
@@ -523,6 +526,10 @@ public final class SQLiteConnectionPool implements Closeable {
         mConnectionLeaked.set(true);
     }
 
+    void onStatementExecuted(long executionTimeMs) {
+        mTotalExecutionTimeCounter.addAndGet(executionTimeMs);
+    }
+
     // Can't throw.
     private void closeAvailableConnectionsAndLogExceptionsLocked() {
         closeAvailableNonPrimaryConnectionsAndLogExceptionsLocked();
@@ -1076,6 +1083,7 @@ public final class SQLiteConnectionPool implements Closeable {
             printer.println("Connection pool for " + mConfiguration.path + ":");
             printer.println("  Open: " + mIsOpen);
             printer.println("  Max connections: " + mMaxConnectionPoolSize);
+            printer.println("  Total execution time: " + mTotalExecutionTimeCounter);
             if (mConfiguration.isLookasideConfigSet()) {
                 printer.println("  Lookaside config: sz=" + mConfiguration.lookasideSlotSize
                         + " cnt=" + mConfiguration.lookasideSlotCount);