diff --git a/audio/aidl/default/EffectConfig.cpp b/audio/aidl/default/EffectConfig.cpp index a1fbefa8b9..eb0c0150e1 100644 --- a/audio/aidl/default/EffectConfig.cpp +++ b/audio/aidl/default/EffectConfig.cpp @@ -37,7 +37,6 @@ namespace aidl::android::hardware::audio::effect { EffectConfig::EffectConfig(const std::string& file) { tinyxml2::XMLDocument doc; doc.LoadFile(file.c_str()); - LOG(DEBUG) << __func__ << " loading " << file; // parse the xml file into maps if (doc.Error()) { LOG(ERROR) << __func__ << " tinyxml2 failed to load " << file @@ -143,7 +142,7 @@ bool EffectConfig::parseEffect(const tinyxml2::XMLElement& xml) { std::string name = xml.Attribute("name"); RETURN_VALUE_IF(name == "", false, "effectsNoName"); - LOG(DEBUG) << __func__ << dump(xml); + LOG(VERBOSE) << __func__ << dump(xml); struct Library library; if (std::strcmp(xml.Name(), "effectProxy") == 0) { // proxy lib and uuid @@ -187,11 +186,11 @@ bool EffectConfig::parseLibrary(const tinyxml2::XMLElement& xml, struct Library& } RETURN_VALUE_IF((library.uuid == getEffectUuidZero()), false, "invalidUuidAttribute"); - LOG(DEBUG) << __func__ << (isProxy ? " proxy " : library.name) << " : uuid " - << ::android::audio::utils::toString(library.uuid) - << (library.type.has_value() - ? ::android::audio::utils::toString(library.type.value()) - : ""); + LOG(VERBOSE) << __func__ << (isProxy ? " proxy " : library.name) << " : uuid " + << ::android::audio::utils::toString(library.uuid) + << (library.type.has_value() + ? ::android::audio::utils::toString(library.type.value()) + : ""); return true; } @@ -245,7 +244,7 @@ std::optional EffectConfig::stringToProcessingType(Processing: } bool EffectConfig::parseProcessing(Processing::Type::Tag typeTag, const tinyxml2::XMLElement& xml) { - LOG(DEBUG) << __func__ << dump(xml); + LOG(VERBOSE) << __func__ << dump(xml); const char* typeStr = xml.Attribute("type"); auto aidlType = stringToProcessingType(typeTag, typeStr); RETURN_VALUE_IF(!aidlType.has_value(), false, "illegalStreamType"); @@ -259,7 +258,6 @@ bool EffectConfig::parseProcessing(Processing::Type::Tag typeTag, const tinyxml2 } RETURN_VALUE_IF(!name, false, "noEffectAttribute"); mProcessingMap[aidlType.value()].emplace_back(mEffectsMap[name]); - LOG(WARNING) << __func__ << " " << typeStr << " : " << name; } return true; } diff --git a/audio/aidl/default/EffectContext.cpp b/audio/aidl/default/EffectContext.cpp index 9575790644..7b8cfb13ae 100644 --- a/audio/aidl/default/EffectContext.cpp +++ b/audio/aidl/default/EffectContext.cpp @@ -157,7 +157,6 @@ Parameter::VolumeStereo EffectContext::getVolumeStereo() { } RetCode EffectContext::setCommon(const Parameter::Common& common) { - LOG(VERBOSE) << __func__ << common.toString(); auto& input = common.input; auto& output = common.output; @@ -186,7 +185,6 @@ RetCode EffectContext::setCommon(const Parameter::Common& common) { } Parameter::Common EffectContext::getCommon() { - LOG(VERBOSE) << __func__ << mCommon.toString(); return mCommon; } @@ -241,7 +239,7 @@ RetCode EffectContext::notifyDataMqUpdate() { LOG(ERROR) << __func__ << ": wake failure with ret " << ret; return RetCode::ERROR_EVENT_FLAG_ERROR; } - LOG(DEBUG) << __func__ << " : signal client for reopen"; + LOG(VERBOSE) << __func__ << " : signal client for reopen"; return RetCode::SUCCESS; } } // namespace aidl::android::hardware::audio::effect diff --git a/audio/aidl/default/EffectFactory.cpp b/audio/aidl/default/EffectFactory.cpp index 96f13ba058..ba5b14163d 100644 --- a/audio/aidl/default/EffectFactory.cpp +++ b/audio/aidl/default/EffectFactory.cpp @@ -43,12 +43,12 @@ Factory::Factory(const std::string& file) : mConfig(EffectConfig(file)) { Factory::~Factory() { if (auto count = mEffectMap.size()) { - LOG(ERROR) << __func__ << " remaining " << count - << " effect instances not destroyed indicating resource leak!"; + LOG(WARNING) << __func__ << " remaining " << count + << " effect instances not destroyed indicating resource leak!"; for (const auto& it : mEffectMap) { if (auto spEffect = it.first.lock()) { - LOG(ERROR) << __func__ << " erase remaining instance UUID " - << ::android::audio::utils::toString(it.second.first); + LOG(WARNING) << __func__ << " erase remaining instance UUID " + << ::android::audio::utils::toString(it.second.first); destroyEffectImpl_l(spEffect); } } @@ -139,7 +139,7 @@ ndk::ScopedAStatus Factory::createEffect(const AudioUuid& in_impl_uuid, std::shared_ptr effectSp; RETURN_IF_BINDER_EXCEPTION(libInterface->createEffectFunc(&in_impl_uuid, &effectSp)); if (!effectSp) { - LOG(ERROR) << __func__ << ": library created null instance without return error!"; + LOG(WARNING) << __func__ << ": library created null instance without return error!"; return ndk::ScopedAStatus::fromExceptionCode(EX_TRANSACTION_FAILED); } *_aidl_return = effectSp; @@ -147,7 +147,6 @@ ndk::ScopedAStatus Factory::createEffect(const AudioUuid& in_impl_uuid, AIBinder_setMinSchedulerPolicy(effectBinder.get(), SCHED_NORMAL, ANDROID_PRIORITY_AUDIO); mEffectMap[std::weak_ptr(effectSp)] = std::make_pair(in_impl_uuid, std::move(effectBinder)); - LOG(DEBUG) << __func__ << ": instance " << effectSp.get() << " created successfully"; return ndk::ScopedAStatus::ok(); } else { LOG(ERROR) << __func__ << ": library doesn't exist"; @@ -192,7 +191,6 @@ void Factory::cleanupEffectMap_l() { } ndk::ScopedAStatus Factory::destroyEffect(const std::shared_ptr& in_handle) { - LOG(DEBUG) << __func__ << ": instance " << in_handle.get(); std::lock_guard lg(mMutex); ndk::ScopedAStatus status = destroyEffectImpl_l(in_handle); // always do the cleanup @@ -215,8 +213,8 @@ bool Factory::openEffectLibrary(const AudioUuid& impl, return false; } - LOG(INFO) << __func__ << " dlopen lib:" << path - << "\nimpl:" << ::android::audio::utils::toString(impl) << "\nhandle:" << libHandle; + LOG(DEBUG) << __func__ << " dlopen lib: " << path + << "\nimpl:" << ::android::audio::utils::toString(impl) << "\nhandle:" << libHandle; auto interface = new effect_dl_interface_s{nullptr, nullptr, nullptr}; mEffectLibMap.insert( {impl, @@ -235,11 +233,12 @@ void Factory::createIdentityWithConfig( id.type = typeUuid; id.uuid = configLib.uuid; id.proxy = proxyUuid; - LOG(DEBUG) << __func__ << " loading lib " << path->second << ": typeUuid " - << ::android::audio::utils::toString(id.type) << "\nimplUuid " - << ::android::audio::utils::toString(id.uuid) << " proxyUuid " - << (proxyUuid.has_value() ? ::android::audio::utils::toString(proxyUuid.value()) - : "null"); + LOG(WARNING) << __func__ << " loading lib " << path->second << ": typeUuid " + << ::android::audio::utils::toString(id.type) << "\nimplUuid " + << ::android::audio::utils::toString(id.uuid) << " proxyUuid " + << (proxyUuid.has_value() + ? ::android::audio::utils::toString(proxyUuid.value()) + : "null"); if (openEffectLibrary(id.uuid, path->second)) { mIdentitySet.insert(std::move(id)); } @@ -263,8 +262,8 @@ void Factory::loadEffectLibs() { createIdentityWithConfig(configLib, type, proxyUuid); } } else { - LOG(ERROR) << __func__ << ": can not find type UUID for effect " << configEffects.first - << " skipping!"; + LOG(WARNING) << __func__ << ": can not find type UUID for effect " + << configEffects.first << " skipping!"; } } } diff --git a/audio/aidl/default/EffectImpl.cpp b/audio/aidl/default/EffectImpl.cpp index 4d7b9809c6..03de74f43c 100644 --- a/audio/aidl/default/EffectImpl.cpp +++ b/audio/aidl/default/EffectImpl.cpp @@ -35,7 +35,6 @@ extern "C" binder_exception_t destroyEffect(const std::shared_ptr& inst << " in state: " << toString(state) << ", status: " << status.getDescription(); return EX_ILLEGAL_STATE; } - LOG(DEBUG) << __func__ << " instance " << instanceSp.get() << " destroyed"; return EX_NONE; } @@ -91,7 +90,7 @@ ndk::ScopedAStatus EffectImpl::close() { } RETURN_IF(notifyEventFlag(kEventFlagNotEmpty) != RetCode::SUCCESS, EX_ILLEGAL_STATE, - "notifyEventFlagFailed"); + "notifyEventFlagNotEmptyFailed"); // stop the worker thread, ignore the return code RETURN_IF(destroyThread() != RetCode::SUCCESS, EX_UNSUPPORTED_OPERATION, "FailedToDestroyWorker"); @@ -231,8 +230,6 @@ ndk::ScopedAStatus EffectImpl::getState(State* state) NO_THREAD_SAFETY_ANALYSIS ndk::ScopedAStatus EffectImpl::command(CommandId command) { std::lock_guard lg(mImplMutex); RETURN_IF(mState == State::INIT, EX_ILLEGAL_STATE, "instanceNotOpen"); - LOG(DEBUG) << getEffectName() << __func__ << ": receive command: " << toString(command) - << " at state " << toString(mState); switch (command) { case CommandId::START: @@ -240,7 +237,7 @@ ndk::ScopedAStatus EffectImpl::command(CommandId command) { RETURN_IF_ASTATUS_NOT_OK(commandImpl(command), "commandImplFailed"); mState = State::PROCESSING; RETURN_IF(notifyEventFlag(kEventFlagNotEmpty) != RetCode::SUCCESS, EX_ILLEGAL_STATE, - "notifyEventFlagFailed"); + "notifyEventFlagNotEmptyFailed"); startThread(); break; case CommandId::STOP: @@ -248,7 +245,7 @@ ndk::ScopedAStatus EffectImpl::command(CommandId command) { RETURN_OK_IF(mState == State::IDLE); mState = State::IDLE; RETURN_IF(notifyEventFlag(kEventFlagNotEmpty) != RetCode::SUCCESS, EX_ILLEGAL_STATE, - "notifyEventFlagFailed"); + "notifyEventFlagNotEmptyFailed"); stopThread(); RETURN_IF_ASTATUS_NOT_OK(commandImpl(command), "commandImplFailed"); break; @@ -257,7 +254,7 @@ ndk::ScopedAStatus EffectImpl::command(CommandId command) { return ndk::ScopedAStatus::fromExceptionCodeWithMessage(EX_ILLEGAL_ARGUMENT, "CommandIdNotSupported"); } - LOG(DEBUG) << getEffectName() << __func__ << " transfer to state: " << toString(mState); + LOG(VERBOSE) << getEffectName() << __func__ << " transfer to state: " << toString(mState); return ndk::ScopedAStatus::ok(); } @@ -294,6 +291,7 @@ RetCode EffectImpl::notifyEventFlag(uint32_t flag) { LOG(ERROR) << getEffectName() << __func__ << ": wake failure with ret " << ret; return RetCode::ERROR_EVENT_FLAG_ERROR; } + LOG(VERBOSE) << getEffectName() << __func__ << ": " << std::hex << mEventFlag; return RetCode::SUCCESS; } @@ -306,7 +304,7 @@ IEffect::Status EffectImpl::status(binder_status_t status, size_t consumed, size } void EffectImpl::process() { - ATRACE_CALL(); + ATRACE_NAME(getEffectName().c_str()); /** * wait for the EventFlag without lock, it's ok because the mEfGroup pointer will not change * in the life cycle of workerThread (threadLoop). @@ -344,8 +342,6 @@ void EffectImpl::process() { IEffect::Status status = effectProcessImpl(buffer, buffer, processSamples); outputMQ->write(buffer, status.fmqProduced); statusMQ->writeBlocking(&status, 1); - LOG(VERBOSE) << getEffectName() << __func__ << ": done processing, effect consumed " - << status.fmqConsumed << " produced " << status.fmqProduced; } } } @@ -355,7 +351,6 @@ IEffect::Status EffectImpl::effectProcessImpl(float* in, float* out, int samples for (int i = 0; i < samples; i++) { *out++ = *in++; } - LOG(VERBOSE) << getEffectName() << __func__ << " done processing " << samples << " samples"; return {STATUS_OK, samples, samples}; } diff --git a/audio/aidl/default/EffectThread.cpp b/audio/aidl/default/EffectThread.cpp index fdd48034e8..b5153859e1 100644 --- a/audio/aidl/default/EffectThread.cpp +++ b/audio/aidl/default/EffectThread.cpp @@ -27,13 +27,8 @@ namespace aidl::android::hardware::audio::effect { -EffectThread::EffectThread() { - LOG(DEBUG) << __func__; -} - EffectThread::~EffectThread() { destroyThread(); - LOG(DEBUG) << __func__ << " done"; } RetCode EffectThread::createThread(const std::string& name, int priority) { @@ -51,7 +46,7 @@ RetCode EffectThread::createThread(const std::string& name, int priority) { } mThread = std::thread(&EffectThread::threadLoop, this); - LOG(DEBUG) << mName << __func__ << " priority " << mPriority << " done"; + LOG(VERBOSE) << mName << __func__ << " priority " << mPriority << " done"; return RetCode::SUCCESS; } @@ -66,7 +61,7 @@ RetCode EffectThread::destroyThread() { mThread.join(); } - LOG(DEBUG) << mName << __func__; + LOG(VERBOSE) << mName << __func__; return RetCode::SUCCESS; } @@ -77,7 +72,7 @@ RetCode EffectThread::startThread() { mCv.notify_one(); } - LOG(DEBUG) << mName << __func__; + LOG(VERBOSE) << mName << __func__; return RetCode::SUCCESS; } @@ -88,7 +83,7 @@ RetCode EffectThread::stopThread() { mCv.notify_one(); } - LOG(DEBUG) << mName << __func__; + LOG(VERBOSE) << mName << __func__; return RetCode::SUCCESS; } @@ -101,7 +96,7 @@ void EffectThread::threadLoop() { ::android::base::ScopedLockAssertion lock_assertion(mThreadMutex); mCv.wait(l, [&]() REQUIRES(mThreadMutex) { return mExit || !mStop; }); if (mExit) { - LOG(INFO) << __func__ << " EXIT!"; + LOG(VERBOSE) << mName << " threadLoop EXIT!"; return; } } diff --git a/audio/aidl/default/include/effect-impl/EffectThread.h b/audio/aidl/default/include/effect-impl/EffectThread.h index 3dbb0e6798..ec2a65834b 100644 --- a/audio/aidl/default/include/effect-impl/EffectThread.h +++ b/audio/aidl/default/include/effect-impl/EffectThread.h @@ -31,11 +31,9 @@ namespace aidl::android::hardware::audio::effect { class EffectThread { public: - // default priority is same as HIDL: ANDROID_PRIORITY_URGENT_AUDIO - EffectThread(); virtual ~EffectThread(); - // called by effect implementation. + // called by effect implementation RetCode createThread(const std::string& name, int priority = ANDROID_PRIORITY_URGENT_AUDIO); RetCode destroyThread(); RetCode startThread();