Chapters

Hide chapters

Android Debugging by Tutorials

First Edition · Android 12 · Kotlin 1.6 · Android Studio Chipmunk (2021.2.1)

Section I: Debugging Basics

Section 1: 8 chapters
Show chapters Hide chapters

3. Logcat Navigation & Customization
Written by Vincenzo Guzzi

The Logcat window in Android Studio acts as a central hub for displaying system and custom messages of applications across Android devices connected via the Android Debug Bridge - ADB.

With the power of the Logcat window, you can view messages in real-time and historically, allowing you to understand exactly how your apps function by viewing the logs they emit.

In this chapter, you’ll discover how to utilize the Logcat window to its fullest potential as you navigate PodPlay and fix a selection of bugs by emitting and reading logs. You’ll learn how to:

  • Navigate the Logcat window.
  • Send custom log messages from your app.
  • Customize the Logcat window, making it easier to read.
  • Filter your logs.
  • Use logs to help you find and fix bugs.

Breaking Down the Logcat Window

To become familiar with the Logcat window, you’ll have to produce some logs first.

Open the Podplay starter project in Android Studio and run PodPlay. Complete these actions inside the app:

  1. Search for the term Farm using the search icon.
  2. Tap the first podcast in the list of results.
  3. Choose the first podcast episode.
  4. Tap the play icon and wait for it to load and start playing.
  5. Pause the podcast.

In Android Studio, expand the Logcat window by clicking View ▸ Tool Windows ▸ Logcat.

You can also expand and minimize the Logcat window by clicking the Logcat tab at the bottom of Android Studio:

There’s now a whole bunch of logs that your Android device has produced; it can be pretty daunting at first sight as there are so many! You’re going to work through it bit by bit.

Now take a closer look:

At the top, you can find:

  1. Android device selector - If you have multiple Android devices connected via the ADB, you can select which device’s logs to view with this option.
  2. Process selector - You can switch between multiple apps or processes with this option. This is useful in cases where you’d like to see how your app interacts with a different Android service such as Bluetooth or the phone’s photo gallery app.
  3. Log level - A quick filter that toggles between different log severity levels.
  4. Filter search bar - This allows filtering the logs displayed based on text or regex.
  5. Filter menu - Use this to filter the logs based on the source of executing process.

For now, make sure that you have Show only selected application in the filter menu:

Your Android device will emit all of your system logs if you don’t have this selected, even if your active app isn’t producing them. In most cases, you’ll want this filter on.

Logs that are output by an Android application can be of six different severity levels:

  1. Verbose - The lowest severity level log; this shouldn’t compile these logs into an application outside of development; choose this filter if you want to see every log level.

  2. Debug - Logs that are useful only during development; they should be stripped from release builds.

  3. Info - General informative log message for standard usage, these are intended to be kept in a release environment.

  4. Warn - Shows possible issues that could become errors; these are always kept in a released app build.

  5. Error - Logs that emit due to errors in the application; these will be displayed in a release build.

  6. Assert - Logs that should never be shown; if they are, something has gone critically wrong with the app.

Next, ensure that the process selector is set to com.yourcompany.podplay and the log level is set to Warn.

Setting the log level filter like this tells Logcat only to display logs that are the level of Warn or higher. (The log levels higher than Warn are Error and Assert.)

You’ll now see several Warn level log messages:

Logs that are warnings generally appear as an app launches. This is due to the nature of warnings. A program compiles anything that the program doesn’t think is set up perfectly and may cause a future error only once.

In this particular case, the emitted logs are due to the selected emulator and outdated code it uses within the Android open source project libraries, you can ignore them. With Android updates, most of the existing warnings disappear, and new ones may show up. It takes a keen eye to spot a warning that’s due to your own code; you should fix these as soon as they’re spotted.

Take a detailed look at one log:

Here’s an explanation of the format:

  1. The date and time that the log was sent.
  2. The identifier of the process and thread that sent the log.
  3. Package ID of the app that sent the log.
  4. Log priority identifier, e.g. W for Warn, I for Info etc.
  5. The log tag that helps identify where the log came from; usually the class name.
  6. The log message itself appears last.

This is the format for every log, no matter the log level.

Now, click the Log level drop-down and select Info:

With the log severity level decreased, you’ll see some additional Info logs that have appeared in the Logcat window. These are general information logs that tell you useful information about your running processes.

In this example, there are new Info logs telling you that the Java garbage collector has freed up some memory and another that tells you the number of windows and views displayed.

