Android/frameworks_base
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

use sqlite 3.6.22 to print and profile the sql statetements

Browse Source 
instead of rolling our own trace/profile code in java, lets use
sqlite 3.6.22 features. turns out sqlite does a good job of
printing the sql statements - including the ones from the triggers.
This commit is contained in:
Vasu Nori
2010-02-05 14:49:04 -08:00
parent 5d36c46d2d
commit 3ef94e25b4
8 changed files with 91 additions and 243 deletions
Download Patch File Download Diff File Expand all files Collapse all files

2
core/java/android/database/sqlite/SQLiteClosable.java
View File

@@ -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++;
}

58
core/java/android/database/sqlite/SQLiteDatabase.java
View File

@@ -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
@@ -2061,6 +2036,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.

72
core/java/android/database/sqlite/SQLiteDebug.java
View File

@@ -30,19 +30,19 @@ public final class SQLiteDebug {
public static final boolean DEBUG_SQL_STATEMENTS =
Log.isLoggable("SQLiteStatements", Log.VERBOSE);
/**
* Controls the printing of wall-clock time taken to execute SQL statements
* as they are executed.
*/
public static final boolean DEBUG_SQL_TIME =
Log.isLoggable("SQLiteTime", Log.VERBOSE);
/**
* Controls the printing of compiled-sql-statement cache stats.
*/
public static final boolean DEBUG_SQL_CACHE =
Log.isLoggable("SQLiteCompiledSql", Log.VERBOSE);
/**
* Controls the capturing and printing of complete sql statement including the bind args and
* the database name.
*/
public static final boolean DEBUG_CAPTURE_SQL =
Log.isLoggable("SQLiteCaptureSql", Log.VERBOSE);
/**
* Controls the stack trace reporting of active cursors being
* finalized.
@@ -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 + ";";
}
}

69
core/java/android/database/sqlite/SQLiteProgram.java
View File

@@ -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();
@@ -258,39 +222,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.
*

1
core/java/android/database/sqlite/SQLiteQuery.java
View File

@@ -18,7 +18,6 @@ package android.database.sqlite;
import android.database.CursorWindow;
import android.os.Debug;
import android.os.SystemClock;
import android.util.Log;
/**

27
core/java/android/database/sqlite/SQLiteStatement.java
View File

@@ -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;

58
core/jni/android_database_SQLiteDatabase.cpp
View File

@@ -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},

47
core/tests/coretests/src/android/database/sqlite/SQLiteDebugTest.java
View File

@@ -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));
}
}