From 5e28d4b59dc6287107c11c2daedad42c98239fa8 Mon Sep 17 00:00:00 2001 From: Edgar Arriaga Date: Tue, 26 Oct 2021 15:46:24 -0700 Subject: [PATCH] Add total execution time and statements executed to dumpsys dbinfo Test: dumpsys dbinfo Bug: 193925357 Change-Id: I1b0933543b9a24f262803627097a7b8a77b5ddf5 --- .../database/sqlite/SQLiteConnectionPool.java | 28 +++++++- .../database/sqlite/SQLiteDatabase.java | 68 +++++++++++++++---- 2 files changed, 79 insertions(+), 17 deletions(-) diff --git a/core/java/android/database/sqlite/SQLiteConnectionPool.java b/core/java/android/database/sqlite/SQLiteConnectionPool.java index 852f8f2a4204a..003d5da860762 100644 --- a/core/java/android/database/sqlite/SQLiteConnectionPool.java +++ b/core/java/android/database/sqlite/SQLiteConnectionPool.java @@ -106,7 +106,11 @@ public final class SQLiteConnectionPool implements Closeable { @GuardedBy("mLock") private IdleConnectionHandler mIdleConnectionHandler; - private final AtomicLong mTotalExecutionTimeCounter = new AtomicLong(0); + // whole execution time for this connection in milliseconds. + private final AtomicLong mTotalStatementsTime = new AtomicLong(0); + + // total statements executed by this connection + private final AtomicLong mTotalStatementsCount = new AtomicLong(0); // Describes what should happen to an acquired connection when it is returned to the pool. enum AcquiredConnectionStatus { @@ -536,7 +540,8 @@ public final class SQLiteConnectionPool implements Closeable { } void onStatementExecuted(long executionTimeMs) { - mTotalExecutionTimeCounter.addAndGet(executionTimeMs); + mTotalStatementsTime.addAndGet(executionTimeMs); + mTotalStatementsCount.incrementAndGet(); } // Can't throw. @@ -1117,11 +1122,20 @@ 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); + printer.println(" Total execution time (ms): " + mTotalStatementsTime); + printer.println(" Total statements executed: " + mTotalStatementsCount); + if (mTotalStatementsCount.get() > 0) { + // Avoid division by 0 by filtering out logs where there are no statements executed. + printer.println(" Average time per statement (ms): " + + mTotalStatementsTime.get() / mTotalStatementsCount.get()); + } printer.println(" Configuration: openFlags=" + mConfiguration.openFlags + ", isLegacyCompatibilityWalEnabled=" + isCompatibilityWalEnabled + ", journalMode=" + TextUtils.emptyIfNull(mConfiguration.journalMode) + ", syncMode=" + TextUtils.emptyIfNull(mConfiguration.syncMode)); + boolean isReadOnlyDatabase = + (mConfiguration.openFlags & SQLiteDatabase.OPEN_READONLY) != 0; + printer.println(" IsReadOnlyDatabase=" + isReadOnlyDatabase); if (isCompatibilityWalEnabled) { printer.println(" Compatibility WAL enabled: wal_syncmode=" @@ -1182,6 +1196,14 @@ public final class SQLiteConnectionPool implements Closeable { } } + public long getTotalStatementsTime() { + return mTotalStatementsTime.get(); + } + + public long getTotalStatementsCount() { + return mTotalStatementsCount.get(); + } + @Override public String toString() { return "SQLiteConnectionPool: " + mConfiguration.path; diff --git a/core/java/android/database/sqlite/SQLiteDatabase.java b/core/java/android/database/sqlite/SQLiteDatabase.java index 9684ece5d9c1f..b6597ca798bdb 100644 --- a/core/java/android/database/sqlite/SQLiteDatabase.java +++ b/core/java/android/database/sqlite/SQLiteDatabase.java @@ -42,11 +42,8 @@ import android.util.EventLog; import android.util.Log; import android.util.Pair; import android.util.Printer; - import com.android.internal.util.Preconditions; - import dalvik.system.CloseGuard; - import java.io.File; import java.io.FileFilter; import java.io.IOException; @@ -2309,6 +2306,21 @@ public final class SQLiteDatabase extends SQLiteClosable { return databases; } + @UnsupportedAppUsage + private static ArrayList getActiveDatabasePools() { + ArrayList connectionPools = new ArrayList(); + synchronized (sActiveDatabases) { + for (SQLiteDatabase db : sActiveDatabases.keySet()) { + synchronized (db.mLock) { + if (db.mConnectionPoolLocked != null) { + connectionPools.add(db.mConnectionPoolLocked); + } + } + } + } + return connectionPools; + } + /** * Dump detailed information about all open databases in the current process. * Used by bug report. @@ -2317,8 +2329,45 @@ public final class SQLiteDatabase extends SQLiteClosable { // Use this ArraySet to collect file paths. final ArraySet directories = new ArraySet<>(); - for (SQLiteDatabase db : getActiveDatabases()) { - db.dump(printer, verbose, isSystem, directories); + // Accounting across all databases + long totalStatementsTimeInMs = 0; + long totalStatementsCount = 0; + + ArrayList activeConnectionPools = getActiveDatabasePools(); + + activeConnectionPools.sort( + (a, b) -> Long.compare(b.getTotalStatementsCount(), a.getTotalStatementsCount())); + for (SQLiteConnectionPool dbPool : activeConnectionPools) { + dbPool.dump(printer, verbose, directories); + totalStatementsTimeInMs += dbPool.getTotalStatementsTime(); + totalStatementsCount += dbPool.getTotalStatementsCount(); + } + + if (totalStatementsCount > 0) { + // Only print when there is information available + + // Sorted statements per database + printer.println("Statements Executed per Database"); + for (SQLiteConnectionPool dbPool : activeConnectionPools) { + printer.println( + " " + dbPool.getPath() + " : " + dbPool.getTotalStatementsCount()); + } + printer.println(""); + printer.println( + "Total Statements Executed for all Active Databases: " + totalStatementsCount); + + // Sorted execution time per database + activeConnectionPools.sort( + (a, b) -> Long.compare(b.getTotalStatementsTime(), a.getTotalStatementsTime())); + printer.println(""); + printer.println(""); + printer.println("Statement Time per Database (ms)"); + for (SQLiteConnectionPool dbPool : activeConnectionPools) { + printer.println( + " " + dbPool.getPath() + " : " + dbPool.getTotalStatementsTime()); + } + printer.println("Total Statements Time for all Active Databases (ms): " + + totalStatementsTimeInMs); } // Dump DB files in the directories. @@ -2331,15 +2380,6 @@ public final class SQLiteDatabase extends SQLiteClosable { } } - private void dump(Printer printer, boolean verbose, boolean isSystem, ArraySet directories) { - synchronized (mLock) { - if (mConnectionPoolLocked != null) { - printer.println(""); - mConnectionPoolLocked.dump(printer, verbose, directories); - } - } - } - private static void dumpDatabaseDirectory(Printer pw, File dir, boolean isSystem) { pw.println(""); pw.println("Database files in " + dir.getAbsolutePath() + ":");