diff --git a/app/src/main/java/org/thoughtcrime/securesms/database/IssueReporter.kt b/app/src/main/java/org/thoughtcrime/securesms/database/IssueReporter.kt index aa50063a47..c41f31bc4d 100644 --- a/app/src/main/java/org/thoughtcrime/securesms/database/IssueReporter.kt +++ b/app/src/main/java/org/thoughtcrime/securesms/database/IssueReporter.kt @@ -40,11 +40,14 @@ object IssueReporter { const val ISSUE_SLOW_DATABASE_WRITE = "Slow Database Write" const val ISSUE_SLOW_DATABASE_READ = "Slow Database Read" + const val ISSUE_SLOW_DATABASE_LOCK = "Slow Database Lock" const val SLOW_WRITE_LOW_PRIORITY_MS = 1_000L const val SLOW_WRITE_MEDIUM_PRIORITY_MS = 5_000L const val SLOW_READ_LOW_PRIORITY_MS = 3_000L const val SLOW_READ_MEDIUM_PRIORITY_MS = 10_000L + const val SLOW_LOCK_LOW_PRIORITY_MS = 1_000L + const val SLOW_LOCK_MEDIUM_PRIORITY_MS = 5_000L private const val NON_INTERNAL_DEBOUNCE_MS = 5_000L @@ -101,6 +104,25 @@ object IssueReporter { report(ISSUE_SLOW_DATABASE_WRITE, query?.trim() ?: "", throwable, priority = priority, duration = durationMs) } + /** + * Notes time spent waiting to acquire the write lock to begin a transaction. This is distinct from a slow write: the + * write itself may be fast, but it was blocked waiting on another holder of the lock (e.g. a long-running transaction). + */ + @JvmStatic + fun noteSlowDatabaseLockAcquire(durationMs: Long, throwable: Throwable) { + if (isExpectedSlowDatabaseOperation()) { + return + } + + val priority = when { + durationMs >= SLOW_LOCK_MEDIUM_PRIORITY_MS -> IssuePriority.MEDIUM + durationMs >= SLOW_LOCK_LOW_PRIORITY_MS -> IssuePriority.LOW + else -> return + } + + report(ISSUE_SLOW_DATABASE_LOCK, "Long wait to acquire the write lock to BEGIN a transaction.", throwable, priority = priority, duration = durationMs) + } + @JvmStatic fun noteSlowDatabaseRead(query: String?, durationMs: Long, throwable: Throwable) { if (isExpectedSlowDatabaseOperation()) { 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 0f177624a6..a12f57daf4 100644 --- a/app/src/main/java/org/thoughtcrime/securesms/database/SQLiteDatabase.java +++ b/app/src/main/java/org/thoughtcrime/securesms/database/SQLiteDatabase.java @@ -327,10 +327,10 @@ public class SQLiteDatabase implements SupportSQLiteDatabase { } }); long waitMs = (System.nanoTime() - waitStartNs) / 1_000_000L; - if (waitMs >= IssueReporter.SLOW_WRITE_LOW_PRIORITY_MS) { + if (waitMs >= IssueReporter.SLOW_LOCK_LOW_PRIORITY_MS) { Throwable throwable = new Throwable(); Log.w(TAG, "Slow write-lock acquire: waited " + waitMs + "ms to BEGIN", throwable); - IssueReporter.noteSlowDatabaseWrite("BEGIN", waitMs, throwable); + IssueReporter.noteSlowDatabaseLockAcquire(waitMs, throwable); } TRANSACTION_HOLD_START_NS.set(System.nanoTime()); });