From b729f4dc84a3e671af5b85c4dfbf004f78f6195a Mon Sep 17 00:00:00 2001 From: Peter Serwylo Date: Fri, 9 Jun 2017 09:37:46 +1000 Subject: [PATCH] Add slow query logging to updateSuggestedFrom* methods. Produces the following output: D Explain: D SCAN TABLE fdroid_app D EXECUTE CORRELATED SCALAR SUBQUERY 0 D SEARCH TABLE fdroid_apk USING INDEX apk_vercode D EXECUTE CORRELATED SCALAR SUBQUERY 1 D SEARCH TABLE fdroid_app AS innerAppName USING INTEGER PRIMARY KEY (rowid=?) D EXECUTE CORRELATED SCALAR SUBQUERY 2 D SEARCH TABLE fdroid_package AS pkg USING INTEGER PRIMARY KEY (rowid=?) D SEARCH TABLE fdroid_installedApp AS installed USING INDEX sqlite_autoindex_fdroid_installedApp_1 (appId=?) There are two possibilities here, one is the number of correlated sub queries (three seems a bit excessive). Alterantively, it could be the fact that one of the inner queries is using a string index (appId=?) instead of an integer primary key. --- .../org/fdroid/fdroid/data/AppProvider.java | 4 ++-- .../org/fdroid/fdroid/data/LoggingQuery.java | 18 ++++++++++++++++++ 2 files changed, 20 insertions(+), 2 deletions(-) diff --git a/app/src/main/java/org/fdroid/fdroid/data/AppProvider.java b/app/src/main/java/org/fdroid/fdroid/data/AppProvider.java index 4c5c3b2f7..5ea9e1a6e 100644 --- a/app/src/main/java/org/fdroid/fdroid/data/AppProvider.java +++ b/app/src/main/java/org/fdroid/fdroid/data/AppProvider.java @@ -985,7 +985,7 @@ public class AppProvider extends FDroidProvider { " ( " + app + "." + Cols.IS_COMPATIBLE + " = 0 OR " + apk + "." + Cols.IS_COMPATIBLE + " = 1 ) ) " + " WHERE " + Cols.UPSTREAM_VERSION_CODE + " > 0 "; - db().execSQL(updateSql); + LoggingQuery.execSQL(db(), updateSql); } /** @@ -1015,7 +1015,7 @@ public class AppProvider extends FDroidProvider { " ( " + app + "." + Cols.IS_COMPATIBLE + " = 0 OR " + apk + "." + ApkTable.Cols.IS_COMPATIBLE + " = 1 ) ) " + " WHERE COALESCE(" + Cols.UPSTREAM_VERSION_CODE + ", 0) = 0 OR " + Cols.SUGGESTED_VERSION_CODE + " IS NULL "; - db().execSQL(updateSql); + LoggingQuery.execSQL(db(), updateSql); } /** diff --git a/app/src/main/java/org/fdroid/fdroid/data/LoggingQuery.java b/app/src/main/java/org/fdroid/fdroid/data/LoggingQuery.java index 9eb40417b..db6731307 100644 --- a/app/src/main/java/org/fdroid/fdroid/data/LoggingQuery.java +++ b/app/src/main/java/org/fdroid/fdroid/data/LoggingQuery.java @@ -66,6 +66,20 @@ final class LoggingQuery { return db.rawQuery(query, queryArgs); } + private void execSQLInternal() { + if (BuildConfig.DEBUG) { + long startTime = System.currentTimeMillis(); + db.execSQL(query); + long queryDuration = System.currentTimeMillis() - startTime; + + if (queryDuration >= SLOW_QUERY_DURATION) { + logSlowQuery(queryDuration); + } + } else { + db.execSQL(query); + } + } + /** * Log the query and its duration to the console. In addition, execute an "EXPLAIN QUERY PLAN" * for the query in question so that the query can be diagnosed (https://sqlite.org/eqp.html) @@ -116,4 +130,8 @@ final class LoggingQuery { public static Cursor query(SQLiteDatabase db, String query, String[] queryBuilderArgs) { return new LoggingQuery(db, query, queryBuilderArgs).rawQuery(); } + + public static void execSQL(SQLiteDatabase db, String sql) { + new LoggingQuery(db, sql, null).execSQLInternal(); + } }