From 089d47936b4e7ee53156263b7ce8c09b0d74e078 Mon Sep 17 00:00:00 2001 From: Greyson Parrelli Date: Tue, 2 Jun 2026 01:05:26 -0400 Subject: [PATCH] Log query analysis of slow queries for internal users. --- .../securesms/database/SQLiteDatabase.java | 161 ++++++++++++++++-- 1 file changed, 143 insertions(+), 18 deletions(-) diff --git a/app/src/main/java/org/thoughtcrime/securesms/database/SQLiteDatabase.java b/app/src/main/java/org/thoughtcrime/securesms/database/SQLiteDatabase.java index 811affd8ea..1a8664c8af 100644 --- a/app/src/main/java/org/thoughtcrime/securesms/database/SQLiteDatabase.java +++ b/app/src/main/java/org/thoughtcrime/securesms/database/SQLiteDatabase.java @@ -12,6 +12,7 @@ import androidx.sqlite.db.SupportSQLiteDatabase; import androidx.sqlite.db.SupportSQLiteQuery; import net.zetetic.database.sqlcipher.SQLiteStatement; +import net.zetetic.database.sqlcipher.SQLiteQueryBuilder; import net.zetetic.database.sqlcipher.SQLiteTransactionListener; import org.signal.core.util.logging.Log; @@ -94,6 +95,10 @@ public class SQLiteDatabase implements SupportSQLiteDatabase { } private void traceSql(String methodName, String query, boolean locked, Runnable returnable) { + traceSql(methodName, query, locked, null, null, returnable); + } + + private void traceSql(String methodName, String query, boolean locked, String queryPlanSql, Object[] queryPlanArgs, Runnable returnable) { if (locked) { traceLockStart(); } @@ -102,7 +107,7 @@ public class SQLiteDatabase implements SupportSQLiteDatabase { long startNs = slowWriteLoggingEnabled && locked ? System.nanoTime() : 0L; returnable.run(); if (slowWriteLoggingEnabled && locked) { - warnIfSlowDirectWrite(methodName, null, query, startNs); + warnIfSlowDirectWrite(methodName, null, query, queryPlanSql, queryPlanArgs, startNs); } tracer.end(methodName); @@ -116,6 +121,10 @@ public class SQLiteDatabase implements SupportSQLiteDatabase { } private E traceSql(String methodName, String table, String query, boolean locked, Returnable returnable) { + return traceSql(methodName, table, query, locked, null, null, returnable); + } + + private E traceSql(String methodName, String table, String query, boolean locked, String queryPlanSql, Object[] queryPlanArgs, Returnable returnable) { if (locked) { traceLockStart(); } @@ -137,9 +146,9 @@ public class SQLiteDatabase implements SupportSQLiteDatabase { } if (slowWriteLoggingEnabled) { if (locked) { - warnIfSlowDirectWrite(methodName, table, query, startNs); + warnIfSlowDirectWrite(methodName, table, query, queryPlanSql, queryPlanArgs, startNs); } else { - warnIfSlowQuery(methodName, table, query, startNs); + warnIfSlowQuery(methodName, table, query, queryPlanSql, queryPlanArgs, startNs); } } tracer.end(methodName); @@ -264,13 +273,13 @@ public class SQLiteDatabase implements SupportSQLiteDatabase { @Override public Cursor query(SupportSQLiteQuery query) { DatabaseMonitor.onSql(query.getSql(), null); - return wrapped.query(query); + return traceSql("query(SupportSQLiteQuery)", null, query.getSql(), false, query.getSql(), null, () -> wrapped.query(query)); } @Override public Cursor query(SupportSQLiteQuery query, CancellationSignal cancellationSignal) { DatabaseMonitor.onSql(query.getSql(), null); - return wrapped.query(query, cancellationSignal); + return traceSql("query(SupportSQLiteQuery, CancellationSignal)", null, query.getSql(), false, query.getSql(), null, () -> wrapped.query(query, cancellationSignal)); } @Override @@ -377,42 +386,42 @@ public class SQLiteDatabase implements SupportSQLiteDatabase { public Cursor query(boolean distinct, String table, String[] columns, String selection, String[] selectionArgs, String groupBy, String having, String orderBy, String limit) { DatabaseMonitor.onQuery(distinct, table, columns, selection, selectionArgs, groupBy, having, orderBy, limit); - return traceSql("query(9)", table, selection, false, () -> wrapped.query(distinct, table, columns, selection, selectionArgs, groupBy, having, orderBy, limit)); + return traceSql("query(9)", table, selection, false, buildQueryPlanSql(distinct, table, columns, selection, groupBy, having, orderBy, limit), selectionArgs, () -> wrapped.query(distinct, table, columns, selection, selectionArgs, groupBy, having, orderBy, limit)); } public Cursor queryWithFactory(net.zetetic.database.sqlcipher.SQLiteDatabase.CursorFactory cursorFactory, boolean distinct, String table, String[] columns, String selection, String[] selectionArgs, String groupBy, String having, String orderBy, String limit) { DatabaseMonitor.onQuery(distinct, table, columns, selection, selectionArgs, groupBy, having, orderBy, limit); - return traceSql("queryWithFactory()", table, selection, false, () -> wrapped.queryWithFactory(cursorFactory, distinct, table, columns, selection, selectionArgs, groupBy, having, orderBy, limit)); + return traceSql("queryWithFactory()", table, selection, false, buildQueryPlanSql(distinct, table, columns, selection, groupBy, having, orderBy, limit), selectionArgs, () -> wrapped.queryWithFactory(cursorFactory, distinct, table, columns, selection, selectionArgs, groupBy, having, orderBy, limit)); } public Cursor query(String table, String[] columns, String selection, String[] selectionArgs, String groupBy, String having, String orderBy) { DatabaseMonitor.onQuery(false, table, columns, selection, selectionArgs, groupBy, having, orderBy, null); - return traceSql("query(7)", table, selection, false, () -> wrapped.query(table, columns, selection, selectionArgs, groupBy, having, orderBy)); + return traceSql("query(7)", table, selection, false, buildQueryPlanSql(false, table, columns, selection, groupBy, having, orderBy, null), selectionArgs, () -> wrapped.query(table, columns, selection, selectionArgs, groupBy, having, orderBy)); } public Cursor query(String table, String[] columns, String selection, String[] selectionArgs, String groupBy, String having, String orderBy, String limit) { DatabaseMonitor.onQuery(false, table, columns, selection, selectionArgs, groupBy, having, orderBy, limit); - return traceSql("query(8)", table, selection, false, () -> wrapped.query(table, columns, selection, selectionArgs, groupBy, having, orderBy, limit)); + return traceSql("query(8)", table, selection, false, buildQueryPlanSql(false, table, columns, selection, groupBy, having, orderBy, limit), selectionArgs, () -> wrapped.query(table, columns, selection, selectionArgs, groupBy, having, orderBy, limit)); } public Cursor rawQuery(String sql, String[] selectionArgs) { DatabaseMonitor.onSql(sql, selectionArgs); - return traceSql("rawQuery(2a)", sql, false, () -> wrapped.rawQuery(sql, selectionArgs)); + return traceSql("rawQuery(2a)", null, sql, false, sql, selectionArgs, () -> wrapped.rawQuery(sql, selectionArgs)); } public Cursor rawQuery(String sql, Object... args) { DatabaseMonitor.onSql(sql, args); - return traceSql("rawQuery(2b)", sql, false,() -> wrapped.rawQuery(sql, args)); + return traceSql("rawQuery(2b)", null, sql, false, sql, args, () -> wrapped.rawQuery(sql, args)); } public Cursor rawQueryWithFactory(net.zetetic.database.sqlcipher.SQLiteDatabase.CursorFactory cursorFactory, String sql, String[] selectionArgs, String editTable) { DatabaseMonitor.onSql(sql, selectionArgs); - return traceSql("rawQueryWithFactory()", sql, false, () -> wrapped.rawQueryWithFactory(cursorFactory, sql, selectionArgs, editTable)); + return traceSql("rawQueryWithFactory()", null, sql, false, sql, selectionArgs, () -> wrapped.rawQueryWithFactory(cursorFactory, sql, selectionArgs, editTable)); } public Cursor rawQuery(String sql, String[] selectionArgs, int initialRead, int maxRead) { DatabaseMonitor.onSql(sql, selectionArgs); - return traceSql("rawQuery(4)", sql, false, () -> rawQuery(sql, selectionArgs, initialRead, maxRead)); + return traceSql("rawQuery(4)", null, sql, false, sql, selectionArgs, () -> rawQuery(sql, selectionArgs, initialRead, maxRead)); } public long insert(String table, String nullColumnHack, ContentValues values) { @@ -437,17 +446,17 @@ public class SQLiteDatabase implements SupportSQLiteDatabase { public int delete(String table, String whereClause, String[] whereArgs) { DatabaseMonitor.onDelete(table, whereClause, whereArgs); - return traceSql("delete()", table, whereClause, true, () -> wrapped.delete(table, whereClause, whereArgs)); + return traceSql("delete()", table, whereClause, true, buildDeletePlanSql(table, whereClause), whereArgs, () -> wrapped.delete(table, whereClause, whereArgs)); } public int update(String table, ContentValues values, String whereClause, String[] whereArgs) { DatabaseMonitor.onUpdate(table, values, whereClause, whereArgs); - return traceSql("update()", table, whereClause, true, () -> wrapped.update(table, values, whereClause, whereArgs)); + return traceSql("update()", table, whereClause, true, buildUpdatePlanSql(table, values, whereClause, CONFLICT_NONE), buildUpdatePlanArgs(values, whereArgs), () -> wrapped.update(table, values, whereClause, whereArgs)); } public int updateWithOnConflict(String table, ContentValues values, String whereClause, String[] whereArgs, int conflictAlgorithm) { DatabaseMonitor.onUpdate(table, values, whereClause, whereArgs); - return traceSql("updateWithOnConflict()", table, whereClause, true, () -> wrapped.updateWithOnConflict(table, values, whereClause, whereArgs, conflictAlgorithm)); + return traceSql("updateWithOnConflict()", table, whereClause, true, buildUpdatePlanSql(table, values, whereClause, conflictAlgorithm), buildUpdatePlanArgs(values, whereArgs), () -> wrapped.updateWithOnConflict(table, values, whereClause, whereArgs, conflictAlgorithm)); } public void execSQL(String sql) throws SQLException { @@ -566,7 +575,93 @@ public class SQLiteDatabase implements SupportSQLiteDatabase { wrapped.setLocale(locale); } - private void warnIfSlowDirectWrite(String methodName, String table, String query, long startNs) { + private static String buildQueryPlanSql(boolean distinct, String table, String[] columns, String selection, String groupBy, String having, String orderBy, String limit) { + try { + return SQLiteQueryBuilder.buildQueryString(distinct, table, columns, selection, groupBy, having, orderBy, limit); + } catch (Throwable t) { + return null; + } + } + + private static String buildDeletePlanSql(String table, String whereClause) { + try { + StringBuilder sql = new StringBuilder(120); + sql.append("DELETE FROM ").append(table); + if (whereClause != null && whereClause.length() > 0) { + sql.append(" WHERE ").append(whereClause); + } + return sql.toString(); + } catch (Throwable t) { + return null; + } + } + + private static String buildUpdatePlanSql(String table, ContentValues values, String whereClause, int conflictAlgorithm) { + try { + StringBuilder sql = new StringBuilder(120); + sql.append("UPDATE").append(getConflictClause(conflictAlgorithm)).append(" ").append(table).append(" SET "); + + boolean needsSeparator = false; + for (Map.Entry entry : values.valueSet()) { + if (needsSeparator) { + sql.append(","); + } + sql.append(entry.getKey()).append("=?"); + needsSeparator = true; + } + + if (whereClause != null && whereClause.length() > 0) { + sql.append(" WHERE ").append(whereClause); + } + + return sql.toString(); + } catch (Throwable t) { + return null; + } + } + + private static Object[] buildUpdatePlanArgs(ContentValues values, String[] whereArgs) { + try { + int valuesSize = values.size(); + int whereSize = whereArgs != null ? whereArgs.length : 0; + Object[] bindArgs = new Object[valuesSize + whereSize]; + int index = 0; + + for (Map.Entry entry : values.valueSet()) { + bindArgs[index++] = entry.getValue(); + } + + if (whereArgs != null) { + for (String whereArg : whereArgs) { + bindArgs[index++] = whereArg; + } + } + + return bindArgs; + } catch (Throwable t) { + return null; + } + } + + private static String getConflictClause(int conflictAlgorithm) { + switch (conflictAlgorithm) { + case CONFLICT_ROLLBACK: + return " OR ROLLBACK"; + case CONFLICT_ABORT: + return " OR ABORT"; + case CONFLICT_FAIL: + return " OR FAIL"; + case CONFLICT_IGNORE: + return " OR IGNORE"; + case CONFLICT_REPLACE: + return " OR REPLACE"; + case CONFLICT_NONE: + default: + return ""; + } + } + + private void warnIfSlowDirectWrite(String methodName, String table, String query, String queryPlanSql, Object[] queryPlanArgs, long startNs) { if (!slowWriteLoggingEnabled || wrapped.inTransaction()) { return; } @@ -575,10 +670,11 @@ public class SQLiteDatabase implements SupportSQLiteDatabase { if (elapsedMs >= SLOW_DIRECT_WRITE_MS) { Log.w(TAG, "Slow direct write: " + methodName + " on " + table + " took " + elapsedMs + "ms (query=" + query + ")", new Throwable()); + logQueryPlan(methodName, queryPlanSql, queryPlanArgs); } } - private void warnIfSlowQuery(String methodName, String table, String query, long startNs) { + private void warnIfSlowQuery(String methodName, String table, String query, String queryPlanSql, Object[] queryPlanArgs, long startNs) { if (!slowWriteLoggingEnabled) { return; } @@ -587,10 +683,39 @@ public class SQLiteDatabase implements SupportSQLiteDatabase { if (elapsedMs >= SLOW_QUERY_MS) { Log.w(TAG, "Slow query: " + methodName + " on " + table + " took " + elapsedMs + "ms (query=" + query + ")", new Throwable()); + logQueryPlan(methodName, queryPlanSql, queryPlanArgs); SlowTransactionInternalNotifier.onSlowEvent(); } } + private void logQueryPlan(String methodName, String queryPlanSql, Object[] queryPlanArgs) { + if (queryPlanSql == null) { + return; + } + + try (Cursor cursor = queryPlanArgs != null ? wrapped.rawQuery("EXPLAIN QUERY PLAN " + queryPlanSql, queryPlanArgs) + : wrapped.rawQuery("EXPLAIN QUERY PLAN " + queryPlanSql, (String[]) null)) + { + StringBuilder plan = new StringBuilder(); + while (cursor.moveToNext()) { + if (plan.length() > 0) { + plan.append('\n'); + } + plan.append(cursor.getInt(0)) + .append('|') + .append(cursor.getInt(1)) + .append('|') + .append(cursor.getInt(2)) + .append('|') + .append(cursor.getString(3)); + } + + Log.w(TAG, "Slow query plan: " + methodName + " (query=" + queryPlanSql + ")\n" + plan); + } catch (Throwable t) { + Log.w(TAG, "Failed to log slow query plan: " + methodName + " (query=" + queryPlanSql + ")", t); + } + } + private static class ConvertedTransactionListener implements SQLiteTransactionListener { private final android.database.sqlite.SQLiteTransactionListener listener;