Go back to the Log level drop-down again and select the Debug filter:

You can see debug logs, such as “Connecting to a MediaBrowserService” and other, more detailed logs that can help you debug the app:

Finally, enable all of the logs by selecting Verbose in the Log level drop-down:

The Logcat fills up with a lot more logs with the Verbose level enabled. You can see logs detailing things like the app’s API connections:

Now that you’ve enabled all the logs, you’re able to see a lot of system information that tells you what the app is doing at each moment.

However, this information is pretty useless if you’re not looking at the logs in real-time, as you have no way of linking the system logs to what actions are being completed within the app. This is because you’re not sending any custom logs.

Next, you’ll go through the process of adding custom logs throughout the PodPlay code so that you can easily interpret what PodPlay is doing at each moment from the Logcat.

Adding Custom Logs

You can create and post any kind of log message to Logcat. Doing so can be a powerful tool that can help you debug your app without needing to set breakpoints. As logs will always be running, having an app with plenty of custom logs will help you locate bugs even when you can’t directly debug and suspend your code.

To send logs to the Logcat, there is a utility class in Android named Log. You’ll use this class to set your custom log severity levels, tags, and messages.

In the starter project, open PodcastActivity.kt and add the Log import to the top of the file next to all of your other imports:

import android.util.Log

Above the PodcastActivity class declaration, add a new constant variable called TAG and set the value to PodcastActivity:

private const val TAG = "PodcastActivity"

This will be the tag you’ll use for all of the custom logs that you’ll send within PodcastActivity. You can, of course, set tags to anything. As a default, it’s best practice to have your custom log tag as the class which has sent the log so you can easily map the location.

Info Logs

When you’re viewing logs, the main piece of information that you need to know is where the app code is during an event. To do this, you can decorate your code with Info logs that simply state what has been called.

Underneath onCreate() inside PodcastActivity, add an override for onResume() and add a custom log inside the method that tells the Logcat that you’ve called this method:

override fun onResume() {
  super.onResume()
  Log.i(TAG, "onResume() called.")
}

The Log class has a number of different static methods which dictate the logs severity level, the very same severity levels discussed earlier in this chapter:

  • Log.v(): Verbose.
  • Log.d(): Debug.
  • Log.i(): Info.
  • Log.w(): Warning.
  • Log.e(): Error.

Each method takes a tag and message String parameter as well as an optional Throwable parameter that logs an exception.

Scroll further down in PodcastActivity until you get to onNewIntent(). Replace // TODO 1 in this method with another info log:

Log.i(TAG, "onNewIntent() called with intent: ${intent.action}.")

Here, you are again logging the information that you’ve called onNewIntent(). You’re also passing the action of the Intent within your log’s message string. It’s always best to include any relevant information in your logs that may be able to help with debugging your code.

Below, find onShowDetails() and replace // TODO 2 with a custom log:

Log.i(TAG, "Retrieving podcast feed for podcast named '${podcastSummaryViewData.name}'")

You’re leaving more detailed information that you’re about to retrieve a podcast feed.

Now, build and run the app again, ensuring you have the Logcat window expanded. Switch the severity level filter to Info. You only want to see the logs of severity level Info and higher right now.

You’ll see right away that you’re now getting an “onResume() called” log appear in the Logcat window:

In PodPlay, tap on the search icon and enter the term test:

Tap on the first podcast that you see and observe the logs:

You’ll now see it sending additional custom logs that inform you’re calling onNewIntent() and that it is retrieving a podcast feed.

With only sending these three additional logs, the Logcat window has become a lot easier to read as, in between the system logs, there are details of what the app is doing at any given time.

Debug Logs

Now that you’ve added some Info logs and seen the clarity that they can add to the Logcat, you’ll gain even more insight by adding debug logs that will inform the Logcat reader of the speed at which it can retrieve a podcast’s information.

Open PodcastViewModel.kt and, just like previously, add a constant variable called TAG above the class declaration:

private const val TAG = "PodcastViewModel"

Also, add the Log utility method import at the top of the file:

import android.util.Log

Now, scroll down to the method getPodcast() and replace // TODO 3 with a new custom log:

Log.d(TAG, "Calling getPodcast for podcast named ${podcastSummaryViewData.name}, recording time.")

You’re setting this log’s severity level to Debug as you’ll use this to debug how long it takes to retrieve a podcast from the repository. This log states the podcast name that the app is about to retrieve data for; it also states that it’s recording the time.

