aaudio: cleanup logs and add counters to dumpsys
Counters will give us some history for AAudio.
Removed some unneeded logs.
Added log to help debug intermittent volume problem.
Bug: 64310586
Test: adb shell logcat
Test: adb shell dumpsys media.aaudio
Change-Id: I012361bb4d0d0bfdedfe5ceef856b59282c8d3f0
diff --git a/media/libaaudio/src/client/AudioStreamInternal.cpp b/media/libaaudio/src/client/AudioStreamInternal.cpp
index ff138aa..0bdfeac 100644
--- a/media/libaaudio/src/client/AudioStreamInternal.cpp
+++ b/media/libaaudio/src/client/AudioStreamInternal.cpp
@@ -501,9 +501,9 @@
ALOGW("%s - AAUDIO_SERVICE_EVENT_DISCONNECTED - FIFO cleared", __func__);
break;
case AAUDIO_SERVICE_EVENT_VOLUME:
+ ALOGD("%s - AAUDIO_SERVICE_EVENT_VOLUME %lf", __func__, message->event.dataDouble);
mStreamVolume = (float)message->event.dataDouble;
doSetVolume();
- ALOGD("%s - AAUDIO_SERVICE_EVENT_VOLUME %lf", __func__, message->event.dataDouble);
break;
case AAUDIO_SERVICE_EVENT_XRUN:
mXRunCount = static_cast<int32_t>(message->event.dataLong);
diff --git a/media/libaaudio/src/client/AudioStreamInternalPlay.cpp b/media/libaaudio/src/client/AudioStreamInternalPlay.cpp
index 0c3b1fa..795ba2c 100644
--- a/media/libaaudio/src/client/AudioStreamInternalPlay.cpp
+++ b/media/libaaudio/src/client/AudioStreamInternalPlay.cpp
@@ -117,7 +117,7 @@
// Still haven't got any timestamps from server.
// Keep waiting until we get some valid timestamps then start writing to the
// current buffer position.
- ALOGD("%s() wait for valid timestamps", __func__);
+ ALOGV("%s() wait for valid timestamps", __func__);
// Sleep very briefly and hope we get a timestamp soon.
*wakeTimePtr = currentNanoTime + (2000 * AAUDIO_NANOS_PER_MICROSECOND);
ATRACE_END();
@@ -310,6 +310,9 @@
//------------------------------------------------------------------------------
// Implementation of PlayerBase
status_t AudioStreamInternalPlay::doSetVolume() {
- mVolumeRamp.setTarget(mStreamVolume * getDuckAndMuteVolume());
+ float combinedVolume = mStreamVolume * getDuckAndMuteVolume();
+ ALOGD("%s() mStreamVolume * duckAndMuteVolume = %f * %f = %f",
+ __func__, mStreamVolume, getDuckAndMuteVolume(), combinedVolume);
+ mVolumeRamp.setTarget(combinedVolume);
return android::NO_ERROR;
}
diff --git a/media/libaaudio/src/core/AudioStream.cpp b/media/libaaudio/src/core/AudioStream.cpp
index acb82c8..358021b 100644
--- a/media/libaaudio/src/core/AudioStream.cpp
+++ b/media/libaaudio/src/core/AudioStream.cpp
@@ -428,6 +428,12 @@
}
#endif
+void AudioStream::setDuckAndMuteVolume(float duckAndMuteVolume) {
+ ALOGD("%s() to %f", __func__, duckAndMuteVolume);
+ mDuckAndMuteVolume = duckAndMuteVolume;
+ doSetVolume(); // apply this change
+}
+
AudioStream::MyPlayerBase::MyPlayerBase(AudioStream *parent) : mParent(parent) {
}
@@ -449,7 +455,6 @@
}
}
-
void AudioStream::MyPlayerBase::destroy() {
unregisterWithAudioManager();
}
diff --git a/media/libaaudio/src/core/AudioStream.h b/media/libaaudio/src/core/AudioStream.h
index c46bdc5..31b895c 100644
--- a/media/libaaudio/src/core/AudioStream.h
+++ b/media/libaaudio/src/core/AudioStream.h
@@ -328,10 +328,7 @@
}
// This is used by the AudioManager to duck and mute the stream when changing audio focus.
- void setDuckAndMuteVolume(float duckAndMuteVolume) {
- mDuckAndMuteVolume = duckAndMuteVolume;
- doSetVolume(); // apply this change
- }
+ void setDuckAndMuteVolume(float duckAndMuteVolume);
float getDuckAndMuteVolume() const {
return mDuckAndMuteVolume;
diff --git a/media/libaaudio/src/core/AudioStreamBuilder.cpp b/media/libaaudio/src/core/AudioStreamBuilder.cpp
index 293a6a8..3a7a578 100644
--- a/media/libaaudio/src/core/AudioStreamBuilder.cpp
+++ b/media/libaaudio/src/core/AudioStreamBuilder.cpp
@@ -87,7 +87,7 @@
break;
default:
- ALOGE("bad direction = %d", direction);
+ ALOGE("%s() bad direction = %d", __func__, direction);
result = AAUDIO_ERROR_ILLEGAL_ARGUMENT;
}
return result;
@@ -99,7 +99,7 @@
aaudio_result_t AudioStreamBuilder::build(AudioStream** streamPtr) {
AudioStream *audioStream = nullptr;
if (streamPtr == nullptr) {
- ALOGE("build() streamPtr is null");
+ ALOGE("%s() streamPtr is null", __func__);
return AAUDIO_ERROR_NULL;
}
*streamPtr = nullptr;
@@ -124,13 +124,11 @@
if (mapExclusivePolicy == AAUDIO_UNSPECIFIED) {
mapExclusivePolicy = AAUDIO_MMAP_EXCLUSIVE_POLICY_DEFAULT;
}
- ALOGD("mmapPolicy = %d, mapExclusivePolicy = %d",
- mmapPolicy, mapExclusivePolicy);
aaudio_sharing_mode_t sharingMode = getSharingMode();
if ((sharingMode == AAUDIO_SHARING_MODE_EXCLUSIVE)
&& (mapExclusivePolicy == AAUDIO_POLICY_NEVER)) {
- ALOGW("EXCLUSIVE sharing mode not supported. Use SHARED.");
+ ALOGD("%s() EXCLUSIVE sharing mode not supported. Use SHARED.", __func__);
sharingMode = AAUDIO_SHARING_MODE_SHARED;
setSharingMode(sharingMode);
}
@@ -141,13 +139,14 @@
// TODO Support other performance settings in MMAP mode.
// Disable MMAP if low latency not requested.
if (getPerformanceMode() != AAUDIO_PERFORMANCE_MODE_LOW_LATENCY) {
- ALOGD("build() MMAP not available because AAUDIO_PERFORMANCE_MODE_LOW_LATENCY not used.");
+ ALOGD("%s() MMAP not available because AAUDIO_PERFORMANCE_MODE_LOW_LATENCY not used.",
+ __func__);
allowMMap = false;
}
// SessionID and Effects are only supported in Legacy mode.
if (getSessionId() != AAUDIO_SESSION_ID_NONE) {
- ALOGD("build() MMAP not available because sessionId used.");
+ ALOGD("%s() MMAP not available because sessionId used.", __func__);
allowMMap = false;
}
@@ -163,7 +162,7 @@
audioStream = nullptr;
if (isMMap && allowLegacy) {
- ALOGD("build() MMAP stream did not open so try Legacy path");
+ ALOGV("%s() MMAP stream did not open so try Legacy path", __func__);
// If MMAP stream failed to open then TRY using a legacy stream.
result = builder_createStream(getDirection(), sharingMode,
false, &audioStream);
diff --git a/media/libaaudio/src/fifo/FifoBuffer.cpp b/media/libaaudio/src/fifo/FifoBuffer.cpp
index e6e7c8e..9b9744e 100644
--- a/media/libaaudio/src/fifo/FifoBuffer.cpp
+++ b/media/libaaudio/src/fifo/FifoBuffer.cpp
@@ -43,7 +43,7 @@
int32_t bytesPerBuffer = bytesPerFrame * capacityInFrames;
mStorage = new uint8_t[bytesPerBuffer];
mStorageOwned = true;
- ALOGD("capacityInFrames = %d, bytesPerFrame = %d",
+ ALOGV("capacityInFrames = %d, bytesPerFrame = %d",
capacityInFrames, bytesPerFrame);
}
diff --git a/services/oboeservice/AAudioClientTracker.cpp b/services/oboeservice/AAudioClientTracker.cpp
index 549a4e9..7264a9b 100644
--- a/services/oboeservice/AAudioClientTracker.cpp
+++ b/services/oboeservice/AAudioClientTracker.cpp
@@ -21,6 +21,8 @@
#include <assert.h>
#include <binder/IPCThreadState.h>
+#include <iomanip>
+#include <iostream>
#include <map>
#include <mutex>
#include <utils/Singleton.h>
@@ -39,7 +41,6 @@
: Singleton<AAudioClientTracker>() {
}
-
std::string AAudioClientTracker::dump() const {
std::stringstream result;
const bool isLocked = AAudio_tryUntilTrue(
@@ -198,7 +199,9 @@
result << " client: pid = " << mProcessId << " has " << mStreams.size() << " streams\n";
for (const auto& serviceStream : mStreams) {
- result << " stream: 0x" << std::hex << serviceStream->getHandle() << std::dec << "\n";
+ result << " stream: 0x" << std::setfill('0') << std::setw(8) << std::hex
+ << serviceStream->getHandle()
+ << std::dec << std::setfill(' ') << "\n";
}
if (isLocked) {
diff --git a/services/oboeservice/AAudioEndpointManager.cpp b/services/oboeservice/AAudioEndpointManager.cpp
index 11fd9f6..ab8f4ed 100644
--- a/services/oboeservice/AAudioEndpointManager.cpp
+++ b/services/oboeservice/AAudioEndpointManager.cpp
@@ -67,11 +67,17 @@
result << "Exclusive MMAP Endpoints: " << mExclusiveStreams.size() << "\n";
index = 0;
- for (const auto &output : mExclusiveStreams) {
+ for (const auto &stream : mExclusiveStreams) {
result << " #" << index++ << ":";
- result << output->dump() << "\n";
+ result << stream->dump() << "\n";
}
+ result << " ExclusiveSearchCount: " << mExclusiveSearchCount << "\n";
+ result << " ExclusiveFoundCount: " << mExclusiveFoundCount << "\n";
+ result << " ExclusiveOpenCount: " << mExclusiveOpenCount << "\n";
+ result << " ExclusiveCloseCount: " << mExclusiveCloseCount << "\n";
+ result << "\n";
+
if (isExclusiveLocked) {
mExclusiveLock.unlock();
}
@@ -79,11 +85,17 @@
result << "Shared Endpoints: " << mSharedStreams.size() << "\n";
index = 0;
- for (const auto &input : mSharedStreams) {
+ for (const auto &stream : mSharedStreams) {
result << " #" << index++ << ":";
- result << input->dump() << "\n";
+ result << stream->dump() << "\n";
}
+ result << " SharedSearchCount: " << mSharedSearchCount << "\n";
+ result << " SharedFoundCount: " << mSharedFoundCount << "\n";
+ result << " SharedOpenCount: " << mSharedOpenCount << "\n";
+ result << " SharedCloseCount: " << mSharedCloseCount << "\n";
+ result << "\n";
+
if (isSharedLocked) {
mSharedLock.unlock();
}
@@ -95,8 +107,10 @@
sp<AAudioServiceEndpoint> AAudioEndpointManager::findExclusiveEndpoint_l(
const AAudioStreamConfiguration &configuration) {
sp<AAudioServiceEndpoint> endpoint;
+ mExclusiveSearchCount++;
for (const auto ep : mExclusiveStreams) {
if (ep->matches(configuration)) {
+ mExclusiveFoundCount++;
endpoint = ep;
break;
}
@@ -111,8 +125,10 @@
sp<AAudioServiceEndpointShared> AAudioEndpointManager::findSharedEndpoint_l(
const AAudioStreamConfiguration &configuration) {
sp<AAudioServiceEndpointShared> endpoint;
+ mSharedSearchCount++;
for (const auto ep : mSharedStreams) {
if (ep->matches(configuration)) {
+ mSharedFoundCount++;
endpoint = ep;
break;
}
@@ -146,21 +162,21 @@
// If we find an existing one then this one cannot be exclusive.
if (endpoint.get() != nullptr) {
- ALOGE("openExclusiveEndpoint() already in use");
+ ALOGW("openExclusiveEndpoint() already in use");
// Already open so do not allow a second stream.
return nullptr;
} else {
sp<AAudioServiceEndpointMMAP> endpointMMap = new AAudioServiceEndpointMMAP();
- ALOGD("openExclusiveEndpoint(), no match so try to open MMAP %p for dev %d",
+ ALOGV("openExclusiveEndpoint(), no match so try to open MMAP %p for dev %d",
endpointMMap.get(), configuration.getDeviceId());
endpoint = endpointMMap;
aaudio_result_t result = endpoint->open(request);
if (result != AAUDIO_OK) {
- ALOGE("openExclusiveEndpoint(), open failed");
endpoint.clear();
} else {
mExclusiveStreams.push_back(endpointMMap);
+ mExclusiveOpenCount++;
}
}
@@ -201,13 +217,13 @@
if (endpoint.get() != nullptr) {
aaudio_result_t result = endpoint->open(request);
if (result != AAUDIO_OK) {
- ALOGE("%s(), open failed", __func__);
endpoint.clear();
} else {
mSharedStreams.push_back(endpoint);
+ mSharedOpenCount++;
}
}
- ALOGD("%s(), created endpoint %p, requested device = %d, dir = %d",
+ ALOGV("%s(), created endpoint %p, requested device = %d, dir = %d",
__func__, endpoint.get(), configuration.getDeviceId(), (int)direction);
IPCThreadState::self()->restoreCallingIdentity(token);
}
@@ -244,7 +260,8 @@
mExclusiveStreams.end());
serviceEndpoint->close();
- ALOGD("%s() %p for device %d",
+ mExclusiveCloseCount++;
+ ALOGV("%s() %p for device %d",
__func__, serviceEndpoint.get(), serviceEndpoint->getDeviceId());
}
}
@@ -266,7 +283,8 @@
mSharedStreams.end());
serviceEndpoint->close();
- ALOGD("%s() %p for device %d",
+ mSharedCloseCount++;
+ ALOGV("%s() %p for device %d",
__func__, serviceEndpoint.get(), serviceEndpoint->getDeviceId());
}
}
diff --git a/services/oboeservice/AAudioEndpointManager.h b/services/oboeservice/AAudioEndpointManager.h
index f6aeb5a..193bdee 100644
--- a/services/oboeservice/AAudioEndpointManager.h
+++ b/services/oboeservice/AAudioEndpointManager.h
@@ -87,8 +87,17 @@
mutable std::mutex mExclusiveLock;
std::vector<android::sp<AAudioServiceEndpointMMAP>> mExclusiveStreams;
+ // Modified under a lock.
+ int32_t mExclusiveSearchCount = 0; // number of times we SEARCHED for an exclusive endpoint
+ int32_t mExclusiveFoundCount = 0; // number of times we FOUND an exclusive endpoint
+ int32_t mExclusiveOpenCount = 0; // number of times we OPENED an exclusive endpoint
+ int32_t mExclusiveCloseCount = 0; // number of times we CLOSED an exclusive endpoint
+ // Same as above but for SHARED endpoints.
+ int32_t mSharedSearchCount = 0;
+ int32_t mSharedFoundCount = 0;
+ int32_t mSharedOpenCount = 0;
+ int32_t mSharedCloseCount = 0;
};
-
} /* namespace aaudio */
#endif //AAUDIO_AAUDIO_ENDPOINT_MANAGER_H
diff --git a/services/oboeservice/AAudioServiceEndpointMMAP.cpp b/services/oboeservice/AAudioServiceEndpointMMAP.cpp
index 713ce60..5f1de76 100644
--- a/services/oboeservice/AAudioServiceEndpointMMAP.cpp
+++ b/services/oboeservice/AAudioServiceEndpointMMAP.cpp
@@ -84,6 +84,7 @@
const audio_content_type_t contentType =
AAudioConvert_contentTypeToInternal(getContentType());
+ // Usage only used for OUTPUT
const audio_usage_t usage = (direction == AAUDIO_DIRECTION_OUTPUT)
? AAudioConvert_usageToInternal(getUsage())
: AUDIO_USAGE_UNKNOWN;
diff --git a/services/oboeservice/AAudioServiceEndpointShared.cpp b/services/oboeservice/AAudioServiceEndpointShared.cpp
index f08a52f..63b9983 100644
--- a/services/oboeservice/AAudioServiceEndpointShared.cpp
+++ b/services/oboeservice/AAudioServiceEndpointShared.cpp
@@ -78,7 +78,6 @@
setSamplesPerFrame(mStreamInternal->getSamplesPerFrame());
setDeviceId(mStreamInternal->getDeviceId());
setSessionId(mStreamInternal->getSessionId());
- ALOGD("open() deviceId = %d, sessionId = %d", getDeviceId(), getSessionId());
mFramesPerBurst = mStreamInternal->getFramesPerBurst();
return result;
diff --git a/services/oboeservice/AAudioServiceStreamShared.cpp b/services/oboeservice/AAudioServiceStreamShared.cpp
index 75d88cf..864a008 100644
--- a/services/oboeservice/AAudioServiceStreamShared.cpp
+++ b/services/oboeservice/AAudioServiceStreamShared.cpp
@@ -122,19 +122,18 @@
aaudio_result_t result = AAudioServiceStreamBase::open(request, AAUDIO_SHARING_MODE_SHARED);
if (result != AAUDIO_OK) {
- ALOGE("open() returned %d", result);
+ ALOGE("%s() returned %d", __func__, result);
return result;
}
const AAudioStreamConfiguration &configurationInput = request.getConstantConfiguration();
-
// Is the request compatible with the shared endpoint?
setFormat(configurationInput.getFormat());
if (getFormat() == AAUDIO_FORMAT_UNSPECIFIED) {
setFormat(AAUDIO_FORMAT_PCM_FLOAT);
} else if (getFormat() != AAUDIO_FORMAT_PCM_FLOAT) {
- ALOGE("open() mAudioFormat = %d, need FLOAT", getFormat());
+ ALOGD("%s() mAudioFormat = %d, need FLOAT", __func__, getFormat());
result = AAUDIO_ERROR_INVALID_FORMAT;
goto error;
}
@@ -143,8 +142,8 @@
if (getSampleRate() == AAUDIO_UNSPECIFIED) {
setSampleRate(mServiceEndpoint->getSampleRate());
} else if (getSampleRate() != mServiceEndpoint->getSampleRate()) {
- ALOGE("open() mSampleRate = %d, need %d",
- getSampleRate(), mServiceEndpoint->getSampleRate());
+ ALOGD("%s() mSampleRate = %d, need %d",
+ __func__, getSampleRate(), mServiceEndpoint->getSampleRate());
result = AAUDIO_ERROR_INVALID_RATE;
goto error;
}
@@ -153,8 +152,8 @@
if (getSamplesPerFrame() == AAUDIO_UNSPECIFIED) {
setSamplesPerFrame(mServiceEndpoint->getSamplesPerFrame());
} else if (getSamplesPerFrame() != mServiceEndpoint->getSamplesPerFrame()) {
- ALOGE("open() mSamplesPerFrame = %d, need %d",
- getSamplesPerFrame(), mServiceEndpoint->getSamplesPerFrame());
+ ALOGD("%s() mSamplesPerFrame = %d, need %d",
+ __func__, getSamplesPerFrame(), mServiceEndpoint->getSamplesPerFrame());
result = AAUDIO_ERROR_OUT_OF_RANGE;
goto error;
}
@@ -173,16 +172,13 @@
mAudioDataQueue = new SharedRingBuffer();
result = mAudioDataQueue->allocate(calculateBytesPerFrame(), getBufferCapacity());
if (result != AAUDIO_OK) {
- ALOGE("open() could not allocate FIFO with %d frames",
- getBufferCapacity());
+ ALOGE("%s() could not allocate FIFO with %d frames",
+ __func__, getBufferCapacity());
result = AAUDIO_ERROR_NO_MEMORY;
goto error;
}
}
- ALOGD("open() actual rate = %d, channels = %d, deviceId = %d",
- getSampleRate(), getSamplesPerFrame(), mServiceEndpoint->getDeviceId());
-
result = mServiceEndpoint->registerStream(keep);
if (result != AAUDIO_OK) {
goto error;
@@ -217,7 +213,7 @@
{
std::lock_guard<std::mutex> lock(mAudioDataQueueLock);
if (mAudioDataQueue == nullptr) {
- ALOGE("getAudioDataDescription(): mUpMessageQueue null! - stream not open");
+ ALOGE("%s(): mUpMessageQueue null! - stream not open", __func__);
return AAUDIO_ERROR_NULL;
}
// Gather information on the data queue.
@@ -255,8 +251,8 @@
int64_t offset = mTimestampPositionOffset.load();
// TODO, do not go below starting value
position -= offset; // Offset from shared MMAP stream
- ALOGV("getHardwareTimestamp() %8lld = %8lld - %8lld",
- (long long) position, (long long) (position + offset), (long long) offset);
+ ALOGV("%s() %8lld = %8lld - %8lld",
+ __func__, (long long) position, (long long) (position + offset), (long long) offset);
}
*positionFrames = position;
return result;