audiopolicy: Improve logging for device connection cases
Add meaningful profile names, while opening input and output profiles
on device connection.
Add logs in openDirectOutput method to get info in case existing
output is closed because of direct track repriorization, profiles are
found or not.
Add logs in setDeviceConnectionState for input device as well.
Add successful connection logs once setDeviceConnectionState completes.
Flag: EXEMPT bugfix
Bug: 345692843
Test: connect an external device, enable verbose logs, check logs for
profile opening
Change-Id: I7e5aa57e7a71bbfecf315943419b06bb8460e857
Merged-In: I7e5aa57e7a71bbfecf315943419b06bb8460e857
diff --git a/services/audiopolicy/managerdefault/AudioPolicyManager.cpp b/services/audiopolicy/managerdefault/AudioPolicyManager.cpp
index cc44299..dffe259 100644
--- a/services/audiopolicy/managerdefault/AudioPolicyManager.cpp
+++ b/services/audiopolicy/managerdefault/AudioPolicyManager.cpp
@@ -374,6 +374,7 @@
checkLeBroadcastRoutes(wasLeUnicastActive, nullptr, 0);
mpClientInterface->onAudioPortListUpdate();
+ ALOGV("%s() completed for device: %s", __func__, device->toString().c_str());
return NO_ERROR;
} // end if is output device
@@ -389,6 +390,8 @@
return INVALID_OPERATION;
}
+ ALOGV("%s() connecting device %s", __func__, device->toString().c_str());
+
if (mAvailableInputDevices.add(device) < 0) {
return NO_MEMORY;
}
@@ -461,6 +464,7 @@
}
mpClientInterface->onAudioPortListUpdate();
+ ALOGV("%s() completed for device: %s", __func__, device->toString().c_str());
return NO_ERROR;
} // end if is input device
@@ -1516,7 +1520,7 @@
(config->channel_mask == desc->getChannelMask()) &&
(session == desc->mDirectClientSession)) {
desc->mDirectOpenCount++;
- ALOGV("%s reusing direct output %d for session %d", __func__,
+ ALOGI("%s reusing direct output %d for session %d", __func__,
mOutputs.keyAt(i), session);
*output = mOutputs.keyAt(i);
return NO_ERROR;
@@ -1526,17 +1530,23 @@
if (!profile->canOpenNewIo()) {
if (!com::android::media::audioserver::direct_track_reprioritization()) {
+ ALOGW("%s profile %s can't open new output maxOpenCount reached", __func__,
+ profile->getName().c_str());
return NAME_NOT_FOUND;
} else if ((profile->getFlags() & AUDIO_OUTPUT_FLAG_MMAP_NOIRQ) != 0) {
// MMAP gracefully handles lack of an exclusive track resource by mixing
// above the audio framework. For AAudio to know that the limit is reached,
// return an error.
+ ALOGW("%s profile %s can't open new mmap output maxOpenCount reached", __func__,
+ profile->getName().c_str());
return NAME_NOT_FOUND;
} else {
// Close outputs on this profile, if available, to free resources for this request
for (int i = 0; i < mOutputs.size() && !profile->canOpenNewIo(); i++) {
const auto desc = mOutputs.valueAt(i);
if (desc->mProfile == profile) {
+ ALOGV("%s closeOutput %d to prioritize session %d on profile %s", __func__,
+ desc->mIoHandle, session, profile->getName().c_str());
closeOutput(desc->mIoHandle);
}
}
@@ -1545,6 +1555,8 @@
// Unable to close streams to find free resources for this request
if (!profile->canOpenNewIo()) {
+ ALOGW("%s profile %s can't open new output maxOpenCount reached", __func__,
+ profile->getName().c_str());
return NAME_NOT_FOUND;
}
@@ -3276,8 +3288,8 @@
ALOGW("%s: no group for stream %s, bailing out", __func__, toString(stream).c_str());
return NO_ERROR;
}
- ALOGV("%s: stream %s attributes=%s", __func__,
- toString(stream).c_str(), toString(attributes).c_str());
+ ALOGV("%s: stream %s attributes=%s, index %d , device 0x%X", __func__,
+ toString(stream).c_str(), toString(attributes).c_str(), index, device);
return setVolumeIndexForAttributes(attributes, index, device);
}
@@ -3455,8 +3467,8 @@
bool hasVoice = hasVoiceStream(volumeCurves.getStreamTypes());
if (((index < volumeCurves.getVolumeIndexMin()) && !(hasVoice && index == 0)) ||
(index > volumeCurves.getVolumeIndexMax())) {
- ALOGD("%s: wrong index %d min=%d max=%d", __FUNCTION__, index,
- volumeCurves.getVolumeIndexMin(), volumeCurves.getVolumeIndexMax());
+ ALOGE("%s: wrong index %d min=%d max=%d, device 0x%X", __FUNCTION__, index,
+ volumeCurves.getVolumeIndexMin(), volumeCurves.getVolumeIndexMax(), device);
return BAD_VALUE;
}
if (!audio_is_output_device(device)) {
@@ -6471,9 +6483,9 @@
(audio_input_flags_t) inProfile->getFlags(),
&input);
if (status != NO_ERROR) {
- ALOGW("Cannot open input stream for device %s on hw module %s",
- availProfileDevices.toString().c_str(),
- hwModule->getName());
+ ALOGW("%s: Cannot open input stream for device %s for profile %s on hw module %s",
+ __func__, availProfileDevices.toString().c_str(),
+ inProfile->getTagName().c_str(), hwModule->getName());
continue;
}
for (const auto &device : availProfileDevices) {
@@ -6581,8 +6593,8 @@
sp<IOProfile> profile = hwModule->getOutputProfiles()[j];
if (profile->supportsDevice(device)) {
profiles.add(profile);
- ALOGV("checkOutputsForDevice(): adding profile %zu from module %s",
- j, hwModule->getName());
+ ALOGV("%s(): adding profile %s from module %s",
+ __func__, profile->getTagName().c_str(), hwModule->getName());
}
}
}
@@ -6680,9 +6692,8 @@
if (!profile->supportsDevice(device)) {
continue;
}
- ALOGV("checkOutputsForDevice(): "
- "clearing direct output profile %zu on module %s",
- j, hwModule->getName());
+ ALOGV("%s(): clearing direct output profile %s on module %s",
+ __func__, profile->getTagName().c_str(), hwModule->getName());
profile->clearAudioProfiles();
if (!profile->hasDynamicAudioProfile()) {
continue;
@@ -6737,8 +6748,8 @@
if (profile->supportsDevice(device)) {
profiles.add(profile);
- ALOGV("checkInputsForDevice(): adding profile %zu from module %s",
- profile_index, hwModule->getName());
+ ALOGV("%s : adding profile %s from module %s", __func__,
+ profile->getTagName().c_str(), hwModule->getName());
}
}
}
@@ -6776,13 +6787,14 @@
continue;
}
if (!profile->canOpenNewIo()) {
- ALOGW("Max Input number %u already opened for this profile %s",
- profile->maxOpenCount, profile->getTagName().c_str());
+ ALOGW("%s Max Input number %u already opened for this profile %s",
+ __func__, profile->maxOpenCount, profile->getTagName().c_str());
continue;
}
desc = new AudioInputDescriptor(profile, mpClientInterface);
audio_io_handle_t input = AUDIO_IO_HANDLE_NONE;
+ ALOGV("%s opening input for profile %s", __func__, profile->getTagName().c_str());
status = desc->open(nullptr, device, AUDIO_SOURCE_MIC,
(audio_input_flags_t) profile->getFlags(), &input);
@@ -6795,7 +6807,8 @@
}
updateAudioProfiles(device, input, profile);
if (!profile->hasValidAudioProfile()) {
- ALOGW("checkInputsForDevice() direct input missing param");
+ ALOGW("%s direct input missing param for profile %s", __func__,
+ profile->getTagName().c_str());
desc->close();
input = AUDIO_IO_HANDLE_NONE;
}
@@ -6806,18 +6819,20 @@
} // endif input != 0
if (input == AUDIO_IO_HANDLE_NONE) {
- ALOGW("%s could not open input for device %s", __func__,
- device->toString().c_str());
+ ALOGW("%s could not open input for device %s on profile %s", __func__,
+ device->toString().c_str(), profile->getTagName().c_str());
profiles.removeAt(profile_index);
profile_index--;
} else {
if (audio_device_is_digital(device->type())) {
device->importAudioPortAndPickAudioProfile(profile);
}
- ALOGV("checkInputsForDevice(): adding input %d", input);
+ ALOGV("%s: adding input %d for profile %s", __func__,
+ input, profile->getTagName().c_str());
if (checkCloseInput(desc)) {
- ALOGV("%s closing input %d", __func__, input);
+ ALOGV("%s: closing input %d for profile %s", __func__,
+ input, profile->getTagName().c_str());
closeInput(input);
}
}
@@ -6836,8 +6851,8 @@
profile_index++) {
sp<IOProfile> profile = hwModule->getInputProfiles()[profile_index];
if (profile->supportsDevice(device)) {
- ALOGV("checkInputsForDevice(): clearing direct input profile %zu on module %s",
- profile_index, hwModule->getName());
+ ALOGV("%s: clearing direct input profile %s on module %s", __func__,
+ profile->getTagName().c_str(), hwModule->getName());
profile->clearAudioProfiles();
}
}