Add Schildi-dbg settings

To control more invasive debugging

Change-Id: I7ee2980388db8999a76992ee7fffc70d8383a283
This commit is contained in:
SpiritCroc 2022-03-15 10:07:44 +01:00
parent c214c2233f
commit 56cae372b4
13 changed files with 205 additions and 32 deletions

View file

@ -0,0 +1,41 @@
package de.spiritcroc.matrixsdk.util
import android.content.Context
import androidx.preference.PreferenceManager
import org.matrix.android.sdk.BuildConfig
import timber.log.Timber
object DbgUtil {
const val DBG_READ_MARKER = "DBG_READ_MARKER"
const val DBG_TIMELINE_CHUNKS = "DBG_TIMELINE_CHUNKS"
const val DBG_SHOW_DISPLAY_INDEX = "DBG_SHOW_DISPLAY_INDEX"
private val prefs = HashMap<String, Boolean>()
private val ALL_PREFS = arrayOf(
DBG_READ_MARKER,
DBG_TIMELINE_CHUNKS,
DBG_SHOW_DISPLAY_INDEX
)
fun load(context: Context) {
val sp = PreferenceManager.getDefaultSharedPreferences(context)
ALL_PREFS.forEach {
prefs[it] = sp.getBoolean(it, false)
}
}
fun onPreferenceChanged(context: Context, key: String, value: Boolean) {
if (key !in ALL_PREFS) {
Timber.e("Trying to set unsupported preference $key to $value")
return
}
prefs[key] = value
PreferenceManager.getDefaultSharedPreferences(context).edit().putBoolean(key, value).apply()
}
fun isDbgEnabled(key: String): Boolean {
return prefs[key] ?: BuildConfig.DEBUG
//return prefs[key] == true
}
}

View file

@ -0,0 +1,37 @@
package de.spiritcroc.matrixsdk.util
import timber.log.Timber
// Timber wrapper
class Dimber(val tag: String, val key: String) {
fun v(msgGen: () -> String) {
if (DbgUtil.isDbgEnabled(key)) {
Timber.tag(tag).v(msgGen())
}
}
fun d(msgGen: () -> String) {
if (DbgUtil.isDbgEnabled(key)) {
Timber.tag(tag).d(msgGen())
}
}
fun i(msgGen: () -> String) {
if (DbgUtil.isDbgEnabled(key)) {
Timber.tag(tag).i(msgGen())
}
}
fun w(msgGen: () -> String) {
if (DbgUtil.isDbgEnabled(key)) {
Timber.tag(tag).w(msgGen())
}
}
fun e(msgGen: () -> String) {
if (DbgUtil.isDbgEnabled(key)) {
Timber.tag(tag).e(msgGen())
}
}
fun exec(doFun: () -> Unit) {
if (DbgUtil.isDbgEnabled(key)) {
doFun()
}
}
}

View file

