How to Debug Jetpack Compose Recomposition with Logging?

Recomposition in Jetpack Compose is a complex topic. It is complex because sometimes you have no idea why a certain function is recomposed, which is not what you expected based on your knowledge. Thus, you need to debug it.

Breakpoints in Debugger

Using breakpoints in a debugger first comes to my mind to debug recomposition. However, there are a few limitations to this approach.

• It doesn't tell you recomposition scope information(i.e. $currentRecomposeScope- see below)

• It doesn't keep track of how many recompositions have been occurred

Standard Logging

So to debug with logging, you use Log.d. It looks like this

Log.d("DebugRecomposition", "RecompositionExample() function scope")

But it missed one important piece of information, which doesn't tell the current recompose scope information. This information is important because different composable functions can still have the same recompose scope - see the explanation below.

To print this recompose scope information, you use $currentRecomposeScope. Now the logging looks like this

Log.d("DebugRecomposition", "RecompositionExample() function scope $currentRecomposeScope")

The log output looks like this:

D/DebugRecomposition: RecompositionExample() function androidx.compose.runtime.RecomposeScopeImpl@894fab8

This RecomposeScopeImpl@894fab8 is the unique ID for this recompose scope. If another composable function has the same unique ID, it means it also belongs to this same recompose scope.

Well, there is still one missing piece of information - the recomposition count. Technically, you still can manually count the log statement, but that is very troublesome and prone to error. Because of that, you need custom logging.

Custom Logging

I steal the custom logging code from this very good post about recomposition here, and I make a few modifications to it because I think some stuff is just unnecessary.

Here is the modified version:

class RecompositionCounter(var value: Int)

@Composable
inline fun LogCompositions(tag: String, msg: String) {
    if (BuildConfig.DEBUG) {
        val recompositionCounter = remember { RecompositionCounter(0) }

        Log.d(tag, "$msg ${recompositionCounter.value} $currentRecomposeScope")
        recompositionCounter.value++
    }
}

• I renamed class Ref to class RecompositionCounterto better reflect it is the recomposition count

• I removed SideEffect {} and moved the counter increment after the logging. I do not think we need SideEffect {}here.

• I added $currentRecomposeScope as additional information which I think is important.

The inline is to ensure the parent who calls this composable function has the same composable function scope. In other words, when a parent is recomposed, this LogCompositions() function definitely will be called.

Examples

Let's look at a simple example below.

@Composable
fun RecompositionExample() {
    var count by remember { mutableStateOf(0) }

    LogCompositions("DebugRecomposition", "RecompositionExample() function scope")

    Column {

        LogCompositions("DebugRecomposition", "Column() content scope")

        MyButton(onClick = { count++ }, text = count.toString())

    }
}

@Composable
fun MyButton(
    onClick: () -> Unit,
    text: String) {

    LogCompositions("DebugRecomposition", "MyButton() function")

    Button(onClick = onClick) {

        LogCompositions("DebugRecomposition", "Button() content")

        Text(
            text = text,
        )
    }
}

MyButton is a wrapper for Button() with Text() in its content lambda.

Please note the difference between function scope and content scope.

• Function scope is the scope inside the function.

  Content scope is the trailing lambda scope, the last lambda parameter of the function.

The log output looks like this during start-up:

D/DebugRecomposition: RecompositionExample() function scope 0 androidx.compose.runtime.RecomposeScopeImpl@894fab8

D/DebugRecomposition: Column() content scope 0 androidx.compose.runtime.RecomposeScopeImpl@894fab8

D/DebugRecomposition: MyButton() function 0 androidx.compose.runtime.RecomposeScopeImpl@399bf6

D/DebugRecomposition: Button() content 0 androidx.compose.runtime.RecomposeScopeImpl@dc1e8e2

• You notice the RecompositionExample() and Column() have the same recompose scope. This is because common layouts such as Column(), Row(), and Box() are all "inline" composable functions. Thus, they have the SAME recompose scope as their callers.

If you click the button, the log output looks like this:

D/DebugRecomposition: RecompositionExample() function scope 1 androidx.compose.runtime.RecomposeScopeImpl@894fab8

D/DebugRecomposition: Column() content scope 1 androidx.compose.runtime.RecomposeScopeImpl@894fab8

D/DebugRecomposition: MyButton() function 1 androidx.compose.runtime.RecomposeScopeImpl@399bf6

D/DebugRecomposition: Button() content 1 androidx.compose.runtime.RecomposeScopeImpl@dc1e8e2

• When the button is clicked, the count state is mutated. Thus, all to recompose scopes that read the state will be recomposed.

• In column() scope, it reads the count state from text = count.toString(). Thus, column() is recomposed. Because column() and RecompositionExample() has the same recompose scope, RecompositionExample() is recomposed as well.

• MyButton() is recomposed because the input parameter text is changed. Scope that read the text will be recomposed. Thus, Button() and Text() are recomposed too. There is no logging for Text(), so it doesn't show up in the log.

Conclusion

As mentioned, recompose is a complex topic. This article doesn't focus on why and how recomposition can happen. It covers a bit in the examples above, but it is just a fairly basic demonstration.

This article shows how you can debug it using the custom logging LogCompositions() to figure out how recomposition behaves. In my opinion, recomposition is the most important concept to master in Jetpack Compose, understanding how it works is crucial.

Source Code

GitHub Repository: Demo_UnderstandComposeConcept