Add CAudioTimedLocker to handle mutex lock timeout

- Revise __dumpStat() to show periodical stream writing status.
- Add overflow callback on playback stream for the future debugging purpose.

[Version] 0.5.55
[Issue Type] New feature

Change-Id: I76cdd0bb03c8de3dac067736cf5e23a44e6f4c4c

diff --git a/include/CAudioIO.h b/include/CAudioIO.h
index c1073aa..0e14ade 100644 (file)
--- a/include/CAudioIO.h
+++ b/include/CAudioIO.h
@@ -120,7 +120,7 @@ namespace tizen_media_audio {
         CAudioInfo::EAudioIOState mState;
         CAudioInfo::EAudioIOState mStatePrev;
         bool                  mByPolicy;
-        std::mutex            mMutex;
+        std::timed_mutex      mMutex;
         std::mutex            mCondMutex;
         std::condition_variable mCond;
 

diff --git a/include/CAudioIODef.h b/include/CAudioIODef.h
index a739eca..1fffbb7 100644 (file)
--- a/include/CAudioIODef.h
+++ b/include/CAudioIODef.h
@@ -32,6 +32,7 @@
 #include "CAudioIO.h"
 #include "CAudioInput.h"
 #include "CAudioOutput.h"
+#include "CAudioLocker.h"
 
 //#define _AUDIO_IO_DEBUG_TIMING_
 

diff --git a/include/CAudioLocker.h b/include/CAudioLocker.h
new file mode 100644 (file)
index 0000000..fd19d81
--- /dev/null
+++ b/include/CAudioLocker.h
@@ -0,0 +1,59 @@
+/*
+ * Copyright (c) 2023 Samsung Electronics Co., Ltd All Rights Reserved
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+*/
+
+#include <chrono>
+#include <thread>
+#include <mutex>
+#include <sys/types.h>
+
+#ifndef __TIZEN_MEDIA_AUDIO_IO_CAUDIOLOCKER_H__
+#define __TIZEN_MEDIA_AUDIO_IO_CAUDIOLOCKER_H__
+
+#ifdef __cplusplus
+
+using namespace std::literals::chrono_literals;
+
+namespace tizen_media_audio {
+
+    constexpr auto mutex_timeout_s = 4s;
+
+    class CAudioTimedLocker {
+    public:
+        explicit CAudioTimedLocker(const std::string& tag);
+        CAudioTimedLocker(const std::string& tag, std::timed_mutex& m,
+                        std::chrono::seconds timeout = mutex_timeout_s);
+        virtual ~CAudioTimedLocker();
+
+        void lock(std::timed_mutex& m,
+                std::chrono::seconds timeout = mutex_timeout_s);
+        void unlock();
+
+    private:
+        void updateHolder(const std::string& tag, pid_t tid);
+
+        std::unique_lock<std::timed_mutex> _lock;
+        std::string _tag;
+
+        static std::string _holder;
+        static pid_t _tid;
+
+
+    };
+
+} /* namespace tizen_media_audio */
+
+#endif
+#endif /* __TIZEN_MEDIA_AUDIO_IO_CAUDIOLOCKER_H__ */
\ No newline at end of file

diff --git a/include/CAudioOutput.h b/include/CAudioOutput.h
index b7a5e81..ff38579 100644 (file)
--- a/include/CAudioOutput.h
+++ b/include/CAudioOutput.h
@@ -62,6 +62,7 @@ namespace tizen_media_audio {
         bool __IsInit() noexcept;
         bool __IsReady() noexcept;
         void __dumpStat() noexcept;
+        void __dumpStat(size_t length) noexcept;
 
         bool __mIsUsedSyncWrite;
         bool __mIsInit;

diff --git a/include/CPulseAudioClient.h b/include/CPulseAudioClient.h
index 80bfb70..b41acc6 100644 (file)
--- a/include/CPulseAudioClient.h
+++ b/include/CPulseAudioClient.h
@@ -111,6 +111,7 @@ namespace tizen_media_audio {
         static void __streamLatencyUpdateCb(pa_stream* s, void* user_data);
         static void __streamStartedCb(pa_stream* s, void* user_data);
         static void __streamUnderflowCb(pa_stream* s, void* user_data);
+        static void __streamOverflowCb(pa_stream* s, void* user_data);
         static void __streamEventCb(pa_stream* s, const char *name, pa_proplist *pl, void *user_data);
         static void __successStreamCb(pa_stream* s, int success, void* user_data);
         static void __successDrainCb(pa_stream* s, int success, void* user_data);

diff --git a/packaging/capi-media-audio-io.spec b/packaging/capi-media-audio-io.spec
index 42ed89c..ba35f46 100644 (file)
--- a/packaging/capi-media-audio-io.spec
+++ b/packaging/capi-media-audio-io.spec
@@ -1,6 +1,6 @@
 Name:           capi-media-audio-io
 Summary:        An Audio Input & Audio Output library in Tizen Native API
-Version:        0.5.54
+Version:        0.5.55
 Release:        0
 Group:          Multimedia/API
 License:        Apache-2.0

diff --git a/src/cpp/CAudioInput.cpp b/src/cpp/CAudioInput.cpp
index e95918d..661247d 100644 (file)
--- a/src/cpp/CAudioInput.cpp
+++ b/src/cpp/CAudioInput.cpp
@@ -108,7 +108,7 @@ void CAudioInput::finalize() {
 }
 
 void CAudioInput::prepare() {
-    std::lock_guard<std::mutex> mutex(mMutex);
+    CAudioTimedLocker locker(__func__, mMutex);
 
     if (!__IsInit())
         THROW_ERROR_MSG(CAudioError::EError::ERROR_NOT_INITIALIZED, "Did not initialize CAudioInput"); //LCOV_EXCL_LINE
@@ -156,7 +156,7 @@ void CAudioInput::prepare() {
 }
 
 void CAudioInput::unprepare() {
-    std::unique_lock<std::mutex> mutex(mMutex);
+    CAudioTimedLocker locker(__func__, mMutex);
 
     if (!__IsInit())
         THROW_ERROR_MSG(CAudioError::EError::ERROR_NOT_INITIALIZED, //LCOV_EXCL_LINE
@@ -177,13 +177,13 @@ void CAudioInput::unprepare() {
 
     CAudioIO::setState(CAudioInfo::EAudioIOState::AUDIO_IO_STATE_IDLE);
 
-    mutex.unlock();
+    locker.unlock();
 
     CAudioIO::onStateChanged(CAudioInfo::EAudioIOState::AUDIO_IO_STATE_IDLE);
 }
 
 void CAudioInput::pause() {
-    std::unique_lock<std::mutex> mutex(mMutex);
+   CAudioTimedLocker locker(__func__, mMutex);
 
     if (!__IsInit() || !__IsReady())
         THROW_ERROR_MSG(CAudioError::EError::ERROR_NOT_INITIALIZED,   //LCOV_EXCL_LINE
@@ -199,13 +199,13 @@ void CAudioInput::pause() {
     CAudioIO::pause();
     CAudioIO::setState(CAudioInfo::EAudioIOState::AUDIO_IO_STATE_PAUSED);
 
-    mutex.unlock();
+    locker.unlock();
 
     CAudioIO::onStateChanged(CAudioInfo::EAudioIOState::AUDIO_IO_STATE_PAUSED);
 }
 
 void CAudioInput::resume() {
-    std::unique_lock<std::mutex> mutex(mMutex);
+    CAudioTimedLocker locker(__func__, mMutex);
 
     if (!__IsInit() || !__IsReady())
         THROW_ERROR_MSG(CAudioError::EError::ERROR_NOT_INITIALIZED,   //LCOV_EXCL_LINE
@@ -221,13 +221,13 @@ void CAudioInput::resume() {
     CAudioIO::resume();
     CAudioIO::setState(CAudioInfo::EAudioIOState::AUDIO_IO_STATE_RUNNING);
 
-    mutex.unlock();
+    locker.unlock();
 
     CAudioIO::onStateChanged(CAudioInfo::EAudioIOState::AUDIO_IO_STATE_RUNNING);
 }
 
 void CAudioInput::flush() {
-    std::lock_guard<std::mutex> mutex(mMutex);
+    CAudioTimedLocker locker(__func__, mMutex);
 
     if (!__IsInit() || !__IsReady())
         THROW_ERROR_MSG(CAudioError::EError::ERROR_NOT_INITIALIZED,   //LCOV_EXCL_LINE
@@ -256,7 +256,7 @@ void CAudioInput::setStreamCallback(SStreamCallback callback) {
 }
 
 size_t CAudioInput::read(void* buffer, size_t length) {
-    std::unique_lock<std::mutex> mutex(mMutex);
+    CAudioTimedLocker locker(__func__, mMutex);
 
     if (!__IsInit() || !__IsReady())
         THROW_ERROR_MSG(CAudioError::EError::ERROR_NOT_INITIALIZED,   //LCOV_EXCL_LINE
@@ -284,7 +284,7 @@ size_t CAudioInput::read(void* buffer, size_t length) {
 
     // Block until read done
     ret = mpPulseAudioClient->read(buffer, length);
-    mutex.unlock();
+    locker.unlock();
 
     sched_yield();
 
@@ -326,9 +326,9 @@ void CAudioInput::setVolume(double volume) {
         THROW_ERROR_MSG(CAudioError::EError::ERROR_NOT_INITIALIZED, "Not initialized"); //LCOV_EXCL_LINE
 
     if (__IsReady()) {
-        std::unique_lock<std::mutex> defer_mutex(mMutex, std::defer_lock);
+        CAudioTimedLocker locker(__func__);
         if (!mpPulseAudioClient->isInThread())
-            defer_mutex.lock();
+            locker.lock(mMutex, mutex_timeout_s);
 
         mpPulseAudioClient->applyRecordVolume(volume);
     }

diff --git a/src/cpp/CAudioLocker.cpp b/src/cpp/CAudioLocker.cpp
new file mode 100644 (file)
index 0000000..02f984b
--- /dev/null
+++ b/src/cpp/CAudioLocker.cpp
@@ -0,0 +1,81 @@
+/*
+ * Copyright (c) 2023 Samsung Electronics Co., Ltd All Rights Reserved
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+#include "CAudioIODef.h"
+
+#include <iostream>
+#include <unistd.h>
+#include <sys/types.h>
+#include <sys/syscall.h>
+
+using namespace std;
+using namespace tizen_media_audio;
+
+string CAudioTimedLocker::_holder;
+pid_t CAudioTimedLocker::_tid;
+
+CAudioTimedLocker::CAudioTimedLocker(const string& tag) : _tag(tag) {
+}
+
+CAudioTimedLocker::CAudioTimedLocker(const string& tag,
+                                    timed_mutex& m,
+                                    chrono::seconds timeout) : _tag(tag) {
+    lock(m, timeout);
+}
+
+void CAudioTimedLocker::lock(timed_mutex& m,
+                            chrono::seconds timeout) {
+    if (_lock.owns_lock()) {
+        AUDIO_IO_LOGW("[%s] already owner!", _tag.c_str());
+        return;
+    }
+
+    _lock = unique_lock<timed_mutex>(m, timeout);
+
+    if (!_lock.owns_lock()) {
+        AUDIO_IO_LOGE("[%s] timeout! owned by [%s:%d]",
+                    _tag.c_str(), _holder.c_str(), _tid);
+        return;
+    }
+
+#ifdef _AUDIO_IO_DEBUG_TIMING_
+    AUDIO_IO_LOGD("[%s] locked success", _tag.c_str());
+#endif
+    updateHolder(_tag, syscall(__NR_gettid));
+}
+
+void CAudioTimedLocker::unlock() {
+    if (!_lock.owns_lock()) {
+        AUDIO_IO_LOGW("[%s] no lock owned...owned by [%s:%d]",
+                       _tag.c_str(), _holder.c_str(), _tid);
+        return;
+    }
+
+    updateHolder({}, 0);
+    _lock.unlock();
+}
+
+void CAudioTimedLocker::updateHolder(const string& tag, pid_t tid) {
+    _holder = tag;
+    _tid = tid;
+}
+
+CAudioTimedLocker::~CAudioTimedLocker() {
+    if (!_lock.owns_lock())
+        return;
+
+    updateHolder({}, 0);
+}

diff --git a/src/cpp/CAudioOutput.cpp b/src/cpp/CAudioOutput.cpp
index df132ec..ec64126 100644 (file)
--- a/src/cpp/CAudioOutput.cpp
+++ b/src/cpp/CAudioOutput.cpp
@@ -108,7 +108,7 @@ void CAudioOutput::finalize() {
 }
 
 void CAudioOutput::prepare() {
-    std::lock_guard<std::mutex> mutex(mMutex);
+    CAudioTimedLocker locker(__func__, mMutex);
 
     if (!__IsInit())
         THROW_ERROR_MSG(CAudioError::EError::ERROR_NOT_INITIALIZED, "Did not initialize CAudioOutput"); //LCOV_EXCL_LINE
@@ -172,7 +172,7 @@ void CAudioOutput::prepare() {
 }
 
 void CAudioOutput::unprepare() {
-    std::unique_lock<std::mutex> mutex(mMutex);
+    CAudioTimedLocker locker(__func__, mMutex);
 
     if (!__IsInit())
         THROW_ERROR_MSG(CAudioError::EError::ERROR_NOT_INITIALIZED, //LCOV_EXCL_LINE
@@ -198,13 +198,13 @@ void CAudioOutput::unprepare() {
 
     CAudioIO::setState(CAudioInfo::EAudioIOState::AUDIO_IO_STATE_IDLE);
 
-    mutex.unlock();
+    locker.unlock();
 
     CAudioIO::onStateChanged(CAudioInfo::EAudioIOState::AUDIO_IO_STATE_IDLE);
 }
 
 void CAudioOutput::pause() {
-    std::unique_lock<std::mutex> mutex(mMutex);
+    CAudioTimedLocker locker(__func__, mMutex);
 
     if (!__IsInit() || !__IsReady())
         THROW_ERROR_MSG(CAudioError::EError::ERROR_NOT_INITIALIZED,    //LCOV_EXCL_LINE
@@ -222,13 +222,13 @@ void CAudioOutput::pause() {
     CAudioIO::pause();
     CAudioIO::setState(CAudioInfo::EAudioIOState::AUDIO_IO_STATE_PAUSED);
 
-    mutex.unlock();
+    locker.unlock();
 
     CAudioIO::onStateChanged(CAudioInfo::EAudioIOState::AUDIO_IO_STATE_PAUSED);
 }
 
 void CAudioOutput::resume() {
-    std::unique_lock<std::mutex> mutex(mMutex);
+    CAudioTimedLocker locker(__func__, mMutex);
 
     if (!__IsInit() || !__IsReady())
         THROW_ERROR_MSG(CAudioError::EError::ERROR_NOT_INITIALIZED,    //LCOV_EXCL_LINE
@@ -246,13 +246,13 @@ void CAudioOutput::resume() {
     CAudioIO::resume();
     CAudioIO::setState(CAudioInfo::EAudioIOState::AUDIO_IO_STATE_RUNNING);
 
-    mutex.unlock();
+    locker.unlock();
 
     CAudioIO::onStateChanged(CAudioInfo::EAudioIOState::AUDIO_IO_STATE_RUNNING);
 }
 
 void CAudioOutput::drain() {
-    std::lock_guard<std::mutex> mutex(mMutex);
+    CAudioTimedLocker locker(__func__, mMutex);
 
     if (!__IsInit() || !__IsReady())
         THROW_ERROR_MSG(CAudioError::EError::ERROR_NOT_INITIALIZED,    //LCOV_EXCL_LINE
@@ -265,7 +265,7 @@ void CAudioOutput::drain() {
 }
 
 void CAudioOutput::flush() {
-    std::lock_guard<std::mutex> mutex(mMutex);
+    CAudioTimedLocker locker(__func__, mMutex);
 
     if (!__IsInit() || !__IsReady())
         THROW_ERROR_MSG(CAudioError::EError::ERROR_NOT_INITIALIZED,    //LCOV_EXCL_LINE
@@ -284,10 +284,10 @@ int CAudioOutput::getBufferSize() {
 }
 
 size_t CAudioOutput::write(const void* buffer, size_t length) {
-    std::unique_lock<std::mutex> mutex(mMutex, std::defer_lock);
+    CAudioTimedLocker locker(__func__);
 
     if (mpPulseAudioClient && !mpPulseAudioClient->isInThread())
-        mutex.lock();
+        locker.lock(mMutex);
 
     if (!__IsInit() || !__IsReady())
         THROW_ERROR_MSG(CAudioError::EError::ERROR_NOT_INITIALIZED,    //LCOV_EXCL_LINE
@@ -310,6 +310,11 @@ size_t CAudioOutput::write(const void* buffer, size_t length) {
 #ifdef _AUDIO_IO_DEBUG_TIMING_
         AUDIO_IO_LOGD("CPulseAudioClient->write(buffer:%p, length:%zu)", buffer, length);
 #endif
+        __mTotalWrittenCount++;
+        __mTotalWrittenBytes += length;
+
+        __dumpStat(length);
+
         return length;
     }
 
@@ -369,7 +374,7 @@ size_t CAudioOutput::write(const void* buffer, size_t length) {
         }  // End of while (lengthIter > 0)
 
         __mIsUsedSyncWrite = false;
-        mutex.unlock();
+        locker.unlock();
 
         sched_yield();
     } catch (const CAudioError& e) {
@@ -377,11 +382,26 @@ size_t CAudioOutput::write(const void* buffer, size_t length) {
         throw;
     }
 
+    __dumpStat(length);
+
     return length;
 }
 
 void CAudioOutput::__dumpStat() noexcept {
-    AUDIO_IO_LOGD("total written %" PRIu64 " times, %" PRIu64 " bytes, %" PRIu64 " ms",
-                  __mTotalWrittenCount, __mTotalWrittenBytes,
+    AUDIO_IO_LOGD("pClient[%p] : total written %5" PRIu64 " times, %10" PRIu64 " bytes, %7" PRIu64 " ms",
+                  mpPulseAudioClient, __mTotalWrittenCount, __mTotalWrittenBytes,
                   __mTotalWrittenBytes * 1000 / mAudioInfo.getSampleSize() / mAudioInfo.getSampleRate());
+}
+
+void CAudioOutput::__dumpStat(size_t length) noexcept {
+    static constexpr auto PRINT_INTERVAL_BYTES = 256 * 1024; // 256k
+    static constexpr auto MIN_PRINTS = 20;
+    static uint64_t writtenBytes = 0;
+
+    if (__mTotalWrittenCount <= MIN_PRINTS) {
+        __dumpStat();
+    } else if ((writtenBytes += length) > PRINT_INTERVAL_BYTES) {
+        __dumpStat();
+        writtenBytes = 0;
+    }
 }
\ No newline at end of file

diff --git a/src/cpp/CPulseAudioClient.cpp b/src/cpp/CPulseAudioClient.cpp
index e222b64..8d4bb43 100644 (file)
--- a/src/cpp/CPulseAudioClient.cpp
+++ b/src/cpp/CPulseAudioClient.cpp
@@ -276,6 +276,15 @@ void CPulseAudioClient::__streamUnderflowCb(pa_stream* s, void* user_data) {
     pClient->__mIsStarted = false;
 }
 
+void CPulseAudioClient::__streamOverflowCb(pa_stream* s, void* user_data) {
+    assert(s);
+    assert(user_data);
+
+    auto pClient = static_cast<CPulseAudioClient*>(user_data);
+
+    AUDIO_IO_LOGD("pClient[%p] pa_stream[%p] OverFlow...", pClient, s);
+}
+
 //LCOV_EXCL_START
 void CPulseAudioClient::__streamEventCb(pa_stream* s, const char* name, pa_proplist* pl, void* user_data) {
     assert(s);
@@ -302,7 +311,7 @@ void CPulseAudioClient::__successStreamCb(pa_stream* s, int success, void* user_
 
     auto pClient = static_cast<CPulseAudioClient*>(user_data);
 
-    AUDIO_IO_LOGD("pClient[%p], pa_stream[%p], success[%d], user_data[%p]", pClient, s, success, user_data);
+    AUDIO_IO_LOGD("pClient[%p] pa_stream[%p] success[%d] user_data[%p]", pClient, s, success, user_data);
 
     pClient->__mIsOperationSuccess = static_cast<bool>(success);
 
@@ -317,7 +326,7 @@ void CPulseAudioClient::__successDrainCbInThread(pa_stream* s, int success, void
 
     auto pClient = static_cast<CPulseAudioClient*>(user_data);
 
-    AUDIO_IO_LOGD("pClient[%p], pa_stream[%p], success[%d], user_data[%p]", pClient, s, success, user_data);
+    AUDIO_IO_LOGD("pClient[%p] pa_stream[%p] success[%d] user_data[%p]", pClient, s, success, user_data);
 
     pClient->__mIsOperationSuccess = static_cast<bool>(success);
     pClient->__mIsDraining = false;
@@ -330,7 +339,7 @@ void CPulseAudioClient::__successDrainCb(pa_stream* s, int success, void* user_d
 
     auto pClient = static_cast<CPulseAudioClient*>(user_data);
 
-    AUDIO_IO_LOGD("pClient[%p], pa_stream[%p], success[%d], user_data[%p]", pClient, s, success, user_data);
+    AUDIO_IO_LOGD("pClient[%p] pa_stream[%p] success[%d] user_data[%p]", pClient, s, success, user_data);
 
     pClient->__mIsOperationSuccess = static_cast<bool>(success);
     pClient->__mIsDraining = false;
@@ -339,7 +348,7 @@ void CPulseAudioClient::__successDrainCb(pa_stream* s, int success, void* user_d
 }
 
 void CPulseAudioClient::__successVolumeCb(pa_context* c, int success, void* user_data) {
-    AUDIO_IO_LOGD("pa_context[%p], success[%d], user_data[%p]", c, success, user_data);
+    AUDIO_IO_LOGD("pa_context[%p] success[%d] user_data[%p]", c, success, user_data);
 }
 
 void CPulseAudioClient::resetStreamCallbacks() {
@@ -488,6 +497,7 @@ void CPulseAudioClient::initialize() {
         if (__mDirection == EStreamDirection::STREAM_DIRECTION_PLAYBACK) {
             pa_stream_set_started_callback(__mpStream, __streamStartedCb, this);
             pa_stream_set_underflow_callback(__mpStream, __streamUnderflowCb, this);
+            pa_stream_set_overflow_callback(__mpStream, __streamOverflowCb, this);
         }
 
         // Connect stream with PA Server