@ -17,6 +17,8 @@
package org.matrix.android.sdk.internal.session.room.timeline
import de.spiritcroc.matrixsdk.StaticScSdkHelper
import de.spiritcroc.matrixsdk.util.DbgUtil
import de.spiritcroc.matrixsdk.util.Dimber
import io.realm.Realm
import io.realm.RealmConfiguration
import kotlinx.coroutines.CoroutineScope
@ -86,6 +88,8 @@ internal class DefaultTimeline(private val roomId: String,
private var isFromThreadTimeline = false
private var rootThreadEventId: String? = null
private val dimber = Dimber("TimelineChunks", DbgUtil.DBG_TIMELINE_CHUNKS)
private val strategyDependencies = LoadTimelineStrategy.Dependencies(
timelineSettings = settings,
realm = backgroundRealm,
@ -298,10 +302,14 @@ internal class DefaultTimeline(private val roomId: String,
val snapshot = strategy.buildSnapshot()
Timber.v("Post snapshot of ${snapshot.size} events")
// Async debugging to not slow down things too much
timelineScope.launch(coroutineDispatchers.computation) {
checkTimelineConsistency("DefaultTimeline.postSnapshot", snapshot, verbose = false) { msg ->
timelineScope.launch(coroutineDispatchers.main) {
StaticScSdkHelper.scSdkPreferenceProvider?.annoyDevelopersWithToast(msg)
dimber.exec {
timelineScope.launch(coroutineDispatchers.computation) {
checkTimelineConsistency("DefaultTimeline.postSnapshot", snapshot, verbose = false) { msg ->
if (DbgUtil.isDbgEnabled(DbgUtil.DBG_SHOW_DISPLAY_INDEX)) {
timelineScope.launch(coroutineDispatchers.main) {
StaticScSdkHelper.scSdkPreferenceProvider?.annoyDevelopersWithToast(msg)
}
}
}
}
}

View file

@ -16,6 +16,8 @@
package org.matrix.android.sdk.internal.session.room.timeline
import de.spiritcroc.matrixsdk.util.DbgUtil
import de.spiritcroc.matrixsdk.util.Dimber
import io.realm.OrderedCollectionChangeSet
import io.realm.OrderedRealmCollectionChangeListener
import io.realm.RealmObjectChangeListener
@ -66,6 +68,8 @@ internal class TimelineChunk(private val chunkEntity: ChunkEntity,
private var nextChunkLatch: CompletableDeferred<Unit>? = null
private val dbgId = chunkEntity.identifier()
private val dimber = Dimber("TimelineChunks", DbgUtil.DBG_TIMELINE_CHUNKS)
private val chunkObjectListener = RealmObjectChangeListener<ChunkEntity> { _, changeSet ->
if (changeSet == null) return@RealmObjectChangeListener
if (changeSet.isDeleted.orFalse()) {
@ -80,12 +84,12 @@ internal class TimelineChunk(private val chunkEntity: ChunkEntity,
}
if (changeSet.isFieldChanged(ChunkEntityFields.NEXT_CHUNK.`$`)) {
nextChunk = createTimelineChunk(chunkEntity.nextChunk)
Timber.i("TimelineChunk.$dbgId set next to ${nextChunk?.dbgId}")
dimber.i{"TimelineChunk.$dbgId set next to ${nextChunk?.dbgId}"}
nextChunkLatch?.complete(Unit)
}
if (changeSet.isFieldChanged(ChunkEntityFields.PREV_CHUNK.`$`)) {
prevChunk = createTimelineChunk(chunkEntity.prevChunk)
Timber.i("TimelineChunk.$dbgId set prev to ${prevChunk?.dbgId}")
dimber.i{"TimelineChunk.$dbgId set prev to ${prevChunk?.dbgId}"}
prevChunkLatch?.complete(Unit)
}
}
@ -104,7 +108,7 @@ internal class TimelineChunk(private val chunkEntity: ChunkEntity,
private var prevChunk: TimelineChunk? = null
init {
Timber.i("TimelineChunk.init.$dbgId prev ${chunkEntity.prevChunk?.identifier()} next ${chunkEntity.nextChunk?.identifier()}")
dimber.i{"TimelineChunk.init.$dbgId prev ${chunkEntity.prevChunk?.identifier()} next ${chunkEntity.nextChunk?.identifier()}"}
timelineEventEntities.addChangeListener(timelineEventsChangeListener)
chunkEntity.addChangeListener(chunkObjectListener)
}
@ -123,7 +127,9 @@ internal class TimelineChunk(private val chunkEntity: ChunkEntity,
val nextEvents = nextChunk?.builtItems(includesNext = true, includesPrev = false).orEmpty()
deepBuiltItems.addAll(nextEvents)
}
checkTimelineConsistency("TimelineChunk.builtItems.$dbgId", builtEvents, verbose = false)
dimber.exec {
checkTimelineConsistency("TimelineChunk.builtItems.$dbgId", builtEvents, verbose = false)
}
deepBuiltItems.addAll(builtEvents)
if (includesPrev) {
val prevEvents = prevChunk?.builtItems(includesNext = false, includesPrev = true).orEmpty()
@ -149,7 +155,7 @@ internal class TimelineChunk(private val chunkEntity: ChunkEntity,
val offsetCount = count - loadFromStorage.numberOfEvents
Timber.i("TimelineChunk.loadMore.$dbgId: $direction, count = $count, loaded = ${loadFromStorage.numberOfEvents}, offsetCount = $offsetCount, builtEvents = ${builtEvents.size}, available = ${timelineEventEntities.size}")
dimber.i{"TimelineChunk.loadMore.$dbgId: $direction, count = $count, loaded = ${loadFromStorage.numberOfEvents}, offsetCount = $offsetCount, builtEvents = ${builtEvents.size}, available = ${timelineEventEntities.size}"}
return if (offsetCount == 0) {
LoadMoreResult.SUCCESS
@ -265,7 +271,7 @@ internal class TimelineChunk(private val chunkEntity: ChunkEntity,
}
// Update the relation of existing event
builtEvents.getOrNull(builtIndex)?.let { te ->
Timber.i("TimelineChunk.rebuildEvent.$dbgId $eventId at $builtIndex, which was ${te.eventId}")
dimber.i{"TimelineChunk.rebuildEvent.$dbgId $eventId at $builtIndex, which was ${te.eventId}"}
val rebuiltEvent = builder(te)
builtEvents[builtIndex] = rebuiltEvent!!
true
@ -303,7 +309,9 @@ internal class TimelineChunk(private val chunkEntity: ChunkEntity,
.findAll()
.orEmpty()
val builtTimelineEvents = timelineEvents.map { it.buildAndDecryptIfNeeded() }
checkTimelineConsistency("TimelineChunk.loadFromStorage-raw-query.$dbgId", builtTimelineEvents)
dimber.exec {
checkTimelineConsistency("TimelineChunk.loadFromStorage-raw-query.$dbgId", builtTimelineEvents)
}
if (timelineEvents.isEmpty()) return LoadedFromStorage()
// Disabled due to the new fallback
@ -312,9 +320,9 @@ internal class TimelineChunk(private val chunkEntity: ChunkEntity,
// }
if (direction == Timeline.Direction.FORWARDS) {
builtEventsIndexes.entries.forEach { it.setValue(it.value + timelineEvents.size) }
Timber.i("TimelineChunk.loadFromStorage.$dbgId: insert ${timelineEvents.size} items forwards at start, old size: ${builtEvents.size}")
dimber.i{"TimelineChunk.loadFromStorage.$dbgId: insert ${timelineEvents.size} items forwards at start, old size: ${builtEvents.size}"}
} else {
Timber.i("TimelineChunk.loadFromStorage.$dbgId: insert ${timelineEvents.size} items backwards at end, old size: ${builtEvents.size}")
dimber.i{"TimelineChunk.loadFromStorage.$dbgId: insert ${timelineEvents.size} items backwards at end, old size: ${builtEvents.size}"}
}
val extraCheck = mutableListOf<TimelineEvent>()
//timelineEvents
@ -333,7 +341,9 @@ internal class TimelineChunk(private val chunkEntity: ChunkEntity,
}
extraCheck.add(timelineEvent)
}
checkTimelineConsistency("TimelineChunk.loadFromStorage-extra-check.$dbgId", extraCheck)
dimber.exec {
checkTimelineConsistency("TimelineChunk.loadFromStorage-extra-check.$dbgId", extraCheck)
}
return LoadedFromStorage(
threadReachedEnd = threadReachedEnd(timelineEvents),
numberOfEvents = timelineEvents.size)
@ -456,7 +466,7 @@ internal class TimelineChunk(private val chunkEntity: ChunkEntity,
isLastBackward.set(true)
}
val correctedIndex = range.startIndex + index
Timber.i("TimelineChunk.handleDatabaseChangeSet.$dbgId: insert ${timelineEvent.eventId} at $correctedIndex (${range.startIndex} + $index)")
dimber.i{"TimelineChunk.handleDatabaseChangeSet.$dbgId: insert ${timelineEvent.eventId} at $correctedIndex (${range.startIndex} + $index)"}
builtEvents.add(correctedIndex, timelineEvent)
builtEventsIndexes[timelineEvent.eventId] = correctedIndex
}
@ -467,7 +477,7 @@ internal class TimelineChunk(private val chunkEntity: ChunkEntity,
val updatedEntity = results[modificationIndex] ?: continue
val displayIndex = builtEventsIndexes.getOrDefault(updatedEntity.eventId, null)
if (displayIndex == null) {
Timber.w("TimelineChunk.handleDatabaseChangeSet.$dbgId: skip modification for ${updatedEntity.eventId} at $modificationIndex, not found in chunk")
dimber.w{"TimelineChunk.handleDatabaseChangeSet.$dbgId: skip modification for ${updatedEntity.eventId} at $modificationIndex, not found in chunk"}
continue
}
try {

View file

@ -41,6 +41,7 @@ import com.vanniktech.emoji.EmojiManager
import com.vanniktech.emoji.google.GoogleEmojiProvider
import dagger.hilt.android.HiltAndroidApp
import de.spiritcroc.matrixsdk.StaticScSdkHelper
import de.spiritcroc.matrixsdk.util.DbgUtil
import im.vector.app.core.di.ActiveSessionHolder
import im.vector.app.core.extensions.configureAndStart
import im.vector.app.core.extensions.startSyncing
@ -123,6 +124,7 @@ class VectorApplication :
// SC SDK helper initialization
StaticScSdkHelper.scSdkPreferenceProvider = vectorPreferences
DbgUtil.load(appContext)
// Remove Log handler statically added by Jitsi
Timber.forest()

View file

@ -69,6 +69,8 @@ import com.airbnb.mvrx.fragmentViewModel
import com.airbnb.mvrx.withState
import com.google.android.material.dialog.MaterialAlertDialogBuilder
import com.vanniktech.emoji.EmojiPopup
import de.spiritcroc.matrixsdk.util.DbgUtil
import de.spiritcroc.matrixsdk.util.Dimber
import de.spiritcroc.recyclerview.widget.BetterLinearLayoutManager
import im.vector.app.R
import im.vector.app.core.dialogs.ConfirmationDialogBuilder
@ -278,6 +280,8 @@ class TimelineFragment @Inject constructor(
GalleryOrCameraDialogHelper.Listener,
CurrentCallsView.Callback {
private val rmDimber = Dimber("ReadMarkerDbg", DbgUtil.DBG_READ_MARKER)
companion object {
/**
@ -2039,7 +2043,7 @@ class TimelineFragment @Inject constructor(
}
override fun onLoadMore(direction: Timeline.Direction) {
Timber.i("ReadMarker debug: on load more $direction")
rmDimber.i{"on load more $direction"}
timelineViewModel.handle(RoomDetailAction.LoadMoreTimelineEvents(direction))
}

View file

@ -28,6 +28,8 @@ import com.airbnb.mvrx.Uninitialized
import dagger.assisted.Assisted
import dagger.assisted.AssistedFactory
import dagger.assisted.AssistedInject
import de.spiritcroc.matrixsdk.util.DbgUtil
import de.spiritcroc.matrixsdk.util.Dimber
import im.vector.app.AppStateHandler
import im.vector.app.BuildConfig
import im.vector.app.R
@ -143,6 +145,8 @@ class TimelineViewModel @AssistedInject constructor(
}
}
private val rmDimber = Dimber("ReadMarkerDbg", DbgUtil.DBG_READ_MARKER)
// Same lifecycle than the ViewModel (survive to screen rotation)
val previewUrlRetriever = PreviewUrlRetriever(session, viewModelScope)
@ -638,7 +642,7 @@ class TimelineViewModel @AssistedInject constructor(
if (trackUnreadMessages.getAndSet(false)) {
mostRecentDisplayedEvent?.root?.eventId?.also {
session.coroutineScope.launch(NonCancellable) {
Timber.i("ReadMarker debug: set RM and RR to $it")
rmDimber.i{"set RM and RR to $it"}
tryOrNull { room.setReadMarker(it) }
if (loadRoomAtFirstUnread()) {
tryOrNull { room.setReadReceipt(it) }
@ -1128,21 +1132,21 @@ class TimelineViewModel @AssistedInject constructor(
}
}
.setOnEach {
Timber.i("ReadMarker debug: update unreadState = $it")
rmDimber.i{"update unreadState = $it"}
copy(unreadState = it)
}
}
private fun computeUnreadState(events: List<TimelineEvent>, roomSummary: RoomSummary): UnreadState {
Timber.i("ReadMarker debug: computeUnreadState, empty = ${events.isEmpty()}, markerId = ${roomSummary.readMarkerId}")
rmDimber.i{"computeUnreadState, empty = ${events.isEmpty()}, markerId = ${roomSummary.readMarkerId}"}
if (events.isEmpty()) return UnreadState.Unknown
val readMarkerIdSnapshot = roomSummary.readMarkerId ?: return UnreadState.Unknown
val firstDisplayableEventIndex = timeline.getIndexOfEvent(readMarkerIdSnapshot)
?: return if (timeline.isLive) {
Timber.i("ReadMarker debug: is live, but did not get index")
rmDimber.i{"is live, but did not get index"}
UnreadState.ReadMarkerNotLoaded(readMarkerIdSnapshot)
} else {
Timber.i("ReadMarker debug: not live")
rmDimber.i{"not live"}
UnreadState.Unknown
}
// If the read marker is at the bottom-most event, this doesn't mean we read all, in case we just haven't loaded more events.
@ -1154,17 +1158,14 @@ class TimelineViewModel @AssistedInject constructor(
val timelineEvent = events.getOrNull(i) ?: return UnreadState.Unknown
val eventId = timelineEvent.root.eventId ?: return UnreadState.Unknown
val isFromMe = timelineEvent.root.senderId == session.myUserId
Timber.i("ReadMarker debug: isFromMe = $isFromMe")
rmDimber.i{"isFromMe = $isFromMe"}
if (!isFromMe) {
return UnreadState.HasUnread(eventId)
}
Timber.i("ReadMarker debug: hasNoUnread / firstDisplayableEventIndex: $firstDisplayableEventIndex / " +
"latest previewable from summary ${roomSummary.latestPreviewableOriginalContentEvent?.eventId} - ${timeline.getIndexOfEvent(roomSummary.latestPreviewableOriginalContentEvent?.eventId)} / " +
"event-0 ${events.getOrNull(0)?.eventId}")
}
Timber.i("ReadMarker debug: hasNoUnread / firstDisplayableEventIndex: $firstDisplayableEventIndex / " +
rmDimber.i{"hasNoUnread / firstDisplayableEventIndex: $firstDisplayableEventIndex / " +
"latest previewable from summary ${roomSummary.latestPreviewableOriginalContentEvent?.eventId} - ${timeline.getIndexOfEvent(roomSummary.latestPreviewableOriginalContentEvent?.eventId)} / " +
"event-0 ${events.getOrNull(0)?.eventId}")
"event-0 ${events.getOrNull(0)?.eventId}"}
return UnreadState.HasNoUnread
}
@ -1213,7 +1214,7 @@ class TimelineViewModel @AssistedInject constructor(
}
override fun onTimelineUpdated(snapshot: List<TimelineEvent>) {
Timber.i("ReadMarker debug: onTimelineUpdated")
rmDimber.i{"onTimelineUpdated"}
viewModelScope.launch {
// tryEmit doesn't work with SharedFlow without cache
timelineEvents.emit(snapshot)

View file

@ -16,6 +16,7 @@
package im.vector.app.features.home.room.detail.timeline.helper
import de.spiritcroc.matrixsdk.util.DbgUtil
import im.vector.app.core.date.DateFormatKind
import im.vector.app.core.date.VectorDateFormatter
import im.vector.app.core.extensions.localDateTime
@ -76,7 +77,7 @@ class MessageInformationDataFactory @Inject constructor(private val session: Ses
prevDisplayableEvent?.root?.localDateTime()?.toLocalDate() != date.toLocalDate()
val time = dateFormatter.format(event.root.originServerTs, DateFormatKind.MESSAGE_SIMPLE).let {
if (vectorPreferences.developerShowDebugInfo()) {
if (DbgUtil.isDbgEnabled(DbgUtil.DBG_SHOW_DISPLAY_INDEX)) {
"$it | ${event.displayIndex}"
} else {
it

View file

@ -18,6 +18,8 @@ package im.vector.app.features.home.room.detail.timeline.helper
import com.airbnb.epoxy.EpoxyModel
import com.airbnb.epoxy.VisibilityState
import de.spiritcroc.matrixsdk.util.DbgUtil
import de.spiritcroc.matrixsdk.util.Dimber
import im.vector.app.core.epoxy.LoadingItem_
import im.vector.app.features.home.room.detail.UnreadState
import im.vector.app.features.home.room.detail.timeline.TimelineEventController
@ -36,6 +38,8 @@ class TimelineControllerInterceptorHelper(private val positionOfReadMarker: KMut
private var previousModelsSize = 0
private val rmDimber = Dimber("ReadMarkerDbg", DbgUtil.DBG_READ_MARKER)
// Update position when we are building new items
fun intercept(
models: MutableList<EpoxyModel<*>>,
@ -50,7 +54,7 @@ class TimelineControllerInterceptorHelper(private val positionOfReadMarker: KMut
models.addBackwardPrefetchIfNeeded(timeline, callback)
models.addForwardPrefetchIfNeeded(timeline, callback)
Timber.i("ReadMarker debug: intercept $unreadState")
rmDimber.i{"intercept $unreadState"}
val modelsIterator = models.listIterator()
var index = 0
@ -84,7 +88,7 @@ class TimelineControllerInterceptorHelper(private val positionOfReadMarker: KMut
index++
positionOfReadMarker.set(index)
appendReadMarker = false
Timber.i("ReadMarker debug: read marker appended at $index")
rmDimber.i{"ReadMarker debug: read marker appended at $index"}
}
index++
}

View file

@ -0,0 +1,44 @@
package im.vector.app.features.settings
import androidx.annotation.StringRes
import androidx.preference.Preference
import de.spiritcroc.matrixsdk.util.DbgUtil
import im.vector.app.R
import im.vector.app.core.preference.VectorSwitchPreference
import javax.inject.Inject
class VectorSettingsScDebuggingFragment @Inject constructor(
//private val vectorPreferences: VectorPreferences
) : VectorSettingsBaseFragment(), Preference.OnPreferenceChangeListener {
override var titleRes = R.string.settings_sc_debugging
override val preferenceXmlRes = R.xml.vector_settings_sc_debugging
data class DbgPref(val key: String, @StringRes val stringRes: Int)
val dbgPrefs = arrayOf(
DbgPref(DbgUtil.DBG_TIMELINE_CHUNKS, R.string.settings_sc_dbg_timeline_chunks),
DbgPref(DbgUtil.DBG_SHOW_DISPLAY_INDEX, R.string.settings_sc_dbg_show_display_index),
DbgPref(DbgUtil.DBG_READ_MARKER, R.string.settings_sc_dbg_read_marker),
)
override fun bindPref() {
dbgPrefs.forEach { dbgPref ->
var pref: VectorSwitchPreference? = findPreference(dbgPref.key)
if (pref == null) {
pref = VectorSwitchPreference(requireContext())
pref.key = dbgPref.key
pref.title = getString(dbgPref.stringRes)
preferenceScreen.addPreference(pref)
}
pref.isChecked = DbgUtil.isDbgEnabled(pref.key)
pref.onPreferenceChangeListener = this
}
}
override fun onPreferenceChange(preference: Preference?, newValue: Any?): Boolean {
if (newValue is Boolean && dbgPrefs.any { preference?.key == it.key }) {
DbgUtil.onPreferenceChanged(requireContext(), preference?.key as String, newValue)
}
return true
}
}

View file

@ -165,4 +165,11 @@
<!-- Default notification rule -->
<string name="room_settings_default">Default</string>
<!-- SC debugging -->
<string name="settings_sc_debugging">Schildi-debugging</string>
<string name="settings_sc_debugging_summary">Enable additional logs or debugging features</string>
<string name="settings_sc_dbg_read_marker">Debug read markers</string>
<string name="settings_sc_dbg_timeline_chunks">Debug timeline consistency</string>
<string name="settings_sc_dbg_show_display_index">Show displayIndex in timeline</string>
</resources>

View file

@ -44,6 +44,11 @@
android:summary="@string/settings_developer_mode_fail_fast_summary"
android:title="@string/settings_developer_mode_fail_fast_title" />
<im.vector.app.core.preference.VectorPreference
android:title="@string/settings_sc_debugging"
android:summary="@string/settings_sc_debugging_summary"
app:fragment="im.vector.app.features.settings.VectorSettingsScDebuggingFragment" />
</im.vector.app.core.preference.VectorPreferenceCategory>
<im.vector.app.core.preference.VectorPreferenceCategory

View file

@ -0,0 +1,9 @@
<?xml version="1.0" encoding="utf-8"?>
<androidx.preference.PreferenceScreen xmlns:android="http://schemas.android.com/apk/res/android"
xmlns:app="http://schemas.android.com/apk/res-auto"
xmlns:tools="http://schemas.android.com/tools">
<im.vector.app.core.preference.VectorPreference
android:summary="@string/settings_sc_debugging_summary" />
</androidx.preference.PreferenceScreen>