summaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
-rw-r--r--core/java/android/database/sqlite/SQLiteDatabase.java57
-rw-r--r--core/java/android/database/sqlite/SQLiteQuery.java9
-rw-r--r--core/java/android/database/sqlite/SQLiteStatement.java29
3 files changed, 52 insertions, 43 deletions
diff --git a/core/java/android/database/sqlite/SQLiteDatabase.java b/core/java/android/database/sqlite/SQLiteDatabase.java
index a07176f..ca7cec2 100644
--- a/core/java/android/database/sqlite/SQLiteDatabase.java
+++ b/core/java/android/database/sqlite/SQLiteDatabase.java
@@ -18,6 +18,7 @@ package android.database.sqlite;
import com.google.android.collect.Maps;
+import android.app.ActivityThread;
import android.content.ContentValues;
import android.database.Cursor;
import android.database.DatabaseUtils;
@@ -36,6 +37,7 @@ import java.util.HashMap;
import java.util.Iterator;
import java.util.Locale;
import java.util.Map;
+import java.util.Random;
import java.util.Set;
import java.util.WeakHashMap;
import java.util.concurrent.locks.ReentrantLock;
@@ -203,6 +205,11 @@ public class SQLiteDatabase extends SQLiteClosable {
private long mLastLockMessageTime = 0L;
+ // always log queries which take 100ms+; shorter queries are sampled accordingly
+ private static final int QUERY_LOG_TIME_IN_NANOS = 100 * 1000000;
+ private static final int QUERY_LOG_SQL_LENGTH = 64;
+ private final Random mRandom = new Random();
+
/** Used by native code, do not rename */
/* package */ int mNativeHandle = 0;
@@ -250,10 +257,6 @@ public class SQLiteDatabase extends SQLiteClosable {
private final RuntimeException mLeakedException;
- // package visible, since callers will access directly to minimize overhead in the case
- // that logging is not enabled.
- /* package */ final boolean mLogStats;
-
// System property that enables logging of slow queries. Specify the threshold in ms.
private static final String LOG_SLOW_QUERIES_PROPERTY = "db.log.slow_query_threshold";
private final int mSlowQueryThreshold;
@@ -1643,8 +1646,7 @@ public class SQLiteDatabase extends SQLiteClosable {
* @throws SQLException If the SQL string is invalid for some reason
*/
public void execSQL(String sql) throws SQLException {
- boolean logStats = mLogStats;
- long timeStart = logStats ? SystemClock.elapsedRealtime() : 0;
+ long timeStart = Debug.threadCpuTimeNanos();
lock();
try {
native_execSQL(sql);
@@ -1654,9 +1656,7 @@ public class SQLiteDatabase extends SQLiteClosable {
} finally {
unlock();
}
- if (logStats) {
- logTimeStat(false /* not a read */, timeStart, SystemClock.elapsedRealtime());
- }
+ logTimeStat(sql, timeStart);
}
/**
@@ -1673,8 +1673,7 @@ public class SQLiteDatabase extends SQLiteClosable {
throw new IllegalArgumentException("Empty bindArgs");
}
- boolean logStats = mLogStats;
- long timeStart = logStats ? SystemClock.elapsedRealtime() : 0;
+ long timeStart = Debug.threadCpuTimeNanos();
lock();
SQLiteStatement statement = null;
try {
@@ -1695,9 +1694,7 @@ public class SQLiteDatabase extends SQLiteClosable {
}
unlock();
}
- if (logStats) {
- logTimeStat(false /* not a read */, timeStart, SystemClock.elapsedRealtime());
- }
+ logTimeStat(sql, timeStart);
}
@Override
@@ -1729,7 +1726,6 @@ public class SQLiteDatabase extends SQLiteClosable {
}
mFlags = flags;
mPath = path;
- mLogStats = "1".equals(android.os.SystemProperties.get("db.logstats"));
mSlowQueryThreshold = SystemProperties.getInt(LOG_SLOW_QUERIES_PROPERTY, -1);
mLeakedException = new IllegalStateException(path +
@@ -1890,8 +1886,35 @@ public class SQLiteDatabase extends SQLiteClosable {
return compiledStatement;
}
- /* package */ void logTimeStat(boolean read, long begin, long end) {
- EventLog.writeEvent(EVENT_DB_OPERATION, mPath, read ? 0 : 1, end - begin);
+ /* package */ void logTimeStat(String sql, long beginNanos) {
+ // Sample fast queries in proportion to the time taken.
+ // Quantize the % first, so the logged sampling probability
+ // exactly equals the actual sampling rate for this query.
+
+ int samplePercent;
+ long nanos = Debug.threadCpuTimeNanos() - beginNanos;
+ if (nanos >= QUERY_LOG_TIME_IN_NANOS) {
+ samplePercent = 100;
+ } else {
+ samplePercent = (int) (100 * nanos / QUERY_LOG_TIME_IN_NANOS) + 1;
+ if (mRandom.nextInt(100) < samplePercent) return;
+ }
+
+ if (sql.length() > QUERY_LOG_SQL_LENGTH) sql = sql.substring(0, QUERY_LOG_SQL_LENGTH);
+
+ // ActivityThread.currentPackageName() only returns non-null if the
+ // current thread is an application main thread. This parameter tells
+ // us whether an event loop is blocked, and if so, which app it is.
+ //
+ // Sadly, there's no fast way to determine app name if this is *not* a
+ // main thread, or when we are invoked via Binder (e.g. ContentProvider).
+ // Hopefully the full path to the database will be informative enough.
+
+ String blockingPackage = ActivityThread.currentPackageName();
+ if (blockingPackage == null) blockingPackage = "";
+
+ int millis = (int) (nanos / 1000000);
+ EventLog.writeEvent(EVENT_DB_OPERATION, mPath, sql, millis, blockingPackage, samplePercent);
}
/**
diff --git a/core/java/android/database/sqlite/SQLiteQuery.java b/core/java/android/database/sqlite/SQLiteQuery.java
index 94b950e..c34661d 100644
--- a/core/java/android/database/sqlite/SQLiteQuery.java
+++ b/core/java/android/database/sqlite/SQLiteQuery.java
@@ -17,6 +17,7 @@
package android.database.sqlite;
import android.database.CursorWindow;
+import android.os.Debug;
import android.os.SystemClock;
import android.util.Log;
@@ -57,10 +58,9 @@ public class SQLiteQuery extends SQLiteProgram {
*/
/* package */ int fillWindow(CursorWindow window,
int maxRead, int lastPos) {
+ long timeStart = Debug.threadCpuTimeNanos();
mDatabase.lock();
- boolean logStats = mDatabase.mLogStats;
- long startTime = logStats ? SystemClock.elapsedRealtime() : 0;
try {
acquireReference();
try {
@@ -75,10 +75,7 @@ public class SQLiteQuery extends SQLiteProgram {
if (SQLiteDebug.DEBUG_SQL_STATEMENTS) {
Log.d(TAG, "fillWindow(): " + mSql);
}
- if (logStats) {
- mDatabase.logTimeStat(true /* read */, startTime,
- SystemClock.elapsedRealtime());
- }
+ mDatabase.logTimeStat(mSql, timeStart);
return numRows;
} catch (IllegalStateException e){
// simply ignore it
diff --git a/core/java/android/database/sqlite/SQLiteStatement.java b/core/java/android/database/sqlite/SQLiteStatement.java
index a81c9a6..cc714ee 100644
--- a/core/java/android/database/sqlite/SQLiteStatement.java
+++ b/core/java/android/database/sqlite/SQLiteStatement.java
@@ -16,6 +16,7 @@
package android.database.sqlite;
+import android.os.Debug;
import android.os.SystemClock;
import android.util.Log;
@@ -47,9 +48,8 @@ public class SQLiteStatement extends SQLiteProgram
* some reason
*/
public void execute() {
+ long timeStart = Debug.threadCpuTimeNanos();
mDatabase.lock();
- boolean logStats = mDatabase.mLogStats;
- long startTime = logStats ? SystemClock.elapsedRealtime() : 0;
acquireReference();
try {
@@ -57,9 +57,7 @@ public class SQLiteStatement extends SQLiteProgram
Log.v(TAG, "execute() for [" + mSql + "]");
}
native_execute();
- if (logStats) {
- mDatabase.logTimeStat(false /* write */, startTime, SystemClock.elapsedRealtime());
- }
+ mDatabase.logTimeStat(mSql, timeStart);
} finally {
releaseReference();
mDatabase.unlock();
@@ -77,9 +75,8 @@ public class SQLiteStatement extends SQLiteProgram
* some reason
*/
public long executeInsert() {
+ long timeStart = Debug.threadCpuTimeNanos();
mDatabase.lock();
- boolean logStats = mDatabase.mLogStats;
- long startTime = logStats ? SystemClock.elapsedRealtime() : 0;
acquireReference();
try {
@@ -87,9 +84,7 @@ public class SQLiteStatement extends SQLiteProgram
Log.v(TAG, "executeInsert() for [" + mSql + "]");
}
native_execute();
- if (logStats) {
- mDatabase.logTimeStat(false /* write */, startTime, SystemClock.elapsedRealtime());
- }
+ mDatabase.logTimeStat(mSql, timeStart);
return mDatabase.lastInsertRow();
} finally {
releaseReference();
@@ -106,9 +101,8 @@ public class SQLiteStatement extends SQLiteProgram
* @throws android.database.sqlite.SQLiteDoneException if the query returns zero rows
*/
public long simpleQueryForLong() {
+ long timeStart = Debug.threadCpuTimeNanos();
mDatabase.lock();
- boolean logStats = mDatabase.mLogStats;
- long startTime = logStats ? SystemClock.elapsedRealtime() : 0;
acquireReference();
try {
@@ -116,9 +110,7 @@ public class SQLiteStatement extends SQLiteProgram
Log.v(TAG, "simpleQueryForLong() for [" + mSql + "]");
}
long retValue = native_1x1_long();
- if (logStats) {
- mDatabase.logTimeStat(false /* write */, startTime, SystemClock.elapsedRealtime());
- }
+ mDatabase.logTimeStat(mSql, timeStart);
return retValue;
} finally {
releaseReference();
@@ -135,9 +127,8 @@ public class SQLiteStatement extends SQLiteProgram
* @throws android.database.sqlite.SQLiteDoneException if the query returns zero rows
*/
public String simpleQueryForString() {
+ long timeStart = Debug.threadCpuTimeNanos();
mDatabase.lock();
- boolean logStats = mDatabase.mLogStats;
- long startTime = logStats ? SystemClock.elapsedRealtime() : 0;
acquireReference();
try {
@@ -145,9 +136,7 @@ public class SQLiteStatement extends SQLiteProgram
Log.v(TAG, "simpleQueryForString() for [" + mSql + "]");
}
String retValue = native_1x1_string();
- if (logStats) {
- mDatabase.logTimeStat(false /* write */, startTime, SystemClock.elapsedRealtime());
- }
+ mDatabase.logTimeStat(mSql, timeStart);
return retValue;
} finally {
releaseReference();