mirror of
https://github.com/signalapp/Signal-Android.git
synced 2026-07-11 00:08:27 +01:00
Log query analysis of slow queries for internal users.
This commit is contained in:
Greyson Parrelli
committed by
Alex Hart
Alex Hart
parent
48f55bba0a
commit
089d47936b
@@ -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> E traceSql(String methodName, String table, String query, boolean locked, Returnable<E> returnable) {
|
||||
return traceSql(methodName, table, query, locked, null, null, returnable);
|
||||
}
|
||||
|
||||
private <E> E traceSql(String methodName, String table, String query, boolean locked, String queryPlanSql, Object[] queryPlanArgs, Returnable<E> 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<String, Object> 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<String, Object> 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;
|
||||
|
||||
Reference in New Issue
Block a user