Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit a761d2b3 authored by Makoto Onuki's avatar Makoto Onuki
Browse files

Rework slow-query log 

- Allow per-uid slow query log with "db.log.slow_query_threshold.UID"
- Add db.log.bindargs to enable bind args log in slow query log
 (debuggable build only)

Bug: 111210683
Test: setprop db.log.slow_query_threshold 0 -> slow query log enabled for all processes
Test: setprop db.log.slow_query_threshold.ACORE-UID 0 -> slow query log enabled for acore
Test: setprop db.log.bindargs 1  + setprop db.log.slow_query_threshold.ACORE-UID 0 + kill acore ->
  Bind args also logged

Change-Id: I3e85479e0c946308837b827f856016bc4fbe1ea3
parent f15bbe2e

api/test-current.txt

+0 −3
Original line number Diff line number Diff line
@@ -314,9 +314,6 @@ package android.database.sqlite { 
  public final class SQLiteDebug {

    method public static void dump(android.util.Printer, java.lang.String[]);

    method public static android.database.sqlite.SQLiteDebug.PagerStats getDatabaseInfo();

    field public static final boolean DEBUG_SQL_LOG;

    field public static final boolean DEBUG_SQL_STATEMENTS;

    field public static final boolean DEBUG_SQL_TIME;

  }



  public static class SQLiteDebug.DbStats {

core/java/android/database/sqlite/SQLiteConnection.java

+10 −15
Original line number Diff line number Diff line
@@ -19,6 +19,7 @@ package android.database.sqlite; 
import android.database.Cursor;

import android.database.CursorWindow;

import android.database.DatabaseUtils;

import android.database.sqlite.SQLiteDebug.Consts;

import android.database.sqlite.SQLiteDebug.DbStats;

import android.os.CancellationSignal;

import android.os.OperationCanceledException;
@@ -34,7 +35,6 @@ import dalvik.system.CloseGuard; 


import java.text.SimpleDateFormat;

import java.util.ArrayList;

import java.util.Arrays;

import java.util.Date;

import java.util.Map;
@@ -90,8 +90,6 @@ public final class SQLiteConnection implements CancellationSignal.OnCancelListen 
    private static final String TAG = "SQLiteConnection";

    private static final boolean DEBUG = false;



    public static volatile boolean sLocalDebug = false;



    private static final String[] EMPTY_STRING_ARRAY = new String[0];

    private static final byte[] EMPTY_BYTE_ARRAY = new byte[0];
@@ -212,7 +210,7 @@ public final class SQLiteConnection implements CancellationSignal.OnCancelListen 
    private void open() {

        mConnectionPtr = nativeOpen(mConfiguration.path, mConfiguration.openFlags,

                mConfiguration.label,

                SQLiteDebug.DEBUG_SQL_STATEMENTS, SQLiteDebug.DEBUG_SQL_TIME,

                SQLiteDebug.Consts.DEBUG_SQL_STATEMENTS, SQLiteDebug.Consts.DEBUG_SQL_TIME,

                mConfiguration.lookasideSlotSize, mConfiguration.lookasideSlotCount);

        setPageSize();

        setForeignKeyModeFromConfiguration();
@@ -993,10 +991,6 @@ public final class SQLiteConnection implements CancellationSignal.OnCancelListen 
    }



    private void bindArguments(PreparedStatement statement, Object[] bindArgs) {

        if (sLocalDebug) {

            Log.v(TAG, statement.mSql + " with args " + Arrays.toString(bindArgs));

        }



        final int count = bindArgs != null ? bindArgs.length : 0;

        if (count != statement.mNumParameters) {

            throw new SQLiteBindOrColumnIndexOutOfRangeException(
@@ -1097,7 +1091,7 @@ public final class SQLiteConnection implements CancellationSignal.OnCancelListen 
        printer.println("  isPrimaryConnection: " + mIsPrimaryConnection);

        printer.println("  onlyAllowReadOnlyOperations: " + mOnlyAllowReadOnlyOperations);



        mRecentOperations.dump(printer, verbose);

        mRecentOperations.dump(printer);



        if (verbose) {

            mPreparedStatementCache.dump(printer);
@@ -1407,7 +1401,7 @@ public final class SQLiteConnection implements CancellationSignal.OnCancelListen 
                operation.mFinished = true;

                final long execTime = operation.mEndTime - operation.mStartTime;

                mPool.onStatementExecuted(execTime);

                return SQLiteDebug.DEBUG_LOG_SLOW_QUERIES && SQLiteDebug.shouldLogSlowQuery(

                return SQLiteDebug.Consts.DEBUG_LOG_SLOW_QUERIES && SQLiteDebug.shouldLogSlowQuery(

                        execTime);

            }

            return false;
@@ -1416,7 +1410,7 @@ public final class SQLiteConnection implements CancellationSignal.OnCancelListen 
        private void logOperationLocked(int cookie, String detail) {

            final Operation operation = getOperationLocked(cookie);

            StringBuilder msg = new StringBuilder();

            operation.describe(msg, false);

            operation.describe(msg, true);

            if (detail != null) {

                msg.append(", ").append(detail);

            }
@@ -1446,7 +1440,7 @@ public final class SQLiteConnection implements CancellationSignal.OnCancelListen 
            }

        }



        public void dump(Printer printer, boolean verbose) {

        public void dump(Printer printer) {

            synchronized (mOperations) {

                printer.println("  Most recently executed operations:");

                int index = mIndex;
@@ -1463,7 +1457,7 @@ public final class SQLiteConnection implements CancellationSignal.OnCancelListen 
                        String formattedStartTime = opDF.format(new Date(operation.mStartWallTime));

                        msg.append(formattedStartTime);

                        msg.append("] ");

                        operation.describe(msg, verbose);

                        operation.describe(msg, false); // Never dump bingargs in a bugreport

                        printer.println(msg.toString());



                        if (index > 0) {
@@ -1498,7 +1492,7 @@ public final class SQLiteConnection implements CancellationSignal.OnCancelListen 
        public Exception mException;

        public int mCookie;



        public void describe(StringBuilder msg, boolean verbose) {

        public void describe(StringBuilder msg, boolean allowBindArgsLog) {

            msg.append(mKind);

            if (mFinished) {

                msg.append(" took ").append(mEndTime - mStartTime).append("ms");
@@ -1510,7 +1504,8 @@ public final class SQLiteConnection implements CancellationSignal.OnCancelListen 
            if (mSql != null) {

                msg.append(", sql=\"").append(trimSqlForDisplay(mSql)).append("\"");

            }

            if (verbose && mBindArgs != null && mBindArgs.size() != 0) {

            if (allowBindArgsLog && Consts.DEBUG_LOG_BIND_ARGS

                    && mBindArgs != null && mBindArgs.size() != 0) {

                msg.append(", bindArgs=[");

                final int count = mBindArgs.size();

                for (int i = 0; i < count; i++) {

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

+51 −27
Original line number Diff line number Diff line
@@ -18,6 +18,7 @@ package android.database.sqlite; 


import android.annotation.TestApi;

import android.os.Build;

import android.os.Process;

import android.os.SystemProperties;

import android.util.Log;

import android.util.Printer;
@@ -33,6 +34,12 @@ import java.util.ArrayList; 
public final class SQLiteDebug {

    private static native void nativeGetPagerStats(PagerStats stats);



    /**

     * Inner class to avoid getting the value frozen in zygote.

     *

     * {@hide}

     */

    public static final class Consts {

        /**

         * Controls the printing of informational SQL log messages.

         *
@@ -58,12 +65,24 @@ public final class SQLiteDebug { 
        public static final boolean DEBUG_SQL_TIME =

                Log.isLoggable("SQLiteTime", Log.VERBOSE);





        /**

         * True to enable database performance testing instrumentation.

     * @hide

         */

        public static final boolean DEBUG_LOG_SLOW_QUERIES = Build.IS_DEBUGGABLE;



        private static final String SLOW_QUERY_THRESHOLD_PROP = "db.log.slow_query_threshold";



        private static final String SLOW_QUERY_THRESHOLD_UID_PROP =

                SLOW_QUERY_THRESHOLD_PROP + "." + Process.myUid();



        /**

         * Whether to log bind args in slow query log or not.

         */

        public static final boolean DEBUG_LOG_BIND_ARGS = Build.IS_DEBUGGABLE

                && SystemProperties.getBoolean("db.log.bindargs", false);

    }



    private SQLiteDebug() {

    }
@@ -75,14 +94,19 @@ public final class SQLiteDebug { 
     * be considered slow.  If the value does not exist or is negative, then no queries will

     * be considered slow.

     *

     * To enable it for a specific UID, "db.log.slow_query_threshold.UID" could also be used.

     *

     * This value can be changed dynamically while the system is running.

     * For example, "adb shell setprop db.log.slow_query_threshold 200" will

     * log all queries that take 200ms or longer to run.

     * @hide

     */

    public static final boolean shouldLogSlowQuery(long elapsedTimeMillis) {

        int slowQueryMillis = SystemProperties.getInt("db.log.slow_query_threshold", -1);

        return slowQueryMillis >= 0 && elapsedTimeMillis >= slowQueryMillis;

    public static boolean shouldLogSlowQuery(long elapsedTimeMillis) {

        final int slowQueryMillis = Math.min(

                SystemProperties.getInt(Consts.SLOW_QUERY_THRESHOLD_PROP, Integer.MAX_VALUE),

                SystemProperties.getInt(Consts.SLOW_QUERY_THRESHOLD_UID_PROP,

                        Integer.MAX_VALUE));

        return elapsedTimeMillis >= slowQueryMillis;

    }



    /**