Investigating and Fixing an Android ROM Bug

Today, I’ve fixed a bug that was reported on my Android 6.0 AOSP ROM. Since the bug was quite simple, but compassed a few layers, I thought I should write down my methods in case other ROM hackers or other people interested in ROM hacking would find it useful.

The bug was simple. In-call mic mute doesn’t work. So let’s go through the steps I took to investigate and fix the issue.


Reproduce the bug and gather logs

Before trying to fix the bug, one must ensure that it actually exists. So I went ahead and called my phone and tried the mute button. Yep, it doesn’t work, I can still hear my voice on the other side.

So to find out what’s happening, I need to gather logs using Android’s logcat command. What some people might not know is that there are many log buffers that the Android system writes to and by default, the logcat command does not show all of them. One log it omits is the radio logcat. Because, this issue may be related to the radio, I used the follow command to ensure that all logs are shown.

adb logcat -b all

Right when I pressed the mute button, these lines were shown in logcat.

01–24 09:57:24.694 569 1954 I Telecom : Event: Call 3: MUTE, on
01–24 09:57:24.695 569 1954 I Telecom : CallAudioManager: setSystemAudioState: changing from [AudioState isMuted: false, route: EARPIECE, supportedRouteMask: EARPIECE, SPEAKER] to [AudioState isMuted: true, route: EARPIECE, supportedRouteMask: EARPIECE, SPEAKER]
01–24 09:57:24.695 569 1954 I Telecom : Event: Call 3: AUDIO_ROUTE, EARPIECE
01–24 09:57:24.695 569 1954 I Telecom : InCallController: Calling onAudioStateChanged, audioState: [AudioState isMuted: false, route: EARPIECE, supportedRouteMask: EARPIECE, SPEAKER] -> [AudioState isMuted: true, route: EARPIECE, supportedRouteMask: EARPIECE, SPEAKER]
01-24 09:57:24.696 154 922 W audio_hw_hdmi: HDMI device get called get_mic_mute: state addr=0

Normally, the first thing I would look for are errors. Unfortunately, there isn’t one apparent here, so more investigation must be done.

Trying a previous version

If something previously worked in a previous version, then it would be a huge clue (which is why I ask people to help try previous versions when reporting bugs). Trying previous versions of the Android 6.0 AOSP ROM probably wouldn’t help since there are no recent changes which might have broken it, so I went ahead and installed CyanogenMod 12.1 (which is Android 5.1.1) to investigate the issue.

I found that the mute button worked fine in CyanogenMod 12.1 and so took another logcat to compare.

I/Telecom ( 468): CallAudioManager: changing audio state from [AudioState isMuted: false, route; EARPIECE, supportedRouteMask: EARPIECE, SPEAKER] to [AudioState isMuted: true, route; EARPIECE, supportedRouteMask: EARPIECE, SPEAKER]
I/Telecom ( 468): CallAudioManager: changing microphone mute state to: true
D/AudioHardwareALSA( 146): setMicMute mControl state = 1 mutestate = 0****
W/audio_hw_hdmi( 146): HDMI device get called set_mic_mute: state=1
I/Telecom ( 468): InCallController: Calling onAudioStateChanged, audioState: [AudioState isMuted: false, route; EARPIECE, supportedRouteMask: EARPIECE, SPEAKER] -> [AudioState isMuted: true, route; EARPIECE, supportedRouteMask: EARPIECE, SPEAKER]

Because the two logs were taken from different versions of Android, you can’t just compare them line-by-line. However, the differences can point to a clue. Here, the line “CallAudioManager: changing microphone mute state to: true” is present here, but not in Android 6.0.

Checking the source code

From the previous clue, I deduced that we can gain something by tracing through CallAudioManager. Because Android’s source code in quite large, doing a search from a text editor on your local system can take a very long time. Luckily, AndroidXRef has already indexed the source code which we can search through. So I went ahead and search for the “changing microphone mute state” string.

Bingo! We’ve found where that string came from.

This is the code snippet from where that piece of log came from.

case MSG_AUDIO_MANAGER_SET_MICROPHONE_MUTE: {
boolean mute = (msg.arg1 != 0);
if (mute != mAudioManager.isMicrophoneMute()) {
Log.i(this, "changing microphone mute state to: %b", mute);
mAudioManager.setMicrophoneMute(mute);
}
break;
}

