diff options
8 files changed, 91 insertions, 243 deletions
diff --git a/core/java/android/database/sqlite/SQLiteClosable.java b/core/java/android/database/sqlite/SQLiteClosable.java index f64261c1d0f9..7776520f3cd7 100644 --- a/core/java/android/database/sqlite/SQLiteClosable.java +++ b/core/java/android/database/sqlite/SQLiteClosable.java @@ -29,7 +29,7 @@ public abstract class SQLiteClosable { synchronized(mLock) { if (mReferenceCount <= 0) { throw new IllegalStateException( - "attempt to acquire a reference on a close SQLiteClosable"); + "attempt to acquire a reference on an already-closed SQLiteClosable obj."); } mReferenceCount++; } diff --git a/core/java/android/database/sqlite/SQLiteDatabase.java b/core/java/android/database/sqlite/SQLiteDatabase.java index 22e2a8351f32..c6548dcb26f7 100644 --- a/core/java/android/database/sqlite/SQLiteDatabase.java +++ b/core/java/android/database/sqlite/SQLiteDatabase.java @@ -290,10 +290,6 @@ public class SQLiteDatabase extends SQLiteClosable { @Override protected void onAllReferencesReleased() { if (isOpen()) { - if (SQLiteDebug.DEBUG_CAPTURE_SQL) { - Log.d(TAG, "captured_sql|" + mPath + "|DETACH DATABASE " + - getDatabaseName(mPath) + ";"); - } if (SQLiteDebug.DEBUG_SQL_CACHE) { mTimeClosed = getTime(); } @@ -782,7 +778,14 @@ public class SQLiteDatabase extends SQLiteClosable { SQLiteDatabase db = null; try { // Open the database. - return new SQLiteDatabase(path, factory, flags); + SQLiteDatabase sqliteDatabase = new SQLiteDatabase(path, factory, flags); + if (SQLiteDebug.DEBUG_SQL_STATEMENTS) { + sqliteDatabase.enableSqlTracing(path); + } + if (SQLiteDebug.DEBUG_SQL_TIME) { + sqliteDatabase.enableSqlProfiling(path); + } + return sqliteDatabase; } catch (SQLiteDatabaseCorruptException e) { // Try to recover from this, if we can. // TODO: should we do this for other open failures? @@ -1652,9 +1655,6 @@ public class SQLiteDatabase extends SQLiteClosable { */ public void execSQL(String sql) throws SQLException { long timeStart = Debug.threadCpuTimeNanos(); - if (SQLiteDebug.DEBUG_CAPTURE_SQL) { - Log.v(TAG, SQLiteDebug.captureSql(this.getPath(), sql, null)); - } lock(); try { native_execSQL(sql); @@ -1680,9 +1680,6 @@ public class SQLiteDatabase extends SQLiteClosable { if (bindArgs == null) { throw new IllegalArgumentException("Empty bindArgs"); } - if (SQLiteDebug.DEBUG_CAPTURE_SQL) { - Log.v(TAG, SQLiteDebug.captureSql(this.getPath(), sql, bindArgs)); - } long timeStart = Debug.threadCpuTimeNanos(); lock(); SQLiteStatement statement = null; @@ -1741,10 +1738,6 @@ public class SQLiteDatabase extends SQLiteClosable { mLeakedException = new IllegalStateException(path + " SQLiteDatabase created and never closed"); mFactory = factory; - if (SQLiteDebug.DEBUG_CAPTURE_SQL) { - Log.d(TAG, "captured_sql|" + mPath + "|ATTACH DATABASE '" + mPath + - "' as " + getDatabaseName(mPath) + ";"); - } dbopen(mPath, mFlags); if (SQLiteDebug.DEBUG_SQL_CACHE) { mTimeOpened = getTime(); @@ -1754,10 +1747,6 @@ public class SQLiteDatabase extends SQLiteClosable { setLocale(Locale.getDefault()); } catch (RuntimeException e) { Log.e(TAG, "Failed to setLocale() when constructing, closing the database", e); - if (SQLiteDebug.DEBUG_CAPTURE_SQL) { - Log.d(TAG, "captured_sql|" + mPath + "|DETACH DATABASE " + - getDatabaseName(mPath) + ";"); - } dbclose(); if (SQLiteDebug.DEBUG_SQL_CACHE) { mTimeClosed = getTime(); @@ -1770,20 +1759,6 @@ public class SQLiteDatabase extends SQLiteClosable { return new SimpleDateFormat("yyyy-MM-dd HH:mm:ss.SSS ").format(System.currentTimeMillis()); } - private String getDatabaseName(String path) { - if (path == null || path.trim().length() == 0) { - return "db not specified?"; - } - - if (path.equalsIgnoreCase(":memory:")) { - return "memorydb"; - } - String[] tokens = path.split("/"); - String[] lastNodeTokens = tokens[tokens.length - 1].split("\\.", 2); - return (lastNodeTokens.length == 1) ? lastNodeTokens[0] - : lastNodeTokens[0] + lastNodeTokens[1]; - } - /** * return whether the DB is opened as read only. * @return true if DB is opened as read only @@ -2062,6 +2037,23 @@ public class SQLiteDatabase extends SQLiteClosable { private native void dbopen(String path, int flags); /** + * Native call to setup tracing of all sql statements + * + * @param path the full path to the database + */ + private native void enableSqlTracing(String path); + + /** + * Native call to setup profiling of all sql statements. + * currently, sqlite's profiling = printing of execution-time + * (wall-clock time) of each of the sql statements, as they + * are executed. + * + * @param path the full path to the database + */ + private native void enableSqlProfiling(String path); + + /** * Native call to execute a raw SQL statement. {@link #lock} must be held * when calling this method. * diff --git a/core/java/android/database/sqlite/SQLiteDebug.java b/core/java/android/database/sqlite/SQLiteDebug.java index b12034af1f60..4ea680e44b6f 100644 --- a/core/java/android/database/sqlite/SQLiteDebug.java +++ b/core/java/android/database/sqlite/SQLiteDebug.java @@ -31,17 +31,17 @@ public final class SQLiteDebug { Log.isLoggable("SQLiteStatements", Log.VERBOSE); /** - * Controls the printing of compiled-sql-statement cache stats. + * Controls the printing of wall-clock time taken to execute SQL statements + * as they are executed. */ - public static final boolean DEBUG_SQL_CACHE = - Log.isLoggable("SQLiteCompiledSql", Log.VERBOSE); + public static final boolean DEBUG_SQL_TIME = + Log.isLoggable("SQLiteTime", Log.VERBOSE); /** - * Controls the capturing and printing of complete sql statement including the bind args and - * the database name. + * Controls the printing of compiled-sql-statement cache stats. */ - public static final boolean DEBUG_CAPTURE_SQL = - Log.isLoggable("SQLiteCaptureSql", Log.VERBOSE); + public static final boolean DEBUG_SQL_CACHE = + Log.isLoggable("SQLiteCompiledSql", Log.VERBOSE); /** * Controls the stack trace reporting of active cursors being @@ -121,62 +121,4 @@ public final class SQLiteDebug { static synchronized void notifyActiveCursorFinalized() { sNumActiveCursorsFinalized++; } - - /** - * returns a message containing the given database name (path) and the string built by - * replacing "?" characters in the given sql string with the corresponding - * positional values from the given param bindArgs. - * - * @param path the database name - * @param sql sql string with possibly "?" for bindargs - * @param bindArgs args for "?"s in the above string - * @return the String to be logged - */ - /* package */ static String captureSql(String path, String sql, Object[] bindArgs) { - // how many bindargs in sql - sql = sql.trim(); - String args[] = sql.split("\\?"); - // how many "?"s in the given sql string? - int varArgsInSql = (sql.endsWith("?")) ? args.length : args.length - 1; - - // how many bind args do we have in the given input param bindArgs - int bindArgsLen = (bindArgs == null) ? 0 : bindArgs.length; - if (varArgsInSql < bindArgsLen) { - return "too many bindArgs provided. " + - "# of bindArgs = " + bindArgsLen + ", # of varargs = " + varArgsInSql + - "; sql = " + sql; - } - - // if there are no bindArgs, we are done. log the sql as is. - if (bindArgsLen == 0 && varArgsInSql == 0) { - return logSql(path, sql); - } - - StringBuilder buf = new StringBuilder(); - - // take the supplied bindArgs and plug them into sql - for (int i = 0; i < bindArgsLen; i++) { - buf.append(args[i]); - buf.append(bindArgs[i]); - } - - // does given sql have more varArgs than the supplied bindArgs - // if so, assign nulls to the extra varArgs in sql - for (int i = bindArgsLen; i < varArgsInSql; i ++) { - buf.append(args[i]); - buf.append("null"); - } - - // if there are any characters left in the given sql string AFTER the last "?" - // log them also. for example, if the given sql = "select * from test where a=? and b=1 - // then the following code appends " and b=1" string to buf. - if (varArgsInSql < args.length) { - buf.append(args[varArgsInSql]); - } - return logSql(path, buf.toString()); - } - - private static String logSql(String path, String sql) { - return "captured_sql|" + path + "|" + sql + ";"; - } } diff --git a/core/java/android/database/sqlite/SQLiteProgram.java b/core/java/android/database/sqlite/SQLiteProgram.java index 1159c1de74c5..a0aa0191f4f4 100644 --- a/core/java/android/database/sqlite/SQLiteProgram.java +++ b/core/java/android/database/sqlite/SQLiteProgram.java @@ -16,19 +16,10 @@ package android.database.sqlite; -import java.util.ArrayList; -import java.util.Collections; -import java.util.HashMap; -import java.util.Map; -import java.util.Set; - -import android.util.Log; - /** * A base class for compiled SQLite programs. */ public abstract class SQLiteProgram extends SQLiteClosable { - private static final String TAG = "SQLiteProgram"; /** The database this program is compiled against. */ protected SQLiteDatabase mDatabase; @@ -53,16 +44,7 @@ public abstract class SQLiteProgram extends SQLiteClosable { */ protected int nStatement = 0; - /** - * stores all bindargs for debugging purposes - */ - private Map<Integer, String> mBindArgs = null; - /* package */ SQLiteProgram(SQLiteDatabase db, String sql) { - if (SQLiteDebug.DEBUG_SQL_STATEMENTS) { - Log.d(TAG, "processing sql: " + sql); - } - mDatabase = db; mSql = sql; db.acquireReference(); @@ -138,9 +120,6 @@ public abstract class SQLiteProgram extends SQLiteClosable { * @param index The 1-based index to the parameter to bind null to */ public void bindNull(int index) { - if (SQLiteDebug.DEBUG_CAPTURE_SQL) { - addToBindArgs(index, "null"); - } acquireReference(); try { native_bind_null(index); @@ -157,9 +136,6 @@ public abstract class SQLiteProgram extends SQLiteClosable { * @param value The value to bind */ public void bindLong(int index, long value) { - if (SQLiteDebug.DEBUG_CAPTURE_SQL) { - addToBindArgs(index, value + ""); - } acquireReference(); try { native_bind_long(index, value); @@ -176,9 +152,6 @@ public abstract class SQLiteProgram extends SQLiteClosable { * @param value The value to bind */ public void bindDouble(int index, double value) { - if (SQLiteDebug.DEBUG_CAPTURE_SQL) { - addToBindArgs(index, value + ""); - } acquireReference(); try { native_bind_double(index, value); @@ -195,9 +168,6 @@ public abstract class SQLiteProgram extends SQLiteClosable { * @param value The value to bind */ public void bindString(int index, String value) { - if (SQLiteDebug.DEBUG_CAPTURE_SQL) { - addToBindArgs(index, "'" + value + "'"); - } if (value == null) { throw new IllegalArgumentException("the bind value at index " + index + " is null"); } @@ -217,9 +187,6 @@ public abstract class SQLiteProgram extends SQLiteClosable { * @param value The value to bind */ public void bindBlob(int index, byte[] value) { - if (SQLiteDebug.DEBUG_CAPTURE_SQL) { - addToBindArgs(index, "blob"); - } if (value == null) { throw new IllegalArgumentException("the bind value at index " + index + " is null"); } @@ -235,9 +202,6 @@ public abstract class SQLiteProgram extends SQLiteClosable { * Clears all existing bindings. Unset bindings are treated as NULL. */ public void clearBindings() { - if (SQLiteDebug.DEBUG_CAPTURE_SQL) { - mBindArgs = null; - } acquireReference(); try { native_clear_bindings(); @@ -259,39 +223,6 @@ public abstract class SQLiteProgram extends SQLiteClosable { } /** - * this method is called under the debug flag {@link SQLiteDebug.DEBUG_CAPTURE_SQL} only. - * it collects the bindargs as they are called by the callers the bind... methods in this - * class. - */ - private void addToBindArgs(int index, String obj) { - if (mBindArgs == null) { - mBindArgs = new HashMap<Integer, String>(); - } - mBindArgs.put(index, obj); - } - - /** - * constructs all the bindargs in sequence and returns a String Array of the values. - * it uses the HashMap built up by the above method. - * - * @return the string array of bindArgs with the args arranged in sequence - */ - /* package */ String[] getBindArgs() { - if (mBindArgs == null) { - return null; - } - Set<Integer> indexSet = mBindArgs.keySet(); - ArrayList<Integer> indexList = new ArrayList<Integer>(indexSet); - Collections.sort(indexList); - int len = indexList.size(); - String[] bindObjs = new String[len]; - for (int i = 0; i < len; i++) { - bindObjs[i] = mBindArgs.get(indexList.get(i)); - } - return bindObjs; - } - - /** * Compiles SQL into a SQLite program. * * <P>The database lock must be held when calling this method. diff --git a/core/java/android/database/sqlite/SQLiteQuery.java b/core/java/android/database/sqlite/SQLiteQuery.java index c34661da8385..5bcad4b9a56e 100644 --- a/core/java/android/database/sqlite/SQLiteQuery.java +++ b/core/java/android/database/sqlite/SQLiteQuery.java @@ -18,7 +18,6 @@ package android.database.sqlite; import android.database.CursorWindow; import android.os.Debug; -import android.os.SystemClock; import android.util.Log; /** diff --git a/core/java/android/database/sqlite/SQLiteStatement.java b/core/java/android/database/sqlite/SQLiteStatement.java index 0cee3c526a08..f1f5a2ad2034 100644 --- a/core/java/android/database/sqlite/SQLiteStatement.java +++ b/core/java/android/database/sqlite/SQLiteStatement.java @@ -17,7 +17,6 @@ package android.database.sqlite; import android.os.Debug; -import android.util.Log; /** * A pre-compiled statement against a {@link SQLiteDatabase} that can be reused. @@ -27,8 +26,6 @@ import android.util.Log; */ public class SQLiteStatement extends SQLiteProgram { - private static final String TAG = "SQLiteStatement"; - /** * Don't use SQLiteStatement constructor directly, please use * {@link SQLiteDatabase#compileStatement(String)} @@ -52,12 +49,6 @@ public class SQLiteStatement extends SQLiteProgram acquireReference(); try { - if (SQLiteDebug.DEBUG_SQL_STATEMENTS) { - Log.v(TAG, "execute() for [" + mSql + "]"); - } - if (SQLiteDebug.DEBUG_CAPTURE_SQL) { - Log.v(TAG, SQLiteDebug.captureSql(mDatabase.getPath(), mSql, getBindArgs())); - } native_execute(); mDatabase.logTimeStat(mSql, timeStart); } finally { @@ -82,12 +73,6 @@ public class SQLiteStatement extends SQLiteProgram acquireReference(); try { - if (SQLiteDebug.DEBUG_SQL_STATEMENTS) { - Log.v(TAG, "executeInsert() for [" + mSql + "]"); - } - if (SQLiteDebug.DEBUG_CAPTURE_SQL) { - Log.v(TAG, SQLiteDebug.captureSql(mDatabase.getPath(), mSql, getBindArgs())); - } native_execute(); mDatabase.logTimeStat(mSql, timeStart); return mDatabase.lastInsertRow(); @@ -111,12 +96,6 @@ public class SQLiteStatement extends SQLiteProgram acquireReference(); try { - if (SQLiteDebug.DEBUG_SQL_STATEMENTS) { - Log.v(TAG, "simpleQueryForLong() for [" + mSql + "]"); - } - if (SQLiteDebug.DEBUG_CAPTURE_SQL) { - Log.v(TAG, SQLiteDebug.captureSql(mDatabase.getPath(), mSql, getBindArgs())); - } long retValue = native_1x1_long(); mDatabase.logTimeStat(mSql, timeStart); return retValue; @@ -140,12 +119,6 @@ public class SQLiteStatement extends SQLiteProgram acquireReference(); try { - if (SQLiteDebug.DEBUG_SQL_STATEMENTS) { - Log.v(TAG, "simpleQueryForString() for [" + mSql + "]"); - } - if (SQLiteDebug.DEBUG_CAPTURE_SQL) { - Log.v(TAG, SQLiteDebug.captureSql(mDatabase.getPath(), mSql, getBindArgs())); - } String retValue = native_1x1_string(); mDatabase.logTimeStat(mSql, timeStart); return retValue; diff --git a/core/jni/android_database_SQLiteDatabase.cpp b/core/jni/android_database_SQLiteDatabase.cpp index 020aff4a5c3b..c19701073e82 100644 --- a/core/jni/android_database_SQLiteDatabase.cpp +++ b/core/jni/android_database_SQLiteDatabase.cpp @@ -143,12 +143,68 @@ done: if (handle != NULL) sqlite3_close(handle); } +void sqlTrace(void *databaseName, const char *sql) { + LOGI("sql_statement|%s|%s\n", (char *)databaseName, sql); +} + +/* public native void enableSqlTracing(); */ +static void enableSqlTracing(JNIEnv* env, jobject object, jstring databaseName) +{ + sqlite3 * handle = (sqlite3 *)env->GetIntField(object, offset_db_handle); + char const *path = env->GetStringUTFChars(databaseName, NULL); + if (path == NULL) { + LOGE("Failure in enableSqlTracing(). VM ran out of memory?\n"); + return; // VM would have thrown OutOfMemoryError + } + int len = strlen(path); + char *traceFuncArg = (char *)malloc(len + 1); + strncpy(traceFuncArg, path, len); + traceFuncArg[len-1] = NULL; + env->ReleaseStringUTFChars(databaseName, path); + sqlite3_trace(handle, &sqlTrace, (void *)traceFuncArg); + LOGI("will be printing all sql statements executed on database = %s\n", traceFuncArg); +} + +void sqlProfile(void *databaseName, const char *sql, sqlite3_uint64 tm) { + double d = tm/1000000.0; + LOGI("elapsedTime4Sql|%s|%.3f ms|%s\n", (char *)databaseName, d, sql); +} + +/* public native void enableSqlProfiling(); */ +static void enableSqlProfiling(JNIEnv* env, jobject object, jstring databaseName) +{ + sqlite3 * handle = (sqlite3 *)env->GetIntField(object, offset_db_handle); + char const *path = env->GetStringUTFChars(databaseName, NULL); + if (path == NULL) { + LOGE("Failure in enableSqlProfiling(). VM ran out of memory?\n"); + return; // VM would have thrown OutOfMemoryError + } + int len = strlen(path); + char *traceFuncArg = (char *)malloc(len + 1); + strncpy(traceFuncArg, path, len); + traceFuncArg[len-1] = NULL; + env->ReleaseStringUTFChars(databaseName, path); + sqlite3_profile(handle, &sqlProfile, (void *)traceFuncArg); + LOGI("will be printing execution time of all sql statements executed on database = %s\n", + traceFuncArg); +} + /* public native void close(); */ static void dbclose(JNIEnv* env, jobject object) { sqlite3 * handle = (sqlite3 *)env->GetIntField(object, offset_db_handle); if (handle != NULL) { + // release the memory associated with the traceFuncArg in enableSqlTracing function + void *traceFuncArg = sqlite3_trace(handle, &sqlTrace, NULL); + if (traceFuncArg != NULL) { + free(traceFuncArg); + } + // release the memory associated with the traceFuncArg in enableSqlProfiling function + traceFuncArg = sqlite3_profile(handle, &sqlProfile, NULL); + if (traceFuncArg != NULL) { + free(traceFuncArg); + } LOGV("Closing database: handle=%p\n", handle); int result = sqlite3_close(handle); if (result == SQLITE_OK) { @@ -357,6 +413,8 @@ static JNINativeMethod sMethods[] = /* name, signature, funcPtr */ {"dbopen", "(Ljava/lang/String;I)V", (void *)dbopen}, {"dbclose", "()V", (void *)dbclose}, + {"enableSqlTracing", "(Ljava/lang/String;)V", (void *)enableSqlTracing}, + {"enableSqlProfiling", "(Ljava/lang/String;)V", (void *)enableSqlProfiling}, {"native_execSQL", "(Ljava/lang/String;)V", (void *)native_execSQL}, {"lastInsertRow", "()J", (void *)lastInsertRow}, {"lastChangeCount", "()I", (void *)lastChangeCount}, diff --git a/core/tests/coretests/src/android/database/sqlite/SQLiteDebugTest.java b/core/tests/coretests/src/android/database/sqlite/SQLiteDebugTest.java deleted file mode 100644 index ea807bd64cb5..000000000000 --- a/core/tests/coretests/src/android/database/sqlite/SQLiteDebugTest.java +++ /dev/null @@ -1,47 +0,0 @@ -/* - * Copyright (C) 2008 The Android Open Source Project - * - * Licensed under the Apache License, Version 2.0 (the "License"); - * you may not use this file except in compliance with the License. - * You may obtain a copy of the License at - * - * http://www.apache.org/licenses/LICENSE-2.0 - * - * Unless required by applicable law or agreed to in writing, software - * distributed under the License is distributed on an "AS IS" BASIS, - * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. - * See the License for the specific language governing permissions and - * limitations under the License. - */ - -package android.database.sqlite; - -import junit.framework.TestCase; - -/** - * Tests for the SQLiteDebug - */ -public class SQLiteDebugTest extends TestCase { - private static final String TEST_DB = "test.db"; - - public void testCaptureSql() { - String rslt = SQLiteDebug.captureSql(TEST_DB, "select * from t1 where a=? and b=1", - new Object[] {"blah"}); - String expectedVal = "select * from t1 where a='blah' and b=1"; - assertTrue(rslt.equals("captured_sql|" + TEST_DB + "|" + expectedVal)); - - rslt = SQLiteDebug.captureSql(TEST_DB, "select * from t1 where a=?", - new Object[] {"blah"}); - expectedVal = "select * from t1 where a='blah'"; - assertTrue(rslt.equals("captured_sql|" + TEST_DB + "|" + expectedVal)); - - rslt = SQLiteDebug.captureSql(TEST_DB, "select * from t1 where a=1", - new Object[] {"blah"}); - assertTrue(rslt.startsWith("too many bindArgs provided.")); - - rslt = SQLiteDebug.captureSql(TEST_DB, "update t1 set a=? where b=?", - new Object[] {"blah", "foo"}); - expectedVal = "update t1 set a='blah' where b='foo'"; - assertTrue(rslt.equals("captured_sql|" + TEST_DB + "|" + expectedVal)); - } -} |