use sqlite 3.6.22 to print and profile the sql statetements

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.

6 files changed, 33 insertions, 196 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;