Next, you’ll need to measure the actual time to log this in a message when the call is complete. You’ll use the Kotlin system method measureTimeMillis() to do this.

To be able to use the method, add it to the imports section at the top of the file:

import kotlin.system.measureTimeMillis

Now, go back to getPodcast(). Find // TODO 4 and replace the getPodcast() call wrapped in measureTimeMillis():

val timeInMillis = measureTimeMillis {
  podcast = podcastRepo?.getPodcast(url)
}

timeInMillis is now populated with the number of milliseconds that it took to execute the getPodcast() repository call. Create a new custom log that shares this information by replacing // TODO 5 further down in the method with:

Log.d(TAG, "getPodcast() for podcast named ${podcastSummaryViewData.name} completed, time taken: $timeInMillis milliseconds.")

Switch the Logcat severity level to Debug, then build and run the app to see this new log in action.

Search for a podcast with the term test by tapping on the search icon and then tap on the first podcast in the results list.

You’ll receive some awesome debug information that details how long it takes the app to retrieve a podcast’s details:

Filtering and Customizing the Logcat Window

When the Logcat window emits many logs, it can become quite cumbersome; it’s hard to navigate and locate the logs you care about quickly. There are ways to improve this with customization and additional filtering.

Customizing Logcat Headers

In the Logcat toolbar to the left, there is a cog icon that has the label Logcat Header:

Click this cog and a Configure Logcat Header dialog will appear:

You can choose what information you’d like to include in each log using this dialog.

Go ahead and uncheck Show date and time, Show process and thread IDs and Show package name:

Click OK.

Your logs now won’t have all of the prefixed metadata, like package and thread ID, making the logs simpler and easier to read.

Note: You can re-enable any prefixes by going back to the Logcat Header setting and checking the relevant boxes.

Folding Logs

Folding is another tool that you can use to partially remove logs that aren’t important to you from view. It’s collapsing some data into a condensed view, so it takes up less screen real estate; you can then usually unfold or expand the collapsed view with a click.

You can use this method of folding with Android code by collapsing scopes like for loops and if statements; you can even collapse whole classes.

You can do this with logs too! Find a log that you would rather fold from view, right-click and select Fold Lines Like This:

This will open a console dialog where you can add, remove or edit the regex pattern of logs you want to fold:

You can add any type of text to this list. If it matches the results of a log, it will fold. To demonstrate this, input a new line by clicking the plus icon and entering the text Accessing hidden method.

Click OK.

With the Verbose severity level set, scroll up in the Logcat window, and you’ll see folded logs that state <3 internal lines>:

Clicking this will expand the folded logs:

Clicking the fold icon to the left of these logs will collapse them again:

By setting up your fold filters appropriately, you can get to a state within the Logcat window where only logs you would actively like to view begin in an expanded state, whereas all others are folded.

Creating Custom Filter Configurations

The easiest filter to use is also the most powerful, the Logcat search bar:

The search bar can match exact text for the logs you’d like to find, with the ability even to match regex patterns for more advanced searching.

Every part of a log is searchable, including the tag. Searching for tags can be a powerful and quick way to find the logs you’re looking for instantly. Add PodcastActivity into the search bar to quickly find all your logs with that tag that have:

You may want to save a search that you find yourself repeatedly using so that you can quickly select it. You can do this with Filter Configurations located to the right of the search bar.

Click Edit Filter Configurations by selecting the Filter Configurations drop-down:

In Edit Filter Configurations, you have access to an even more powerful set of search settings that allow you to combine multiple search results into one filter.

Add a permanent filter configuration for viewing your custom logs so you can easily toggle it to on in the Logcat window.

In the Filter Name input field type PodPlay Custom Logs, and in the Log Tag input field add the regex PodcastActivity|PodcastViewModel:

Click OK.

This will create a new filter that searches for all logs that have the tag of either PodcastActivity or PodcastViewModel. You can select this filter, or a different one, by going back to the Filter Configurations drop-down:

Using Logs to Fix a Bug

Now that you’ve mastered the art of logging, you’ll put these new skills into practice by identifying a bug and then fixing it.

Your first step is to find a bug.

Launch PodPlay and make sure that you have the Logcat window open to see emitting logs while navigating the app. Set the Log level filter to Info and make sure you’re not using the custom filter configuration:

Search for a podcast by inputting Science into the search window of PodPlay and tap on the first podcast in the list of results. Then, select the first podcast episode. You’ll now be on an episode with the ability to play the podcast.

Press the Play icon and observe the lag between pressing play and the podcast actually playing.