To investigate more, I decided to set breakpoints and step through the code. If you have the Android source code loaded in Eclipse or IntelliJ (I use IntelliJ), you can set it up to connect to your Android device to remotely debug the code. I won’t go into the detail here, but basically, you open Android Device Monitor, click on the process you want to debug and set your IDE to connect to JDWP on port 8700. In this case, we want to debug “system_process” because there’s where CallManager runs. (You can find out by checking the PID in the logcat.)

After playing around with breakpoints, I’ve found that:

  1. This code snippet is getting called. (So there’s no problem up until this point)
  2. mAudioManager.isMicrophoneMute() always return true, so the code inside isn’t getting executed.

Continuing the chase

So our next step is to find out why that method always return true. I went ahead and search for it on AndroidXRef. The code is in AudioManager.java and calls AudioSystem.isMicrophoneMuted().

Continuing the search, I’ve found that AudioSystem.isMicrophoneMuted() is a native function.

/*
* Checks whether the microphone mute is on or off.
*
* @return true if microphone is muted, false if it's not
*/
public static native boolean isMicrophoneMuted();

Jumping through android_media_AudioSystem.cpp (1) (2) and AudioSystem.cpp, I’ve finally landed at the implementation in AudioFlinger.cpp.

bool AudioFlinger::getMicMute() const
{
status_t ret = initCheck();
if (ret != NO_ERROR) {
return false;
}
bool mute = true;
bool state = AUDIO_MODE_INVALID;
AutoMutex lock(mHardwareLock);
mHardwareStatus = AUDIO_HW_GET_MIC_MUTE;
for (size_t i = 0; i < mAudioHwDevs.size(); i++) {
audio_hw_device_t *dev = mAudioHwDevs.valueAt(i)->hwDevice();
status_t result = dev->get_mic_mute(dev, &state);
if (result == NO_ERROR) {
mute = mute && state;
}
}
mHardwareStatus = AUDIO_HW_IDLE;
return mute;
}

If you know gdb, you might be able to use it to trace through the code. However, I don’t, so I’ll just add a few logging statements to see what’s going on.

Note that in temporary logging statements, I like to add my screen name so I can just grep for it instead looking through all the logs.

Then, I’ve compiled the changed library, pushed it to the device and restarted mediaserver by killing it to reload the code without having the reboot the device. (What process you need to kill will differs depending on the library you change.)

mmm frameworks/av/services/audioflinger/
adb root
adb remount
adb push out/target/product/i9082/system/lib/libaudioflinger.so /system/lib/
adb shell pkill mediaserver

Then I made another call and got the following logs.

The one we’re interested in is the “LEGACY Audio HW HAL”, because all other audio devices return -38, which is ENOSYS, meaning that the function is not implemented. So for some reason, the LEGACY Audio HW HAL returns -19 (ENODEV).

So why did it work in the previous version? Let’s check out Android 5.1.1’s code. This is easy because AndroidXRef has many versions of Android’s source code already indexed.

This is the code of this function in Android 5.1.1.

bool AudioFlinger::getMicMute() const
{
status_t ret = initCheck();
if (ret != NO_ERROR) {
return false;
}
    bool state = AUDIO_MODE_INVALID;
AutoMutex lock(mHardwareLock);
audio_hw_device_t *dev = mPrimaryHardwareDev->hwDevice();
mHardwareStatus = AUDIO_HW_GET_MIC_MUTE;
dev->get_mic_mute(dev, &state);
mHardwareStatus = AUDIO_HW_IDLE;
return state;
}

So apparently, the previous version didn’t check the return code at all. The Audio HAL has always been returning the wrong return code, but since the caller wasn’t checking it, it worked fine!

Fixing the bug

Now that we have found out a potential cause of the bug, time to fix it. Normally, it would be best to fix the Audio HAL to return the correct error code, but in this case, it’s not possible since the Audio HAL used is a proprietary blob extracted from the stock ROM with no source code. So we must patch AudioFlinger.cpp to ignore the return code.

However, we cannot always ignore it as other devices return -38 and we cannot ignore those because we’d be reading incorrect states if we do. In the end, I’ve decided to ignore the error code of the primary device only if the error code is -19.

Next, I’ve compiled and tested the new library on the device. It’s working now. Case closed.

Note that if you want to submit the patch to CyanogenMod or other projects, you will want to wrap it in #ifdef directives to prevent the patch from affecting other devices.