Merge "add instrumentation to log the sql statement + bindargs + databasename" (8fccf67f) · Commits · e / os / android_frameworks_base

core/java/android/database/sqlite/SQLiteDatabase.java

+32 −1

Original line number	Diff line number	Diff line
		@@ -290,6 +290,10 @@ 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();
		}
		@@ -1648,6 +1652,9 @@ 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);
		@@ -1673,7 +1680,9 @@ 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;
		@@ -1732,6 +1741,10 @@ 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();
		@@ -1741,6 +1754,10 @@ 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();
		@@ -1753,6 +1770,20 @@ 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

core/java/android/database/sqlite/SQLiteDebug.java

+71 −7

Original line number	Diff line number	Diff line
		@@ -16,7 +16,6 @@

		package android.database.sqlite;

		import android.util.Config;
		import android.util.Log;

		/**
		@@ -37,6 +36,13 @@ public final class SQLiteDebug {
		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.
		@@ -115,4 +121,62 @@ 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 + ";";
		}
		}

core/java/android/database/sqlite/SQLiteProgram.java

+62 −0

Original line number	Diff line number	Diff line
		@@ -16,6 +16,12 @@

		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;

		/**
		@@ -47,6 +53,11 @@ 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);
		@@ -127,6 +138,9 @@ 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);
		@@ -143,6 +157,9 @@ 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);
		@@ -159,6 +176,9 @@ 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);
		@@ -175,6 +195,9 @@ 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");
		}
		@@ -194,6 +217,9 @@ 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");
		}
		@@ -209,6 +235,9 @@ 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();
		@@ -229,6 +258,39 @@ 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.
		*

core/java/android/database/sqlite/SQLiteStatement.java

+12 −1

Original line number	Diff line number	Diff line
		@@ -17,7 +17,6 @@
		package android.database.sqlite;

		import android.os.Debug;
		import android.os.SystemClock;
		import android.util.Log;

		/**
		@@ -56,6 +55,9 @@ public class SQLiteStatement extends SQLiteProgram
		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 {
		@@ -83,6 +85,9 @@ public class SQLiteStatement extends SQLiteProgram
		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();
		@@ -109,6 +114,9 @@ public class SQLiteStatement extends SQLiteProgram
		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;
		@@ -135,6 +143,9 @@ public class SQLiteStatement extends SQLiteProgram
		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;

core/tests/coretests/src/android/database/sqlite/SQLiteDebugTest.java

0 → 100644

+47 −0

Original line number	Diff line number	Diff line
		/*
		* 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));
		}
		}