aaudio: improve error logging
Report when INVALID_STATE returned.
This was used to debug monkey test errors.
Cleanup some log messages.
Improve "dumpsys media.aaudio"
Bug: 64310586
Test: CTS nativemedia/aaudio
Change-Id: Ifbcac4794cda22cccbacff6352243c0ef4589c53
diff --git a/services/oboeservice/AAudioServiceEndpoint.cpp b/services/oboeservice/AAudioServiceEndpoint.cpp
index 6c345cd..81f1d1b 100644
--- a/services/oboeservice/AAudioServiceEndpoint.cpp
+++ b/services/oboeservice/AAudioServiceEndpoint.cpp
@@ -64,8 +64,9 @@
}
result << " Registered Streams:" << "\n";
+ result << AAudioServiceStreamShared::dumpHeader() << "\n";
for (sp<AAudioServiceStreamShared> sharedStream : mRegisteredStreams) {
- result << sharedStream->dump();
+ result << sharedStream->dump() << "\n";
}
if (isLocked) {
diff --git a/services/oboeservice/AAudioServiceEndpointPlay.cpp b/services/oboeservice/AAudioServiceEndpointPlay.cpp
index 20cc5b8..8b1cc9f 100644
--- a/services/oboeservice/AAudioServiceEndpointPlay.cpp
+++ b/services/oboeservice/AAudioServiceEndpointPlay.cpp
@@ -65,7 +65,6 @@
// Mix data from each application stream and write result to the shared MMAP stream.
void *AAudioServiceEndpointPlay::callbackLoop() {
- int32_t underflowCount = 0;
aaudio_result_t result = AAUDIO_OK;
int64_t timeoutNanos = getStreamInternal()->calculateReasonableTimeout();
@@ -90,14 +89,16 @@
float volume = 1.0; // to match legacy volume
bool underflowed = mMixer.mix(index, fifo, volume);
- underflowCount += underflowed ? 1 : 0;
- // TODO log underflows in each stream
// This timestamp represents the completion of data being read out of the
// client buffer. It is sent to the client and used in the timing model
// to decide when the client has room to write more data.
Timestamp timestamp(fifo->getReadCounter(), AudioClock::getNanoseconds());
clientStream->markTransferTime(timestamp);
+
+ if (underflowed) {
+ clientStream->incrementXRunCount();
+ }
}
index++;
}
@@ -116,8 +117,5 @@
}
}
- ALOGW_IF((underflowCount > 0),
- "AAudioServiceEndpointPlay(): callbackLoop() had %d underflows", underflowCount);
-
return NULL; // TODO review
}
diff --git a/services/oboeservice/AAudioServiceStreamBase.cpp b/services/oboeservice/AAudioServiceStreamBase.cpp
index 3fc5957..e5f916c 100644
--- a/services/oboeservice/AAudioServiceStreamBase.cpp
+++ b/services/oboeservice/AAudioServiceStreamBase.cpp
@@ -18,6 +18,8 @@
//#define LOG_NDEBUG 0
#include <utils/Log.h>
+#include <iomanip>
+#include <iostream>
#include <mutex>
#include "binding/IAAudioService.h"
@@ -54,16 +56,22 @@
"service stream still open, state = %d", mState);
}
+std::string AAudioServiceStreamBase::dumpHeader() {
+ return std::string(" T Handle UId Run State Format Burst Chan Capacity");
+}
+
std::string AAudioServiceStreamBase::dump() const {
std::stringstream result;
- result << " -------- handle = 0x" << std::hex << mHandle << std::dec << "\n";
- result << " state = " << AAudio_convertStreamStateToText(mState) << "\n";
- result << " format = " << mAudioFormat << "\n";
- result << " framesPerBurst = " << mFramesPerBurst << "\n";
- result << " channelCount = " << mSamplesPerFrame << "\n";
- result << " capacityFrames = " << mCapacityInFrames << "\n";
- result << " owner uid = " << mMmapClient.clientUid << "\n";
+ result << " 0x" << std::setfill('0') << std::setw(8) << std::hex << mHandle
+ << std::dec << std::setfill(' ') ;
+ result << std::setw(6) << mMmapClient.clientUid;
+ result << std::setw(4) << (isRunning() ? "yes" : " no");
+ result << std::setw(6) << mState;
+ result << std::setw(7) << mAudioFormat;
+ result << std::setw(6) << mFramesPerBurst;
+ result << std::setw(5) << mSamplesPerFrame;
+ result << std::setw(9) << mCapacityInFrames;
return result.str();
}
diff --git a/services/oboeservice/AAudioServiceStreamBase.h b/services/oboeservice/AAudioServiceStreamBase.h
index e91ea82..2f94614 100644
--- a/services/oboeservice/AAudioServiceStreamBase.h
+++ b/services/oboeservice/AAudioServiceStreamBase.h
@@ -54,7 +54,10 @@
ILLEGAL_THREAD_ID = 0
};
- std::string dump() const;
+ static std::string dumpHeader();
+
+ // does not include EOL
+ virtual std::string dump() const;
// -------------------------------------------------------------------
/**
diff --git a/services/oboeservice/AAudioServiceStreamShared.cpp b/services/oboeservice/AAudioServiceStreamShared.cpp
index 07c4faf..d648c6d 100644
--- a/services/oboeservice/AAudioServiceStreamShared.cpp
+++ b/services/oboeservice/AAudioServiceStreamShared.cpp
@@ -18,6 +18,8 @@
//#define LOG_NDEBUG 0
#include <utils/Log.h>
+#include <iomanip>
+#include <iostream>
#include <mutex>
#include <aaudio/AAudio.h>
@@ -42,9 +44,32 @@
AAudioServiceStreamShared::AAudioServiceStreamShared(AAudioService &audioService)
: mAudioService(audioService)
, mTimestampPositionOffset(0)
+ , mXRunCount(0)
{
}
+std::string AAudioServiceStreamShared::dumpHeader() {
+ std::stringstream result;
+ result << AAudioServiceStreamBase::dumpHeader();
+ result << " Write# Read# Avail XRuns";
+ return result.str();
+}
+
+std::string AAudioServiceStreamShared::dump() const {
+ std::stringstream result;
+ result << AAudioServiceStreamBase::dump();
+
+ auto fifo = mAudioDataQueue->getFifoBuffer();
+ int32_t readCounter = fifo->getReadCounter();
+ int32_t writeCounter = fifo->getWriteCounter();
+ result << std::setw(10) << writeCounter;
+ result << std::setw(10) << readCounter;
+ result << std::setw(8) << (writeCounter - readCounter);
+ result << std::setw(8) << getXRunCount();
+
+ return result.str();
+}
+
int32_t AAudioServiceStreamShared::calculateBufferCapacity(int32_t requestedCapacityFrames,
int32_t framesPerBurst) {
@@ -197,6 +222,7 @@
}
AAudioServiceEndpoint *endpoint = mServiceEndpoint;
if (endpoint == nullptr) {
+ ALOGE("AAudioServiceStreamShared::start() missing endpoint");
return AAUDIO_ERROR_INVALID_STATE;
}
// For output streams, this will add the stream to the mixer.
@@ -224,6 +250,7 @@
}
AAudioServiceEndpoint *endpoint = mServiceEndpoint;
if (endpoint == nullptr) {
+ ALOGE("AAudioServiceStreamShared::pause() missing endpoint");
return AAUDIO_ERROR_INVALID_STATE;
}
endpoint->getStreamInternal()->stopClient(mClientHandle);
@@ -241,6 +268,7 @@
}
AAudioServiceEndpoint *endpoint = mServiceEndpoint;
if (endpoint == nullptr) {
+ ALOGE("AAudioServiceStreamShared::stop() missing endpoint");
return AAUDIO_ERROR_INVALID_STATE;
}
endpoint->getStreamInternal()->stopClient(mClientHandle);
@@ -260,6 +288,7 @@
aaudio_result_t AAudioServiceStreamShared::flush() {
AAudioServiceEndpoint *endpoint = mServiceEndpoint;
if (endpoint == nullptr) {
+ ALOGE("AAudioServiceStreamShared::flush() missing endpoint");
return AAUDIO_ERROR_INVALID_STATE;
}
if (mState != AAUDIO_STREAM_STATE_PAUSED) {
diff --git a/services/oboeservice/AAudioServiceStreamShared.h b/services/oboeservice/AAudioServiceStreamShared.h
index 8caccda..36a56b8 100644
--- a/services/oboeservice/AAudioServiceStreamShared.h
+++ b/services/oboeservice/AAudioServiceStreamShared.h
@@ -46,6 +46,10 @@
AAudioServiceStreamShared(android::AAudioService &aAudioService);
virtual ~AAudioServiceStreamShared() = default;
+ static std::string dumpHeader();
+
+ std::string dump() const override;
+
aaudio_result_t open(const aaudio::AAudioStreamRequest &request,
aaudio::AAudioStreamConfiguration &configurationOutput) override;
@@ -91,6 +95,14 @@
mTimestampPositionOffset.store(deltaFrames);
}
+ void incrementXRunCount() {
+ mXRunCount++;
+ }
+
+ int32_t getXRunCount() const {
+ return mXRunCount.load();
+ }
+
protected:
aaudio_result_t getDownDataDescription(AudioEndpointParcelable &parcelable) override;
@@ -114,6 +126,7 @@
SharedRingBuffer *mAudioDataQueue = nullptr;
std::atomic<int64_t> mTimestampPositionOffset;
+ std::atomic<int32_t> mXRunCount;
};
} /* namespace aaudio */
diff --git a/services/oboeservice/AAudioThread.cpp b/services/oboeservice/AAudioThread.cpp
index ebb50f8..c6fb57d 100644
--- a/services/oboeservice/AAudioThread.cpp
+++ b/services/oboeservice/AAudioThread.cpp
@@ -53,7 +53,7 @@
aaudio_result_t AAudioThread::start(Runnable *runnable) {
if (mHasThread) {
- ALOGE("AAudioThread::start() - mHasThread.load() already true");
+ ALOGE("AAudioThread::start() - mHasThread already true");
return AAUDIO_ERROR_INVALID_STATE;
}
// mRunnable will be read by the new thread when it starts.
@@ -71,6 +71,7 @@
aaudio_result_t AAudioThread::stop() {
if (!mHasThread) {
+ ALOGE("AAudioThread::stop() but no thread running");
return AAUDIO_ERROR_INVALID_STATE;
}
int err = pthread_join(mThread, nullptr);