This is strange behavior; something is clearly misbehaving, the Logcat can help identify the problem.

Open the Logcat window, and you’ll see that an Info log with the tag of Choreographer has been output:

The message says:

“Skipped 42 frames! The application may be doing too much work on its main thread.”

This log appears exactly as you press the Play icon for a podcast episode but not on subsequent playing after pausing the episode.

Interesting!

Armed with this information, you know that something is wrong; something is blocking the main thread and causing lag.

The next step is to add custom logs to PodplayMediaCallback so you can locate the exact method that is blocking the main thread.

Using Custom Logs to Locate a Problem

Open PodplayMediaCallback.kt. Above the class declaration add a constant called TAG:

private const val TAG = "PodplayMediaCallback"

Now add the Log utility import to the top of the file so you can use it throughout this class:

import android.util.Log

To locate the offending method, you’ll need to add custom logs that inform you of when it calls each method to get more clarity on what PodPlay is doing when the bug occurs.

Start off with onPlay().

Scroll down PodplayMediaCallback until you find onPlay() and replace // TODO 6 with an Info log:

Log.i(TAG, "onPlay() called.")

Do the same in onStop() by replacing // TODO 7:

Log.i(TAG, "onStop() called.")

Finally, modify onPause() by replacing // TODO 8:

Log.i(TAG, "onPause() called.")

Scroll down to initializeMediaPlayer() and replace // TODO 9 with an Info log that informs it has been called:

Log.i(TAG, "initializeMediaPlayer() called.")

Similar to before, replace // TODO 10 within prepareMedia():

Log.i(TAG, "prepareMedia() called.")

And finally, inside startPlaying() replace // TODO 11 with another Info log:

Log.i(TAG, "startPlaying() called.")

You’ve now added six Info logs to PodplayMediaCallback. These will give you a lot more context when trying to locate the bug that’s blocking the main thread.

Build and run PodPlay and, once again, navigate to a podcast episode and play it by pressing the Play icon.

Take a look at the logs; you can see that the Logcat is emitting each Info log and the skipped frames system log appears at the end. This doesn’t tell you much about the exact method causing issues, but you may have noticed that one of the methods took longer to execute.

If you don’t see the log times, enable the time Logcat header, Show date and time, by clicking the Configure Logcat Header settings icon, then look at the logs again:

You can see that a larger than average amount of time passed between prepareMedia() and startPlaying().

prepareMedia() is blocking the main thread!

Fixing the Bug

This book is about locating problems, not necessarily how to fix them. But you can can solve this particular problem by wrapping prepareMedia() inside onPlay() in an asynchronous call, so it doesn’t block the main thread:

CoroutineScope(Dispatchers.IO).async {
  prepareMedia()
}.invokeOnCompletion{
  startPlaying()
}

This requires adding three additional imports to the top of the file:

import kotlinx.coroutines.CoroutineScope
import kotlinx.coroutines.Dispatchers
import kotlinx.coroutines.async

Now, if you reinstall the app and try playing an episode, you’ll notice that the “skipped frames” is no longer displayed, indicating that the main thread is not blocked. You’ve successfully fixed a bug by observing the Logcat.

Challenge

A frustrating situation happens when you attempt to click the podcast series called Early Middle Ages; it doesn’t do anything!

The Logcat window is sparse when clicking this podcast; it doesn’t log any debug or info logs that state what is wrong. It’s up to you to change that in this challenge.

Use what you’ve learned so far with breakpoints and logging to find out why this bug is happening and implement a viable solution.

Go to the challenge or final projects for this chapter if you need help locating this bug.

Key Points

  • Logs can be of different severity levels: Verbose, Debug, Info, Error, Warn and Assert.
  • You can configure the Logcat window to make it easier to read by clicking the Logcat Header icon.
  • Fold logs that you don’t care about by right-clicking it and selecting Fold Lines Like This.
  • Send custom logs from the app using the Util Log method.
  • Decorate the app with Info logs so it can debug the Logcat window more easily.
  • Add custom filer configurations by clicking Edit Filter Configurations in the Logcat window.

Where to Go From Here?

In this chapter, you learned a lot about logs and how to customize Logcat as per your needs. Great job!

If you’re interested in discovering more about this topic, check out the Android documentation about Logcat.

Don’t stop here. In the following chapter, you’ll find out how to deal with stack traces and how to analyze them.

Have a technical question? Want to report a bug? You can ask questions and report bugs to the book authors in our official book forum here.
© 2024 Kodeco Inc.