Track perf issues in a table, add internal viewer.

This commit is contained in:
Greyson Parrelli
2026-06-09 17:21:47 -04:00
committed by Cody Henthorne
parent 65082893db
commit 53c4069c64
18 changed files with 1220 additions and 343 deletions
@@ -512,8 +512,6 @@ public class ApplicationContext extends Application implements AppForegroundObse
if (RemoteConfig.internalUser()) {
Tracer.getInstance().setMaxBufferSize(35_000);
}
SQLiteDatabase.setSlowWriteLoggingEnabled(RemoteConfig.slowDatabaseNotifications());
}
private void initializePeriodicTasks() {
@@ -256,6 +256,14 @@ class InternalSettingsFragment : DSLSettingsFragment(R.string.preferences__inter
}
)
clickPref(
title = DSLSettingsText.from("App Issues"),
summary = DSLSettingsText.from("View recorded app issues, like slow reads and writes."),
onClick = {
findNavController().safeNavigate(InternalSettingsFragmentDirections.actionInternalSettingsFragmentToInternalIssuesFragment())
}
)
switchPref(
title = DSLSettingsText.from("Disable internal user flag"),
summary = DSLSettingsText.from("Experience life as a non-internal user. Force-stop the app to be an internal user again."),
@@ -267,6 +275,50 @@ class InternalSettingsFragment : DSLSettingsFragment(R.string.preferences__inter
dividerPref()
sectionHeaderPref(DSLSettingsText.from("Playgrounds"))
clickPref(
title = DSLSettingsText.from("SQLite Playground"),
summary = DSLSettingsText.from("Run raw SQLite queries."),
onClick = {
findNavController().safeNavigate(InternalSettingsFragmentDirections.actionInternalSettingsFragmentToInternalSqlitePlaygroundFragment())
}
)
clickPref(
title = DSLSettingsText.from("Backup Playground"),
summary = DSLSettingsText.from("Test backup import/export."),
onClick = {
findNavController().safeNavigate(InternalSettingsFragmentDirections.actionInternalSettingsFragmentToInternalBackupPlaygroundFragment())
}
)
clickPref(
title = DSLSettingsText.from("Storage Service Playground"),
summary = DSLSettingsText.from("Test and view storage service stuff."),
onClick = {
findNavController().safeNavigate(InternalSettingsFragmentDirections.actionInternalSettingsFragmentToInternalStorageServicePlaygroundFragment())
}
)
clickPref(
title = DSLSettingsText.from("SVR Playground"),
summary = DSLSettingsText.from("Quickly test various SVR options and error conditions."),
onClick = {
findNavController().safeNavigate(InternalSettingsFragmentDirections.actionInternalSettingsFragmentToInternalSvrPlaygroundFragment())
}
)
clickPref(
title = DSLSettingsText.from("Data Seeding Playground"),
summary = DSLSettingsText.from("Seed conversations with media files from a folder."),
onClick = {
findNavController().safeNavigate(InternalSettingsFragmentDirections.actionInternalSettingsFragmentToDataSeedingPlaygroundFragment())
}
)
dividerPref()
sectionHeaderPref(DSLSettingsText.from("App UI"))
switchPref(
@@ -315,50 +367,6 @@ class InternalSettingsFragment : DSLSettingsFragment(R.string.preferences__inter
dividerPref()
sectionHeaderPref(DSLSettingsText.from("Playgrounds"))
clickPref(
title = DSLSettingsText.from("SQLite Playground"),
summary = DSLSettingsText.from("Run raw SQLite queries."),
onClick = {
findNavController().safeNavigate(InternalSettingsFragmentDirections.actionInternalSettingsFragmentToInternalSqlitePlaygroundFragment())
}
)
clickPref(
title = DSLSettingsText.from("Backup Playground"),
summary = DSLSettingsText.from("Test backup import/export."),
onClick = {
findNavController().safeNavigate(InternalSettingsFragmentDirections.actionInternalSettingsFragmentToInternalBackupPlaygroundFragment())
}
)
clickPref(
title = DSLSettingsText.from("Storage Service Playground"),
summary = DSLSettingsText.from("Test and view storage service stuff."),
onClick = {
findNavController().safeNavigate(InternalSettingsFragmentDirections.actionInternalSettingsFragmentToInternalStorageServicePlaygroundFragment())
}
)
clickPref(
title = DSLSettingsText.from("SVR Playground"),
summary = DSLSettingsText.from("Quickly test various SVR options and error conditions."),
onClick = {
findNavController().safeNavigate(InternalSettingsFragmentDirections.actionInternalSettingsFragmentToInternalSvrPlaygroundFragment())
}
)
clickPref(
title = DSLSettingsText.from("Data Seeding Playground"),
summary = DSLSettingsText.from("Seed conversations with media files from a folder."),
onClick = {
findNavController().safeNavigate(InternalSettingsFragmentDirections.actionInternalSettingsFragmentToDataSeedingPlaygroundFragment())
}
)
dividerPref()
sectionHeaderPref(DSLSettingsText.from("Miscellaneous"))
clickPref(
@@ -0,0 +1,34 @@
/*
* Copyright 2026 Signal Messenger, LLC
* SPDX-License-Identifier: AGPL-3.0-only
*/
package org.thoughtcrime.securesms.components.settings.app.internal.issues
import androidx.compose.runtime.Composable
import androidx.compose.runtime.LaunchedEffect
import androidx.compose.runtime.getValue
import androidx.fragment.app.viewModels
import androidx.lifecycle.compose.collectAsStateWithLifecycle
import androidx.navigation.fragment.findNavController
import org.signal.core.ui.compose.ComposeFragment
class InternalIssuesFragment : ComposeFragment() {
private val viewModel: InternalIssuesViewModel by viewModels()
@Composable
override fun FragmentContent() {
val state by viewModel.state.collectAsStateWithLifecycle()
LaunchedEffect(Unit) {
viewModel.onEvent(InternalIssuesScreenEvent.Load)
}
InternalIssuesScreen(
state = state,
onEvent = viewModel::onEvent,
onBack = { findNavController().popBackStack() }
)
}
}
@@ -0,0 +1,344 @@
/*
* Copyright 2026 Signal Messenger, LLC
* SPDX-License-Identifier: AGPL-3.0-only
*/
package org.thoughtcrime.securesms.components.settings.app.internal.issues
import android.widget.Toast
import androidx.compose.foundation.ExperimentalFoundationApi
import androidx.compose.foundation.clickable
import androidx.compose.foundation.combinedClickable
import androidx.compose.foundation.layout.Arrangement
import androidx.compose.foundation.layout.Column
import androidx.compose.foundation.layout.Row
import androidx.compose.foundation.layout.Spacer
import androidx.compose.foundation.layout.fillMaxSize
import androidx.compose.foundation.layout.fillMaxWidth
import androidx.compose.foundation.layout.padding
import androidx.compose.foundation.layout.size
import androidx.compose.foundation.lazy.LazyColumn
import androidx.compose.foundation.lazy.items
import androidx.compose.material3.ExperimentalMaterial3Api
import androidx.compose.material3.HorizontalDivider
import androidx.compose.material3.Icon
import androidx.compose.material3.IconButton
import androidx.compose.material3.MaterialTheme
import androidx.compose.material3.ModalBottomSheet
import androidx.compose.material3.Text
import androidx.compose.material3.rememberModalBottomSheetState
import androidx.compose.runtime.Composable
import androidx.compose.runtime.getValue
import androidx.compose.runtime.mutableStateOf
import androidx.compose.runtime.remember
import androidx.compose.runtime.setValue
import androidx.compose.ui.Alignment
import androidx.compose.ui.Modifier
import androidx.compose.ui.graphics.Color
import androidx.compose.ui.platform.LocalClipboardManager
import androidx.compose.ui.platform.LocalContext
import androidx.compose.ui.res.painterResource
import androidx.compose.ui.text.AnnotatedString
import androidx.compose.ui.text.font.FontFamily
import androidx.compose.ui.text.font.FontWeight
import androidx.compose.ui.unit.dp
import org.signal.core.ui.compose.DayNightPreviews
import org.signal.core.ui.compose.Dialogs
import org.signal.core.ui.compose.Previews
import org.signal.core.ui.compose.Rows
import org.signal.core.ui.compose.Scaffolds
import org.signal.core.ui.compose.SignalIcons
import org.thoughtcrime.securesms.R
import org.thoughtcrime.securesms.database.LogDatabase.IssueTable.IssueRecord
import org.thoughtcrime.securesms.database.model.IssuePriority
import java.text.SimpleDateFormat
import java.util.Date
import java.util.Locale
@OptIn(ExperimentalMaterial3Api::class)
@Composable
fun InternalIssuesScreen(
state: InternalIssuesState,
onEvent: (InternalIssuesScreenEvent) -> Unit = {},
onBack: () -> Unit = {}
) {
var showFilterSheet by remember { mutableStateOf(false) }
var showSortSheet by remember { mutableStateOf(false) }
var showClearDialog by remember { mutableStateOf(false) }
Scaffolds.Settings(
title = "App Issues",
onNavigationClick = onBack,
navigationIcon = SignalIcons.ArrowStart.imageVector,
snackbarHost = {},
actions = {
if (state.names.isNotEmpty()) {
IconButton(onClick = { showFilterSheet = true }) {
Icon(painter = painterResource(R.drawable.symbol_filter_24), contentDescription = "Filter")
}
IconButton(onClick = { showSortSheet = true }) {
Icon(painter = painterResource(R.drawable.symbol_list_bullet_24), contentDescription = "Sort")
}
IconButton(onClick = { showClearDialog = true }) {
Icon(painter = SignalIcons.Trash.painter, contentDescription = "Clear")
}
}
}
) { paddingValues ->
Column(
modifier = Modifier
.fillMaxSize()
.padding(paddingValues)
) {
Rows.RadioListRow(
text = "Notification priority threshold",
labels = IssuePriority.entries.map { it.label }.toTypedArray(),
values = IssuePriority.entries.map { it.name }.toTypedArray(),
selectedValue = state.notificationPriority.name,
onSelected = { onEvent(InternalIssuesScreenEvent.SetNotificationPriority(IssuePriority.valueOf(it))) }
)
HorizontalDivider()
if (!state.loading && state.issues.isEmpty()) {
Column(
modifier = Modifier
.fillMaxWidth()
.weight(1f),
horizontalAlignment = Alignment.CenterHorizontally,
verticalArrangement = Arrangement.Center
) {
Text(
text = if (state.nameFilter != null) "No issues match this filter." else "No issues recorded.",
color = MaterialTheme.colorScheme.onSurfaceVariant
)
}
} else {
LazyColumn(
modifier = Modifier
.fillMaxWidth()
.weight(1f)
) {
items(state.issues, key = { it.id }) { issue ->
IssueRow(
issue = issue,
expanded = state.expandedIds.contains(issue.id),
onClick = { onEvent(InternalIssuesScreenEvent.ToggleExpanded(issue.id)) }
)
HorizontalDivider()
}
}
}
}
}
if (showFilterSheet) {
ModalBottomSheet(
onDismissRequest = { showFilterSheet = false },
sheetState = rememberModalBottomSheetState()
) {
SheetTitle("Filter by name")
SelectionRow(
text = "All",
selected = state.nameFilter == null,
onClick = {
onEvent(InternalIssuesScreenEvent.SetNameFilter(null))
showFilterSheet = false
}
)
state.names.forEach { name ->
SelectionRow(
text = name,
selected = state.nameFilter == name,
onClick = {
onEvent(InternalIssuesScreenEvent.SetNameFilter(name))
showFilterSheet = false
}
)
}
Spacer(modifier = Modifier.size(16.dp))
}
}
if (showSortSheet) {
ModalBottomSheet(
onDismissRequest = { showSortSheet = false },
sheetState = rememberModalBottomSheetState()
) {
SheetTitle("Sort by")
IssueSortOrder.entries.forEach { order ->
SelectionRow(
text = order.label,
selected = state.sortOrder == order,
onClick = {
onEvent(InternalIssuesScreenEvent.SetSortOrder(order))
showSortSheet = false
}
)
}
Spacer(modifier = Modifier.size(16.dp))
}
}
if (showClearDialog) {
Dialogs.SimpleAlertDialog(
title = "Clear all issues?",
body = "This will permanently delete all recorded app issues.",
confirm = "Clear",
dismiss = "Cancel",
onConfirm = { onEvent(InternalIssuesScreenEvent.ClearAll) },
onDismiss = { showClearDialog = false }
)
}
}
@Composable
private fun SheetTitle(text: String) {
Text(
text = text,
style = MaterialTheme.typography.titleMedium,
modifier = Modifier.padding(horizontal = 24.dp, vertical = 12.dp)
)
}
@Composable
private fun SelectionRow(
text: String,
selected: Boolean,
onClick: () -> Unit
) {
Row(
modifier = Modifier
.fillMaxWidth()
.clickable(onClick = onClick)
.padding(horizontal = 24.dp, vertical = 16.dp),
verticalAlignment = Alignment.CenterVertically
) {
Text(
text = text,
style = MaterialTheme.typography.bodyLarge,
modifier = Modifier.weight(1f)
)
if (selected) {
Icon(
painter = SignalIcons.Check.painter,
contentDescription = null,
tint = MaterialTheme.colorScheme.primary
)
}
}
}
@OptIn(ExperimentalFoundationApi::class)
@Composable
private fun IssueRow(
issue: IssueRecord,
expanded: Boolean,
onClick: () -> Unit
) {
val clipboardManager = LocalClipboardManager.current
val context = LocalContext.current
Column(
modifier = Modifier
.fillMaxWidth()
.combinedClickable(
onClick = onClick,
onLongClick = {
clipboardManager.setText(AnnotatedString(issue.toCopyText()))
Toast.makeText(context, "Copied", Toast.LENGTH_SHORT).show()
}
)
.padding(horizontal = 16.dp, vertical = 12.dp)
) {
Row(verticalAlignment = Alignment.CenterVertically) {
Text(
text = issue.name,
style = MaterialTheme.typography.titleMedium,
fontWeight = FontWeight.Bold,
modifier = Modifier.weight(1f)
)
Text(
text = issue.priority.label,
style = MaterialTheme.typography.labelMedium,
color = priorityColor(issue.priority),
fontWeight = FontWeight.Bold
)
}
Text(
text = buildString {
append(formatTimestamp(issue.createdAt))
append(" • v")
append(issue.version)
issue.duration?.let { append("${it}ms") }
},
style = MaterialTheme.typography.bodySmall,
color = MaterialTheme.colorScheme.onSurfaceVariant
)
Text(
text = issue.description,
style = MaterialTheme.typography.bodyMedium,
maxLines = if (expanded) Int.MAX_VALUE else 2
)
if (expanded && !issue.stackTrace.isNullOrBlank()) {
Text(
text = issue.stackTrace,
style = MaterialTheme.typography.bodySmall.copy(fontFamily = FontFamily.Monospace),
color = MaterialTheme.colorScheme.onSurfaceVariant,
modifier = Modifier.padding(top = 4.dp)
)
}
}
}
private fun IssueRecord.toCopyText(): String {
return buildString {
append(name)
append(" (")
append(priority.label)
append(")\n")
append(formatTimestamp(createdAt))
append(" • v")
append(version)
duration?.let { append("${it}ms") }
append("\n")
append(description)
if (!stackTrace.isNullOrBlank()) {
append("\n")
append(stackTrace)
}
}
}
@Composable
private fun priorityColor(priority: IssuePriority): Color {
return when (priority) {
IssuePriority.HIGH -> MaterialTheme.colorScheme.error
IssuePriority.MEDIUM -> MaterialTheme.colorScheme.tertiary
IssuePriority.LOW -> MaterialTheme.colorScheme.onSurfaceVariant
}
}
private fun formatTimestamp(time: Long): String {
return SimpleDateFormat("yyyy-MM-dd HH:mm:ss", Locale.US).format(Date(time))
}
@DayNightPreviews
@Composable
private fun InternalIssuesScreenPreview() {
Previews.Preview {
InternalIssuesScreen(
state = InternalIssuesState(
loading = false,
names = listOf("Slow Database Read", "Slow Database Write"),
issues = listOf(
IssueRecord(1, System.currentTimeMillis(), "7.42.1", "Slow Database Write", "Took 812ms. query=transaction hold", "java.lang.Throwable\n\tat Foo.bar(Foo.java:1)", IssuePriority.HIGH, 812),
IssueRecord(2, System.currentTimeMillis(), "7.42.1", "Slow Database Read", "Took 1043ms. query=SELECT * FROM message", null, IssuePriority.LOW, 1043)
)
)
)
}
}
@@ -0,0 +1,37 @@
/*
* Copyright 2026 Signal Messenger, LLC
* SPDX-License-Identifier: AGPL-3.0-only
*/
package org.thoughtcrime.securesms.components.settings.app.internal.issues
import org.thoughtcrime.securesms.database.LogDatabase.IssueTable.IssueRecord
import org.thoughtcrime.securesms.database.model.IssuePriority
data class InternalIssuesState(
val loading: Boolean = true,
val issues: List<IssueRecord> = emptyList(),
val names: List<String> = emptyList(),
val nameFilter: String? = null,
val sortOrder: IssueSortOrder = IssueSortOrder.CREATED_DESC,
val expandedIds: Set<Long> = emptySet(),
val notificationPriority: IssuePriority = IssuePriority.HIGH
)
enum class IssueSortOrder(val label: String) {
CREATED_DESC("Newest first"),
CREATED_ASC("Oldest first"),
DURATION_DESC("Longest duration"),
DURATION_ASC("Shortest duration"),
PRIORITY_DESC("Highest priority"),
PRIORITY_ASC("Lowest priority")
}
sealed interface InternalIssuesScreenEvent {
data object Load : InternalIssuesScreenEvent
data object ClearAll : InternalIssuesScreenEvent
data class ToggleExpanded(val id: Long) : InternalIssuesScreenEvent
data class SetNotificationPriority(val priority: IssuePriority) : InternalIssuesScreenEvent
data class SetNameFilter(val name: String?) : InternalIssuesScreenEvent
data class SetSortOrder(val order: IssueSortOrder) : InternalIssuesScreenEvent
}
@@ -0,0 +1,88 @@
/*
* Copyright 2026 Signal Messenger, LLC
* SPDX-License-Identifier: AGPL-3.0-only
*/
package org.thoughtcrime.securesms.components.settings.app.internal.issues
import android.app.Application
import androidx.lifecycle.AndroidViewModel
import androidx.lifecycle.viewModelScope
import kotlinx.coroutines.Dispatchers
import kotlinx.coroutines.flow.MutableStateFlow
import kotlinx.coroutines.flow.StateFlow
import kotlinx.coroutines.flow.asStateFlow
import kotlinx.coroutines.flow.update
import kotlinx.coroutines.launch
import kotlinx.coroutines.withContext
import org.thoughtcrime.securesms.database.LogDatabase
import org.thoughtcrime.securesms.database.LogDatabase.IssueTable.IssueRecord
import org.thoughtcrime.securesms.database.model.IssuePriority
import org.thoughtcrime.securesms.keyvalue.SignalStore
class InternalIssuesViewModel(application: Application) : AndroidViewModel(application) {
private val _state = MutableStateFlow(InternalIssuesState())
val state: StateFlow<InternalIssuesState> = _state.asStateFlow()
private val issues = LogDatabase.getInstance(application).issues
private var allIssues: List<IssueRecord> = emptyList()
fun onEvent(event: InternalIssuesScreenEvent) {
when (event) {
InternalIssuesScreenEvent.Load -> load()
InternalIssuesScreenEvent.ClearAll -> clearAll()
is InternalIssuesScreenEvent.ToggleExpanded -> toggleExpanded(event.id)
is InternalIssuesScreenEvent.SetNotificationPriority -> setNotificationPriority(event.priority)
is InternalIssuesScreenEvent.SetNameFilter -> _state.update { it.copy(nameFilter = event.name).withVisibleIssues() }
is InternalIssuesScreenEvent.SetSortOrder -> _state.update { it.copy(sortOrder = event.order).withVisibleIssues() }
}
}
private fun load() {
viewModelScope.launch {
allIssues = withContext(Dispatchers.IO) { issues.getRecent() }
_state.update { it.copy(loading = false, notificationPriority = SignalStore.internal.issueNotificationPriority).withVisibleIssues() }
}
}
private fun setNotificationPriority(priority: IssuePriority) {
SignalStore.internal.issueNotificationPriority = priority
_state.update { it.copy(notificationPriority = priority) }
}
private fun clearAll() {
viewModelScope.launch {
withContext(Dispatchers.IO) { issues.clear() }
allIssues = emptyList()
_state.update { it.copy(nameFilter = null, expandedIds = emptySet()).withVisibleIssues() }
}
}
private fun toggleExpanded(id: Long) {
_state.update {
val expanded = if (it.expandedIds.contains(id)) it.expandedIds - id else it.expandedIds + id
it.copy(expandedIds = expanded)
}
}
private fun InternalIssuesState.withVisibleIssues(): InternalIssuesState {
val visible = allIssues
.filter { nameFilter == null || it.name == nameFilter }
.sortedWith(sortOrder.comparator())
return copy(issues = visible, names = allIssues.map { it.name }.distinct().sorted())
}
private fun IssueSortOrder.comparator(): Comparator<IssueRecord> {
return when (this) {
IssueSortOrder.CREATED_DESC -> compareByDescending { it.createdAt }
IssueSortOrder.CREATED_ASC -> compareBy { it.createdAt }
IssueSortOrder.DURATION_DESC -> compareByDescending { it.duration ?: Long.MIN_VALUE }
IssueSortOrder.DURATION_ASC -> compareBy { it.duration ?: Long.MAX_VALUE }
IssueSortOrder.PRIORITY_DESC -> compareByDescending { it.priority.value }
IssueSortOrder.PRIORITY_ASC -> compareBy { it.priority.value }
}
}
}
@@ -0,0 +1,226 @@
/*
* Copyright 2026 Signal Messenger, LLC
* SPDX-License-Identifier: AGPL-3.0-only
*/
package org.thoughtcrime.securesms.database
import android.Manifest
import android.app.Notification
import android.app.PendingIntent
import android.content.Intent
import android.content.pm.PackageManager
import androidx.core.app.NotificationCompat
import androidx.core.app.NotificationManagerCompat
import androidx.core.content.ContextCompat
import org.signal.core.util.PendingIntentFlags
import org.thoughtcrime.securesms.BuildConfig
import org.thoughtcrime.securesms.R
import org.thoughtcrime.securesms.database.model.IssueEntry
import org.thoughtcrime.securesms.database.model.IssuePriority
import org.thoughtcrime.securesms.dependencies.AppDependencies
import org.thoughtcrime.securesms.keyvalue.SignalStore
import org.thoughtcrime.securesms.logsubmit.SubmitDebugLogActivity
import org.thoughtcrime.securesms.notifications.NotificationChannels
import org.thoughtcrime.securesms.notifications.NotificationIds
import org.thoughtcrime.securesms.util.RemoteConfig
import java.io.ByteArrayOutputStream
import java.io.PrintStream
/**
* Records noteworthy runtime issues to the [LogDatabase] issue table on a low-priority background thread.
*
* Issues are assigned an [IssuePriority]. Issues whose priority is at or above the user's configured notification
* threshold ([SignalStore.internal] `issueNotificationPriority`) additionally raise a user notification.
* Lower-priority issues simply sit in the table to be reviewed later via the internal issues screen or a submitted debug log.
*
* To limit any potential perf overhead for external users, issues are gated to be saved at most once ever [NON_INTERNAL_DEBOUNCE_MS].
*/
object IssueReporter {
const val ISSUE_SLOW_DATABASE_WRITE = "Slow Database Write"
const val ISSUE_SLOW_DATABASE_READ = "Slow Database Read"
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
private const val NON_INTERNAL_DEBOUNCE_MS = 5_000L
private val IGNORED_DB_STACK_TRACE_CLASSES = listOf(
"BackupRepository",
"BackupMessagesJob",
"ArchiveAttachmentReconciliationJob",
"SubmitDebugLogRepository"
)
private val requests = IssueRequests()
@Volatile
private var lastInsertTime = 0L
init {
WriteThread(requests).apply {
priority = Thread.MIN_PRIORITY
}.start()
}
/**
* Records a generic issue. Safe to call from any thread.
*/
@JvmStatic
@JvmOverloads
fun report(name: String, description: String, throwable: Throwable? = null, priority: IssuePriority = IssuePriority.LOW, duration: Long? = null) {
val now = System.currentTimeMillis()
if (!RemoteConfig.internalUser) {
if (now - lastInsertTime < NON_INTERNAL_DEBOUNCE_MS) {
return
}
lastInsertTime = now
}
requests.add(IssueRequest(now, BuildConfig.VERSION_NAME, name, description, throwable, priority, duration))
maybeNotify(name, priority)
}
@JvmStatic
fun noteSlowDatabaseWrite(query: String?, durationMs: Long, throwable: Throwable) {
if (isExpectedSlowDatabaseOperation()) {
return
}
val priority = when {
durationMs >= SLOW_WRITE_MEDIUM_PRIORITY_MS -> IssuePriority.MEDIUM
durationMs >= SLOW_WRITE_LOW_PRIORITY_MS -> IssuePriority.LOW
else -> return
}
report(ISSUE_SLOW_DATABASE_WRITE, query?.trim() ?: "", throwable, priority = priority, duration = durationMs)
}
@JvmStatic
fun noteSlowDatabaseRead(query: String?, durationMs: Long, throwable: Throwable) {
if (isExpectedSlowDatabaseOperation()) {
return
}
val priority = when {
durationMs >= SLOW_READ_MEDIUM_PRIORITY_MS -> IssuePriority.MEDIUM
durationMs >= SLOW_READ_LOW_PRIORITY_MS -> IssuePriority.LOW
else -> return
}
report(ISSUE_SLOW_DATABASE_READ, query?.trim() ?: "", throwable, priority = priority, duration = durationMs)
}
private fun maybeNotify(name: String, priority: IssuePriority) {
if (!RemoteConfig.internalUser) {
return
}
if (priority.value < SignalStore.internal.issueNotificationPriority.value) {
return
}
val context = AppDependencies.application
if (ContextCompat.checkSelfPermission(context, Manifest.permission.POST_NOTIFICATIONS) != PackageManager.PERMISSION_GRANTED) {
return
}
val notification: Notification = NotificationCompat.Builder(context, NotificationChannels.getInstance().FAILURES)
.setSmallIcon(R.drawable.ic_notification)
.setContentTitle("[Internal-only] Issue detected")
.setContentText("$name (${priority.label}). Please tap to get a debug log.")
.setContentIntent(PendingIntent.getActivity(context, 0, Intent(context, SubmitDebugLogActivity::class.java), PendingIntentFlags.mutable()))
.build()
NotificationManagerCompat.from(context).notify(NotificationIds.INTERNAL_ERROR, notification)
}
private fun isExpectedSlowDatabaseOperation(): Boolean {
return Thread
.currentThread()
.stackTrace
.any { element ->
IGNORED_DB_STACK_TRACE_CLASSES.any {
element.className.contains(it)
}
}
}
private data class IssueRequest(
val createdAt: Long,
val version: String,
val name: String,
val description: String,
val throwable: Throwable?,
val priority: IssuePriority,
val duration: Long?
)
private class WriteThread(
private val requests: IssueRequests
) : Thread("signal-issue-reporter") {
private val db: LogDatabase by lazy { LogDatabase.getInstance(AppDependencies.application) }
override fun run() {
var buffer = mutableListOf<IssueRequest>()
while (true) {
buffer = requests.blockForRequests(buffer)
db.issues.insert(buffer.asSequence().map { requestToEntry(it) }, System.currentTimeMillis())
buffer.clear()
}
}
private fun requestToEntry(request: IssueRequest): IssueEntry {
return IssueEntry(
createdAt = request.createdAt,
version = request.version,
name = request.name,
description = request.description,
stackTrace = request.throwable?.let { stackTraceToString(it) },
priority = request.priority,
duration = request.duration
)
}
private fun stackTraceToString(throwable: Throwable): String {
val outputStream = ByteArrayOutputStream()
throwable.printStackTrace(PrintStream(outputStream))
return String(outputStream.toByteArray())
}
}
private class IssueRequests {
// Mutable because it gets replaced in blockForRequests, to save a copy operation.
var requests = mutableListOf<IssueRequest>()
val lock = Object()
fun add(request: IssueRequest) {
synchronized(lock) {
requests.add(request)
lock.notify()
}
}
/**
* Blocks until requests are available. When they are, returns all pending requests and swaps `swapBuffer` with the
* internal storage for future requests. `swapBuffer` should already be empty upon entry to this method.
*/
fun blockForRequests(swapBuffer: MutableList<IssueRequest>): MutableList<IssueRequest> {
synchronized(lock) {
while (requests.isEmpty()) {
lock.wait()
}
val result = requests
requests = swapBuffer
return result
}
}
}
}
@@ -3,6 +3,7 @@ package org.thoughtcrime.securesms.database
import android.annotation.SuppressLint
import android.app.Application
import android.database.Cursor
import androidx.sqlite.db.SupportSQLiteDatabase
import net.zetetic.database.sqlcipher.SQLiteDatabase
import net.zetetic.database.sqlcipher.SQLiteOpenHelper
import org.signal.core.util.SqlUtil
@@ -18,7 +19,9 @@ import org.signal.core.util.readToList
import org.signal.core.util.readToSingleInt
import org.signal.core.util.readToSingleLong
import org.signal.core.util.requireBoolean
import org.signal.core.util.requireInt
import org.signal.core.util.requireLong
import org.signal.core.util.requireLongOrNull
import org.signal.core.util.requireNonNullString
import org.signal.core.util.requireString
import org.signal.core.util.select
@@ -27,6 +30,8 @@ import org.signal.core.util.withinTransaction
import org.thoughtcrime.securesms.crash.CrashConfig
import org.thoughtcrime.securesms.crypto.DatabaseSecret
import org.thoughtcrime.securesms.crypto.DatabaseSecretProvider
import org.thoughtcrime.securesms.database.model.IssueEntry
import org.thoughtcrime.securesms.database.model.IssuePriority
import org.thoughtcrime.securesms.database.model.LogEntry
import java.io.Closeable
import kotlin.math.abs
@@ -60,7 +65,7 @@ class LogDatabase private constructor(
companion object {
private val TAG = Log.tag(LogDatabase::class.java)
private const val DATABASE_VERSION = 4
private const val DATABASE_VERSION = 5
private const val DATABASE_NAME = "signal-logs.db"
@SuppressLint("StaticFieldLeak") // We hold an Application context, not a view context
@@ -90,15 +95,20 @@ class LogDatabase private constructor(
@get:JvmName("anrs")
val anrs: AnrTable by lazy { AnrTable(this) }
@get:JvmName("issues")
val issues: IssueTable by lazy { IssueTable({ readableDatabase }, { writableDatabase }) }
override fun onCreate(db: SQLiteDatabase) {
Log.i(TAG, "onCreate()")
db.execSQL(LogTable.CREATE_TABLE)
db.execSQL(CrashTable.CREATE_TABLE)
db.execSQL(AnrTable.CREATE_TABLE)
db.execSQL(IssueTable.CREATE_TABLE)
LogTable.CREATE_INDEXES.forEach { db.execSQL(it) }
CrashTable.CREATE_INDEXES.forEach { db.execSQL(it) }
IssueTable.CREATE_INDEXES.forEach { db.execSQL(it) }
}
override fun onUpgrade(db: SQLiteDatabase, oldVersion: Int, newVersion: Int) {
@@ -120,6 +130,12 @@ class LogDatabase private constructor(
if (oldVersion < 4) {
db.execSQL("CREATE TABLE anr (_id INTEGER PRIMARY KEY, created_at INTEGER NOT NULL, thread_dump TEXT NOT NULL)")
}
if (oldVersion < 5) {
db.execSQL("CREATE TABLE issue (_id INTEGER PRIMARY KEY, created_at INTEGER NOT NULL, app_version TEXT NOT NULL, name TEXT NOT NULL, description TEXT NOT NULL, stack_trace TEXT, priority INTEGER NOT NULL, duration INTEGER)")
db.execSQL("CREATE INDEX issue_created_at ON issue (created_at)")
db.execSQL("CREATE INDEX issue_name ON issue (name)")
}
}
override fun onOpen(db: SQLiteDatabase) {
@@ -526,4 +542,155 @@ class LogDatabase private constructor(
val threadDump: String
)
}
class IssueTable(
private val readableDatabaseProvider: () -> SupportSQLiteDatabase,
private val writableDatabaseProvider: () -> SupportSQLiteDatabase
) {
companion object {
const val TABLE_NAME = "issue"
const val ID = "_id"
const val CREATED_AT = "created_at"
const val APP_VERSION = "app_version"
const val NAME = "name"
const val DESCRIPTION = "description"
const val STACK_TRACE = "stack_trace"
const val PRIORITY = "priority"
const val DURATION = "duration"
const val CREATE_TABLE = """
CREATE TABLE $TABLE_NAME (
$ID INTEGER PRIMARY KEY,
$CREATED_AT INTEGER NOT NULL,
$APP_VERSION TEXT NOT NULL,
$NAME TEXT NOT NULL,
$DESCRIPTION TEXT NOT NULL,
$STACK_TRACE TEXT,
$PRIORITY INTEGER NOT NULL,
$DURATION INTEGER
)
"""
val CREATE_INDEXES = arrayOf(
"CREATE INDEX issue_created_at ON $TABLE_NAME ($CREATED_AT)",
"CREATE INDEX issue_name ON $TABLE_NAME ($NAME)"
)
private val MAX_LIFESPAN = 30.days.inWholeMilliseconds
private const val MAX_ROWS = 500
}
private val readableDatabase: SupportSQLiteDatabase get() = readableDatabaseProvider()
private val writableDatabase: SupportSQLiteDatabase get() = writableDatabaseProvider()
fun insert(issues: Sequence<IssueEntry>, currentTime: Long) {
writableDatabase.withinTransaction { db ->
issues.forEach { issue ->
db.insertInto(TABLE_NAME)
.values(
CREATED_AT to issue.createdAt,
APP_VERSION to issue.version,
NAME to issue.name,
DESCRIPTION to issue.description,
STACK_TRACE to issue.stackTrace,
PRIORITY to issue.priority.value,
DURATION to issue.duration
)
.run()
}
trimToSize(db, currentTime)
}
}
fun getRecent(limit: Int = MAX_ROWS): List<IssueRecord> {
return readableDatabase
.select()
.from(TABLE_NAME)
.orderBy("$CREATED_AT DESC")
.limit(limit)
.run()
.readToList { cursor ->
IssueRecord(
id = cursor.requireLong(ID),
createdAt = cursor.requireLong(CREATED_AT),
version = cursor.requireNonNullString(APP_VERSION),
name = cursor.requireNonNullString(NAME),
description = cursor.requireNonNullString(DESCRIPTION),
stackTrace = cursor.requireString(STACK_TRACE),
priority = IssuePriority.fromValue(cursor.requireInt(PRIORITY)),
duration = cursor.requireLongOrNull(DURATION)
)
}
}
fun getSummary(): List<IssueSummary> {
return readableDatabase
.select(NAME, "COUNT(*) AS count", "MAX($PRIORITY) AS max_priority", "MIN($CREATED_AT) AS first_seen", "MAX($CREATED_AT) AS last_seen", "CAST(AVG($DURATION) AS INTEGER) AS avg_duration")
.from(TABLE_NAME)
.where("1 = 1")
.groupBy(NAME)
.run()
.readToList { cursor ->
val name = cursor.requireNonNullString(NAME)
IssueSummary(
name = name,
count = cursor.requireInt("count"),
maxPriority = IssuePriority.fromValue(cursor.requireInt("max_priority")),
firstSeen = cursor.requireLong("first_seen"),
lastSeen = cursor.requireLong("last_seen"),
lastVersion = getLatestVersion(name),
averageDuration = cursor.requireLongOrNull("avg_duration")
)
}
.sortedByDescending { it.count }
}
fun clear() {
writableDatabase.deleteAll(TABLE_NAME)
}
private fun getLatestVersion(name: String): String {
return readableDatabase
.select(APP_VERSION)
.from(TABLE_NAME)
.where("$NAME = ?", name)
.orderBy("$CREATED_AT DESC")
.limit(1)
.run()
.readToList { it.requireNonNullString(APP_VERSION) }
.firstOrNull() ?: ""
}
private fun trimToSize(db: SupportSQLiteDatabase, currentTime: Long) {
db.delete(TABLE_NAME)
.where("$CREATED_AT < ${currentTime - MAX_LIFESPAN}")
.run()
db.delete(TABLE_NAME)
.where("$ID NOT IN (SELECT $ID FROM $TABLE_NAME ORDER BY $CREATED_AT DESC LIMIT $MAX_ROWS)")
.run()
}
data class IssueRecord(
val id: Long,
val createdAt: Long,
val version: String,
val name: String,
val description: String,
val stackTrace: String?,
val priority: IssuePriority,
val duration: Long?
)
data class IssueSummary(
val name: String,
val count: Int,
val maxPriority: IssuePriority,
val firstSeen: Long,
val lastSeen: Long,
val lastVersion: String,
val averageDuration: Long?
)
}
}
@@ -12,9 +12,9 @@ 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.ThreadUtil;
import org.signal.core.util.logging.Log;
import org.signal.core.util.tracing.Tracer;
@@ -27,7 +27,6 @@ import java.util.Locale;
import java.util.Map;
import java.util.Objects;
import java.util.Set;
import java.util.concurrent.TimeUnit;
/**
* This is a wrapper around {@link net.zetetic.database.sqlcipher.SQLiteDatabase}. There's difficulties
@@ -38,12 +37,6 @@ public class SQLiteDatabase implements SupportSQLiteDatabase {
private static final String TAG = Log.tag(SQLiteDatabase.class);
private static final long SLOW_WRITE_LOCK_WAIT_MS = TimeUnit.SECONDS.toMillis(3);
private static final long SLOW_TRANSACTION_HOLD_MS = 750;
private static final long SLOW_DIRECT_WRITE_MS = 250;
private static final long SLOW_DIRECT_DELETE_MS = TimeUnit.SECONDS.toMillis(1);
private static final long SLOW_QUERY_MS = TimeUnit.SECONDS.toMillis(1);
public static final int CONFLICT_ROLLBACK = 1;
public static final int CONFLICT_ABORT = 2;
public static final int CONFLICT_FAIL = 3;
@@ -59,8 +52,6 @@ public class SQLiteDatabase implements SupportSQLiteDatabase {
private final net.zetetic.database.sqlcipher.SQLiteDatabase wrapped;
private final Tracer tracer;
private static volatile boolean slowWriteLoggingEnabled = false;
private static final ThreadLocal<Long> TRANSACTION_HOLD_START_NS = new ThreadLocal<>();
private static final ThreadLocal<Set<Runnable>> PENDING_POST_SUCCESSFUL_TRANSACTION_TASKS;
private static final ThreadLocal<Set<Runnable>> POST_SUCCESSFUL_TRANSACTION_TASKS;
@@ -72,10 +63,6 @@ public class SQLiteDatabase implements SupportSQLiteDatabase {
PENDING_POST_SUCCESSFUL_TRANSACTION_TASKS.set(new LinkedHashSet<>());
}
public static void setSlowWriteLoggingEnabled(boolean enabled) {
slowWriteLoggingEnabled = enabled;
}
public SQLiteDatabase(net.zetetic.database.sqlcipher.SQLiteDatabase wrapped) {
this.wrapped = wrapped;
this.tracer = Tracer.getInstance();
@@ -96,19 +83,15 @@ 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();
}
tracer.start(methodName, KEY_QUERY, query);
long startNs = slowWriteLoggingEnabled && locked ? System.nanoTime() : 0L;
long startNs = locked ? System.nanoTime() : 0L;
returnable.run();
if (slowWriteLoggingEnabled && locked) {
warnIfSlowDirectWrite(methodName, null, query, queryPlanSql, queryPlanArgs, startNs);
if (locked) {
warnIfSlowDirectWrite(methodName, null, query, startNs);
}
tracer.end(methodName);
@@ -122,10 +105,6 @@ 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();
}
@@ -139,18 +118,16 @@ public class SQLiteDatabase implements SupportSQLiteDatabase {
}
tracer.start(methodName, params);
long startNs = slowWriteLoggingEnabled ? System.nanoTime() : 0L;
long startNs = System.nanoTime();
E result = returnable.run();
if (result instanceof Cursor) {
// Triggers filling the window (which is about to be done anyway), but lets us capture that time inside the trace
((Cursor) result).getCount();
}
if (slowWriteLoggingEnabled) {
if (locked) {
warnIfSlowDirectWrite(methodName, table, query, queryPlanSql, queryPlanArgs, startNs);
} else {
warnIfSlowQuery(methodName, table, query, queryPlanSql, queryPlanArgs, startNs);
}
if (locked) {
warnIfSlowDirectWrite(methodName, table, query, startNs);
} else {
warnIfSlowQuery(methodName, table, query, startNs);
}
tracer.end(methodName);
@@ -274,13 +251,13 @@ public class SQLiteDatabase implements SupportSQLiteDatabase {
@Override
public Cursor query(SupportSQLiteQuery query) {
DatabaseMonitor.onSql(query.getSql(), null);
return traceSql("query(SupportSQLiteQuery)", null, query.getSql(), false, query.getSql(), null, () -> wrapped.query(query));
return traceSql("query(SupportSQLiteQuery)", null, query.getSql(), false, () -> wrapped.query(query));
}
@Override
public Cursor query(SupportSQLiteQuery query, CancellationSignal cancellationSignal) {
DatabaseMonitor.onSql(query.getSql(), null);
return traceSql("query(SupportSQLiteQuery, CancellationSignal)", null, query.getSql(), false, query.getSql(), null, () -> wrapped.query(query, cancellationSignal));
return traceSql("query(SupportSQLiteQuery, CancellationSignal)", null, query.getSql(), false, () -> wrapped.query(query, cancellationSignal));
}
@Override
@@ -330,7 +307,7 @@ public class SQLiteDatabase implements SupportSQLiteDatabase {
trace("beginTransaction()", wrapped::beginTransaction);
} else {
trace("beginTransaction()", () -> {
long waitStartNs = slowWriteLoggingEnabled ? System.nanoTime() : 0L;
long waitStartNs = System.nanoTime();
wrapped.beginTransactionWithListener(new SQLiteTransactionListener() {
@Override
public void onBegin() { }
@@ -349,29 +326,28 @@ public class SQLiteDatabase implements SupportSQLiteDatabase {
getPendingPostSuccessfulTransactionTasks().clear();
}
});
if (slowWriteLoggingEnabled) {
long waitMs = (System.nanoTime() - waitStartNs) / 1_000_000L;
if (waitMs >= SLOW_WRITE_LOCK_WAIT_MS) {
Log.w(TAG, "Slow write-lock acquire: waited " + waitMs + "ms to BEGIN", new Throwable());
}
TRANSACTION_HOLD_START_NS.set(System.nanoTime());
long waitMs = (System.nanoTime() - waitStartNs) / 1_000_000L;
if (waitMs >= IssueReporter.SLOW_WRITE_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);
}
TRANSACTION_HOLD_START_NS.set(System.nanoTime());
});
}
}
public void endTransaction() {
Long holdStartNs = slowWriteLoggingEnabled ? TRANSACTION_HOLD_START_NS.get() : null;
Long holdStartNs = TRANSACTION_HOLD_START_NS.get();
trace("endTransaction()", wrapped::endTransaction);
traceLockEnd();
if (holdStartNs != null && !wrapped.inTransaction()) {
TRANSACTION_HOLD_START_NS.remove();
if (slowWriteLoggingEnabled) {
long holdMs = (System.nanoTime() - holdStartNs) / 1_000_000L;
if (holdMs >= SLOW_TRANSACTION_HOLD_MS) {
Log.w(TAG, "Slow transaction: held write lock for " + holdMs + "ms", new Throwable());
SlowTransactionInternalNotifier.onSlowEvent();
}
long holdMs = (System.nanoTime() - holdStartNs) / 1_000_000L;
if (holdMs >= IssueReporter.SLOW_WRITE_LOW_PRIORITY_MS) {
Throwable throwable = new Throwable();
Log.w(TAG, "Slow transaction: held write lock for " + holdMs + "ms", throwable);
IssueReporter.noteSlowDatabaseWrite("transaction hold", holdMs, throwable);
}
}
Set<Runnable> tasks = getPostSuccessfulTransactionTasks();
@@ -387,42 +363,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, buildQueryPlanSql(distinct, table, columns, selection, groupBy, having, orderBy, limit), selectionArgs, () -> wrapped.query(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));
}
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, buildQueryPlanSql(distinct, table, columns, selection, groupBy, having, orderBy, limit), selectionArgs, () -> wrapped.queryWithFactory(cursorFactory, 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));
}
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, buildQueryPlanSql(false, table, columns, selection, groupBy, having, orderBy, null), selectionArgs, () -> wrapped.query(table, columns, selection, selectionArgs, groupBy, having, orderBy));
return traceSql("query(7)", table, selection, false, () -> 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, buildQueryPlanSql(false, table, columns, selection, groupBy, having, orderBy, limit), selectionArgs, () -> wrapped.query(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));
}
public Cursor rawQuery(String sql, String[] selectionArgs) {
DatabaseMonitor.onSql(sql, selectionArgs);
return traceSql("rawQuery(2a)", null, sql, false, sql, selectionArgs, () -> wrapped.rawQuery(sql, selectionArgs));
return traceSql("rawQuery(2a)", null, sql, false, () -> wrapped.rawQuery(sql, selectionArgs));
}
public Cursor rawQuery(String sql, Object... args) {
DatabaseMonitor.onSql(sql, args);
return traceSql("rawQuery(2b)", null, sql, false, sql, args, () -> wrapped.rawQuery(sql, args));
return traceSql("rawQuery(2b)", null, sql, false, () -> 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()", null, sql, false, sql, selectionArgs, () -> wrapped.rawQueryWithFactory(cursorFactory, sql, selectionArgs, editTable));
return traceSql("rawQueryWithFactory()", null, sql, false, () -> 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)", null, sql, false, sql, selectionArgs, () -> rawQuery(sql, selectionArgs, initialRead, maxRead));
return traceSql("rawQuery(4)", null, sql, false, () -> rawQuery(sql, selectionArgs, initialRead, maxRead));
}
public long insert(String table, String nullColumnHack, ContentValues values) {
@@ -447,17 +423,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, buildDeletePlanSql(table, whereClause), whereArgs, () -> wrapped.delete(table, whereClause, whereArgs));
return traceSql("delete()", table, whereClause, true, () -> 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, buildUpdatePlanSql(table, values, whereClause, CONFLICT_NONE), buildUpdatePlanArgs(values, whereArgs), () -> wrapped.update(table, values, whereClause, whereArgs));
return traceSql("update()", table, whereClause, true, () -> 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, buildUpdatePlanSql(table, values, whereClause, conflictAlgorithm), buildUpdatePlanArgs(values, whereArgs), () -> wrapped.updateWithOnConflict(table, values, whereClause, whereArgs, conflictAlgorithm));
return traceSql("updateWithOnConflict()", table, whereClause, true, () -> wrapped.updateWithOnConflict(table, values, whereClause, whereArgs, conflictAlgorithm));
}
public void execSQL(String sql) throws SQLException {
@@ -576,146 +552,27 @@ public class SQLiteDatabase implements SupportSQLiteDatabase {
wrapped.setLocale(locale);
}
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()) {
private void warnIfSlowDirectWrite(String methodName, String table, String query, long startNs) {
if (wrapped.inTransaction()) {
return;
}
long elapsedMs = (System.nanoTime() - startNs) / 1_000_000L;
long threshold = "delete()".equals(methodName) ? SLOW_DIRECT_DELETE_MS : SLOW_DIRECT_WRITE_MS;
if (elapsedMs >= threshold) {
Log.w(TAG, "Slow direct write: " + methodName + " on " + table + " took " + elapsedMs + "ms (query=" + query + ")", new Throwable());
logQueryPlan(methodName, queryPlanSql, queryPlanArgs);
if (elapsedMs >= IssueReporter.SLOW_WRITE_LOW_PRIORITY_MS) {
Throwable throwable = new Throwable();
Log.w(TAG, "Slow direct write: " + methodName + " on " + table + " took " + elapsedMs + "ms (query=" + query + ")", throwable);
IssueReporter.noteSlowDatabaseWrite(query, elapsedMs, throwable);
}
}
private void warnIfSlowQuery(String methodName, String table, String query, String queryPlanSql, Object[] queryPlanArgs, long startNs) {
if (!slowWriteLoggingEnabled) {
return;
}
private void warnIfSlowQuery(String methodName, String table, String query, long startNs) {
long elapsedMs = (System.nanoTime() - startNs) / 1_000_000L;
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);
if (elapsedMs >= IssueReporter.SLOW_READ_LOW_PRIORITY_MS) {
Throwable throwable = new Throwable();
Log.w(TAG, "Slow query: " + methodName + " on " + table + " took " + elapsedMs + "ms (query=" + query + ")", throwable);
IssueReporter.noteSlowDatabaseRead(query, elapsedMs, throwable);
}
}
@@ -1,96 +0,0 @@
/*
* Copyright 2026 Signal Messenger, LLC
* SPDX-License-Identifier: AGPL-3.0-only
*/
package org.thoughtcrime.securesms.database
import android.Manifest
import android.app.Notification
import android.app.PendingIntent
import android.content.Intent
import android.content.pm.PackageManager
import androidx.core.app.NotificationCompat
import androidx.core.app.NotificationManagerCompat
import androidx.core.content.ContextCompat
import org.signal.core.util.PendingIntentFlags
import org.thoughtcrime.securesms.R
import org.thoughtcrime.securesms.dependencies.AppDependencies
import org.thoughtcrime.securesms.logsubmit.SubmitDebugLogActivity
import org.thoughtcrime.securesms.notifications.NotificationChannels
import org.thoughtcrime.securesms.notifications.NotificationIds
import org.thoughtcrime.securesms.util.RemoteConfig
import java.util.concurrent.atomic.AtomicInteger
import kotlin.time.Duration
import kotlin.time.Duration.Companion.milliseconds
import kotlin.time.Duration.Companion.minutes
/**
* Notifier that surfaces SQLite write-lock contention. Gated behind the [RemoteConfig.slowDatabaseNotifications] flag.
*/
object SlowTransactionInternalNotifier {
private const val THRESHOLD = 5
private val NOTIFY_INTERVAL = 30.minutes
private val IGNORED_STACK_TRACE_CLASSES = listOf(
"BackupRepository",
"BackupMessagesJob",
"ArchiveAttachmentReconciliationJob",
"SubmitDebugLogRepository"
)
private val count = AtomicInteger(0)
@Volatile
private var lastNotify: Duration = 0.milliseconds
@JvmStatic
fun onSlowEvent() {
if (!RemoteConfig.slowDatabaseNotifications) {
return
}
if (isExpectedSlowOperation()) {
return
}
if (count.incrementAndGet() < THRESHOLD) {
return
}
val now = System.currentTimeMillis().milliseconds
if (lastNotify + NOTIFY_INTERVAL > now) {
return
}
val context = AppDependencies.application
if (ContextCompat.checkSelfPermission(context, Manifest.permission.POST_NOTIFICATIONS) != PackageManager.PERMISSION_GRANTED) {
return
}
val observed = count.getAndSet(0)
lastNotify = now
val notification: Notification = NotificationCompat.Builder(context, NotificationChannels.getInstance().FAILURES)
.setSmallIcon(R.drawable.ic_notification)
.setContentTitle("[Internal-only] Slow database activity")
.setContentText("$observed slow database operations (transactions/queries) observed. Please tap to get a debug log.")
.setContentIntent(PendingIntent.getActivity(context, 0, Intent(context, SubmitDebugLogActivity::class.java), PendingIntentFlags.mutable()))
.build()
NotificationManagerCompat.from(context).notify(NotificationIds.INTERNAL_ERROR, notification)
}
private fun isExpectedSlowOperation(): Boolean {
return Thread
.currentThread()
.stackTrace
.any { element ->
IGNORED_STACK_TRACE_CLASSES.any {
element.className.contains(it)
}
}
}
}
@@ -0,0 +1,11 @@
package org.thoughtcrime.securesms.database.model
data class IssueEntry(
val createdAt: Long,
val version: String,
val name: String,
val description: String,
val stackTrace: String?,
val priority: IssuePriority,
val duration: Long?
)
@@ -0,0 +1,17 @@
package org.thoughtcrime.securesms.database.model
/**
* The relative importance of a recorded issue. Stored in the database as [value] so that ordering and threshold
* comparisons are meaningful.
*/
enum class IssuePriority(val value: Int, val label: String) {
LOW(100, "Low"),
MEDIUM(200, "Medium"),
HIGH(300, "High");
companion object {
fun fromValue(value: Int): IssuePriority {
return entries.firstOrNull { it.value == value } ?: LOW
}
}
}
@@ -3,6 +3,7 @@ package org.thoughtcrime.securesms.keyvalue
import org.signal.archive.proto.BackupDebugInfo
import org.signal.ringrtc.CallManager.DataMode
import org.thoughtcrime.securesms.BuildConfig
import org.thoughtcrime.securesms.database.model.IssuePriority
import org.thoughtcrime.securesms.util.Environment.Calling.defaultSfuUrl
import org.thoughtcrime.securesms.util.RemoteConfig
@@ -37,6 +38,7 @@ class InternalValues internal constructor(store: KeyValueStore) : SignalStoreVal
const val IMPORTED_BACKUP_DEBUG_INFO: String = "internal.imported_backup_debug_info"
const val USE_NEW_MEDIA_ACTIVITY: String = "internal.use_new_media_activity"
const val ANR_DETECTION_CRASH: String = "internal.anr_detection_crash"
const val ISSUE_NOTIFICATION_PRIORITY: String = "internal.issue_notification_priority"
}
public override fun onFirstEverAppLaunch() = Unit
@@ -177,6 +179,14 @@ class InternalValues internal constructor(store: KeyValueStore) : SignalStoreVal
var forceSsre2Capability by booleanValue("internal.force_ssre2_capability", false).defaultForExternalUsers()
/**
* The minimum [IssuePriority] that an issue recorded by [org.thoughtcrime.securesms.database.IssueReporter] must have
* in order to raise a user notification.
*/
var issueNotificationPriority: IssuePriority
get() = IssuePriority.fromValue(getInteger(ISSUE_NOTIFICATION_PRIORITY, IssuePriority.HIGH.value))
set(value) = putInteger(ISSUE_NOTIFICATION_PRIORITY, value.value)
var showArchiveStateHint by booleanValue(SHOW_ARCHIVE_STATE_HINT, false).defaultForExternalUsers()
/** Whether or not we should include a debuglog in the backup debug info when generating a backup. */
@@ -0,0 +1,46 @@
/*
* Copyright 2026 Signal Messenger, LLC
* SPDX-License-Identifier: AGPL-3.0-only
*/
package org.thoughtcrime.securesms.logsubmit
import android.app.Application
import android.content.Context
import org.thoughtcrime.securesms.database.LogDatabase
import java.text.SimpleDateFormat
import java.util.Date
import java.util.Locale
/**
* Summarizes the recorded database issues (grouped by name) rather than listing every individual occurrence.
*/
class LogSectionDatabaseIssues : LogSection {
override fun getTitle(): String = "APP ISSUES"
override fun getContent(context: Context): CharSequence {
val summaries = LogDatabase.getInstance(context.applicationContext as Application).issues.getSummary()
if (summaries.isEmpty()) {
return "None"
}
val dateFormat = SimpleDateFormat("yyyy-MM-dd HH:mm:ss", Locale.US)
return summaries.joinToString(separator = "\n\n") { summary ->
"""
-- ${summary.name}
Count : ${summary.count}
Max Priority: ${summary.maxPriority.label}
Avg Duration: ${summary.averageDuration?.let { "${it}ms" } ?: "n/a"}
First Seen : ${dateFormat.format(Date(summary.firstSeen))}
Last Seen : ${dateFormat.format(Date(summary.lastSeen))}
Last Version: ${summary.lastVersion}
""".trimIndent()
}
}
override fun hasContent(): Boolean {
return true
}
}
@@ -103,6 +103,7 @@ public class SubmitDebugLogRepository {
}
add(new LogSectionDatabaseSchema());
add(new LogSectionRemappedRecords());
add(new LogSectionDatabaseIssues());
add(new LogSectionAnr());
add(new LogSectionLogcat());
add(new LogSectionLoggerHeader());
@@ -11,7 +11,6 @@ import org.signal.core.util.gibiBytes
import org.signal.core.util.kibiBytes
import org.signal.core.util.logging.Log
import org.signal.core.util.mebiBytes
import org.thoughtcrime.securesms.database.SQLiteDatabase
import org.thoughtcrime.securesms.dependencies.AppDependencies
import org.thoughtcrime.securesms.groups.SelectionLimits
import org.thoughtcrime.securesms.jobs.RemoteConfigRefreshJob
@@ -684,16 +683,6 @@ object RemoteConfig {
hotSwappable = true
)
/** Whether we log and surface notifications for slow database transactions/queries. */
@JvmStatic
@get:JvmName("slowDatabaseNotifications")
val slowDatabaseNotifications: Boolean by remoteBoolean(
key = "android.slowDatabaseNotifications",
defaultValue = false,
hotSwappable = true,
onChangeListener = { SQLiteDatabase.setSlowWriteLoggingEnabled(it.newValue.asBoolean(false)) }
)
/** How often we allow an automatic session reset. */
@JvmStatic
@get:JvmName("automaticSessionResetIntervalSeconds")