fix broken logTimeStat stuff
log time in the following 2 situations
1. all transactions. time measured = wall time between begin-commit
2. queries (which are not in tranactions)
Change-Id: I67be9487a96072695aff3529ba4a257f4c8ec596
diff --git a/core/java/android/database/sqlite/SQLiteDatabase.java b/core/java/android/database/sqlite/SQLiteDatabase.java
index 90a5b5d..c6051e1 100644
--- a/core/java/android/database/sqlite/SQLiteDatabase.java
+++ b/core/java/android/database/sqlite/SQLiteDatabase.java
@@ -230,9 +230,23 @@
private static int sQueryLogTimeInMillis = 0; // lazily initialized
private static final int QUERY_LOG_SQL_LENGTH = 64;
private static final String COMMIT_SQL = "COMMIT;";
+ private static final String BEGIN_SQL = "BEGIN;";
private final Random mRandom = new Random();
+ /** the last non-commit/rollback sql statement in a transaction */
+ // guarded by 'this'
private String mLastSqlStatement = null;
+ synchronized String getLastSqlStatement() {
+ return mLastSqlStatement;
+ }
+
+ synchronized void setLastSqlStatement(String sql) {
+ mLastSqlStatement = sql;
+ }
+
+ /** guarded by {@link #mLock} */
+ private long mTransStartTime;
+
// String prefix for slow database query EventLog records that show
// lock acquistions of the database.
/* package */ static final String GET_LOCK_LOG_PREFIX = "GETLOCK:";
@@ -386,11 +400,16 @@
*
* @see #unlock()
*/
- /* package */ void lock() {
- lock(false);
+ /* package */ void lock(String sql) {
+ lock(sql, false);
}
+
+ /* pachage */ void lock() {
+ lock(null, false);
+ }
+
private static final long LOCK_WAIT_PERIOD = 30L;
- private void lock(boolean forced) {
+ private void lock(String sql, boolean forced) {
// make sure this method is NOT being called from a 'synchronized' method
if (Thread.holdsLock(this)) {
Log.w(TAG, "don't lock() while in a synchronized method");
@@ -398,6 +417,7 @@
verifyDbIsOpen();
if (!forced && !mLockingEnabled) return;
boolean done = false;
+ long timeStart = SystemClock.uptimeMillis();
while (!done) {
try {
// wait for 30sec to acquire the lock
@@ -420,6 +440,9 @@
mLockAcquiredThreadTime = Debug.threadCpuTimeNanos();
}
}
+ if (sql != null) {
+ logTimeStat(sql, timeStart, GET_LOCK_LOG_PREFIX);
+ }
}
private static class DatabaseReentrantLock extends ReentrantLock {
DatabaseReentrantLock(boolean fair) {
@@ -444,7 +467,11 @@
* @see #unlockForced()
*/
private void lockForced() {
- lock(true);
+ lock(null, true);
+ }
+
+ private void lockForced(String sql) {
+ lock(sql, true);
}
/**
@@ -612,7 +639,7 @@
private void beginTransaction(SQLiteTransactionListener transactionListener,
boolean exclusive) {
verifyDbIsOpen();
- lockForced();
+ lockForced(BEGIN_SQL);
boolean ok = false;
try {
// If this thread already had the lock then get out
@@ -635,6 +662,7 @@
} else {
execSQL("BEGIN IMMEDIATE;");
}
+ mTransStartTime = SystemClock.uptimeMillis();
mTransactionListener = transactionListener;
mTransactionIsSuccessful = true;
mInnerTransactionIsSuccessful = false;
@@ -698,6 +726,8 @@
Log.i(TAG, "PRAGMA wal_Checkpoint done");
}
}
+ // log the transaction time to the Eventlog.
+ logTimeStat(getLastSqlStatement(), mTransStartTime, COMMIT_SQL);
} else {
try {
execSQL("ROLLBACK;");
@@ -1855,24 +1885,11 @@
* @throws SQLException if the SQL string is invalid
*/
public void execSQL(String sql) throws SQLException {
- int stmtType = DatabaseUtils.getSqlStatementType(sql);
- if (stmtType == DatabaseUtils.STATEMENT_ATTACH) {
+ if (DatabaseUtils.getSqlStatementType(sql) == DatabaseUtils.STATEMENT_ATTACH) {
disableWriteAheadLogging();
- }
- long timeStart = SystemClock.uptimeMillis();
- logTimeStat(mLastSqlStatement, timeStart, GET_LOCK_LOG_PREFIX);
- executeSql(sql, null);
-
- if (stmtType == DatabaseUtils.STATEMENT_ATTACH) {
mHasAttachedDbs = true;
}
- // Log commit statements along with the most recently executed
- // SQL statement for disambiguation.
- if (stmtType == DatabaseUtils.STATEMENT_COMMIT) {
- logTimeStat(mLastSqlStatement, timeStart, COMMIT_SQL);
- } else {
- logTimeStat(sql, timeStart, null);
- }
+ executeSql(sql, null);
}
/**
@@ -1926,19 +1943,15 @@
}
private int executeSql(String sql, Object[] bindArgs) throws SQLException {
- long timeStart = SystemClock.uptimeMillis();
- int n;
SQLiteStatement statement = new SQLiteStatement(this, sql, bindArgs);
try {
- n = statement.executeUpdateDelete();
+ return statement.executeUpdateDelete();
} catch (SQLiteDatabaseCorruptException e) {
onCorruption();
throw e;
} finally {
statement.close();
}
- logTimeStat(sql, timeStart);
- return n;
}
@Override
@@ -2027,12 +2040,7 @@
logTimeStat(sql, beginMillis, null);
}
- /* package */ void logTimeStat(String sql, long beginMillis, String prefix) {
- // Keep track of the last statement executed here, as this is
- // the common funnel through which all methods of hitting
- // libsqlite eventually flow.
- mLastSqlStatement = sql;
-
+ private void logTimeStat(String sql, long beginMillis, String prefix) {
// 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.
@@ -2059,7 +2067,6 @@
if (prefix != null) {
sql = prefix + sql;
}
-
if (sql.length() > QUERY_LOG_SQL_LENGTH) sql = sql.substring(0, QUERY_LOG_SQL_LENGTH);
// ActivityThread.currentPackageName() only returns non-null if the