Add verbose logging

This commit is contained in:
Iscle 2025-04-02 12:28:43 +02:00
parent d2aeef3e64
commit b65dd9fd0b
2 changed files with 90 additions and 26 deletions

View File

@ -29,20 +29,42 @@ static void init_libcutils() {
} }
ashmem_create_region = dlsym(libcutils, "ashmem_create_region"); ashmem_create_region = dlsym(libcutils, "ashmem_create_region");
ashmem_set_prot_region = dlsym(libcutils, "ashmem_set_prot_region"); if (ashmem_create_region == nullptr) {
ALOGE("Failed to load symbol ashmem_create_region from libcutils.so");
native_handle_create = dlsym(libcutils, "native_handle_create"); goto exit;
native_handle_close = dlsym(libcutils, "native_handle_close");
native_handle_delete = dlsym(libcutils, "native_handle_delete");
if (ashmem_create_region == nullptr ||
ashmem_set_prot_region == nullptr ||
native_handle_create == nullptr ||
native_handle_close == nullptr ||
native_handle_delete == nullptr) {
ALOGE("Failed to load symbols from libcutils.so");
} }
ashmem_set_prot_region = dlsym(libcutils, "ashmem_set_prot_region");
if (ashmem_set_prot_region == nullptr) {
ALOGE("Failed to load symbol ashmem_set_prot_region from libcutils.so");
goto exit;
}
native_handle_create = dlsym(libcutils, "native_handle_create");
if (native_handle_create == nullptr) {
ALOGE("Failed to load symbol native_handle_create from libcutils.so");
goto exit;
}
native_handle_close = dlsym(libcutils, "native_handle_close");
if (native_handle_close == nullptr) {
ALOGE("Failed to load symbol native_handle_close from libcutils.so");
goto exit;
}
native_handle_delete = dlsym(libcutils, "native_handle_delete");
if (native_handle_delete == nullptr) {
ALOGE("Failed to load symbol native_handle_delete from libcutils.so");
goto exit;
}
ALOGD("ashmem_create_region: %p", ashmem_create_region);
ALOGD("ashmem_set_prot_region: %p", ashmem_set_prot_region);
ALOGD("native_handle_create: %p", native_handle_create);
ALOGD("native_handle_close: %p", native_handle_close);
ALOGD("native_handle_delete: %p", native_handle_delete);
exit:
dlclose(libcutils); dlclose(libcutils);
} }
@ -54,26 +76,42 @@ static void init_libfmq() {
} }
_ZN7android8hardware7details5checkEbPKc = dlsym(libfmq, "_ZN7android8hardware7details5checkEbPKc"); _ZN7android8hardware7details5checkEbPKc = dlsym(libfmq, "_ZN7android8hardware7details5checkEbPKc");
// ndk variant, real symbol: _ZN7android8hardware7details8logErrorERKNSt3__112basic_stringIcNS2_11char_traitsIcEENS2_9allocatorIcEEEE if (_ZN7android8hardware7details5checkEbPKc == nullptr) {
_ZN7android8hardware7details8logErrorERKNSt6__ndk112basic_stringIcNS2_11char_traitsIcEENS2_9allocatorIcEEEE = dlsym(libfmq, "_ZN7android8hardware7details8logErrorERKNSt3__112basic_stringIcNS2_11char_traitsIcEENS2_9allocatorIcEEEE"); ALOGE("Failed to load symbol _ZN7android8hardware7details5checkEbPKc from libfmq.so");
// ndk variant, real symbol: _ZN7android8hardware9EventFlag15createEventFlagEPNSt3__16atomicIjEEPPS1_ goto exit;
_ZN7android8hardware9EventFlag15createEventFlagEPNSt6__ndk16atomicIjEEPPS1_ = dlsym(libfmq, "_ZN7android8hardware9EventFlag15createEventFlagEPNSt3__16atomicIjEEPPS1_");
_ZN7android8hardware9EventFlag15deleteEventFlagEPPS1_ = dlsym(libfmq, "_ZN7android8hardware9EventFlag15deleteEventFlagEPPS1_");
if (_ZN7android8hardware7details5checkEbPKc == nullptr ||
_ZN7android8hardware7details8logErrorERKNSt6__ndk112basic_stringIcNS2_11char_traitsIcEENS2_9allocatorIcEEEE == nullptr ||
_ZN7android8hardware9EventFlag15createEventFlagEPNSt6__ndk16atomicIjEEPPS1_ == nullptr ||
_ZN7android8hardware9EventFlag15deleteEventFlagEPPS1_ == nullptr) {
ALOGE("Failed to load symbols from libfmq.so");
} }
// ndk variant, real symbol: _ZN7android8hardware7details8logErrorERKNSt3__112basic_stringIcNS2_11char_traitsIcEENS2_9allocatorIcEEEE
_ZN7android8hardware7details8logErrorERKNSt6__ndk112basic_stringIcNS2_11char_traitsIcEENS2_9allocatorIcEEEE = dlsym(libfmq, "_ZN7android8hardware7details8logErrorERKNSt3__112basic_stringIcNS2_11char_traitsIcEENS2_9allocatorIcEEEE");
if (_ZN7android8hardware7details8logErrorERKNSt6__ndk112basic_stringIcNS2_11char_traitsIcEENS2_9allocatorIcEEEE == nullptr) {
ALOGE("Failed to load symbol _ZN7android8hardware7details8logErrorERKNSt6__ndk112basic_stringIcNS2_11char_traitsIcEENS2_9allocatorIcEEEE from libfmq.so");
goto exit;
}
// ndk variant, real symbol: _ZN7android8hardware9EventFlag15createEventFlagEPNSt3__16atomicIjEEPPS1_
_ZN7android8hardware9EventFlag15createEventFlagEPNSt6__ndk16atomicIjEEPPS1_ = dlsym(libfmq, "_ZN7android8hardware9EventFlag15createEventFlagEPNSt3__16atomicIjEEPPS1_");
if (_ZN7android8hardware9EventFlag15createEventFlagEPNSt6__ndk16atomicIjEEPPS1_ == nullptr) {
ALOGE("Failed to load symbol _ZN7android8hardware9EventFlag15createEventFlagEPNSt3__16atomicIjEEPPS1_ from libfmq.so");
goto exit;
}
_ZN7android8hardware9EventFlag15deleteEventFlagEPPS1_ = dlsym(libfmq, "_ZN7android8hardware9EventFlag15deleteEventFlagEPPS1_");
if (_ZN7android8hardware9EventFlag15deleteEventFlagEPPS1_ == nullptr) {
ALOGE("Failed to load symbol _ZN7android8hardware9EventFlag15deleteEventFlagEPPS1_ from libfmq.so");
goto exit;
}
ALOGD("_ZN7android8hardware7details5checkEbPKc: %p", _ZN7android8hardware7details5checkEbPKc);
ALOGD("_ZN7android8hardware7details8logErrorERKNSt6__ndk112basic_stringIcNS2_11char_traitsIcEENS2_9allocatorIcEEEE: %p", _ZN7android8hardware7details8logErrorERKNSt6__ndk112basic_stringIcNS2_11char_traitsIcEENS2_9allocatorIcEEEE);
ALOGD("_ZN7android8hardware9EventFlag15createEventFlagEPNSt6__ndk16atomicIjEEPPS1_: %p", _ZN7android8hardware9EventFlag15createEventFlagEPNSt6__ndk16atomicIjEEPPS1_);
ALOGD("_ZN7android8hardware9EventFlag15deleteEventFlagEPPS1_: %p", _ZN7android8hardware9EventFlag15deleteEventFlagEPPS1_);
exit:
dlclose(libfmq); dlclose(libfmq);
} }
__attribute__((constructor)) __attribute__((constructor))
void shim_init() { void shim_init() {
ALOGD("shim_init");
init_libcutils(); init_libcutils();
init_libfmq(); init_libfmq();
ALOGD("shim_init done");
} }

View File

@ -129,13 +129,17 @@ constexpr size_t getFrameSizeInBytes(
ndk::ScopedAStatus ViPER4AndroidAIDL::open(const Parameter::Common &common, ndk::ScopedAStatus ViPER4AndroidAIDL::open(const Parameter::Common &common,
const std::optional<Parameter::Specific> &specific, const std::optional<Parameter::Specific> &specific,
IEffect::OpenEffectReturn *ret) { IEffect::OpenEffectReturn *ret) {
if (common.input.base.format.pcm != PcmType::FLOAT_32_BIT) { ALOGD("open called");
if (common.input.base.format.pcm != PcmType::FLOAT_32_BIT ||
common.output.base.format.pcm != PcmType::FLOAT_32_BIT) {
ALOGE("open called with invalid PCM type"); ALOGE("open called with invalid PCM type");
return ndk::ScopedAStatus::fromExceptionCode(EX_ILLEGAL_ARGUMENT); return ndk::ScopedAStatus::fromExceptionCode(EX_ILLEGAL_ARGUMENT);
} }
std::lock_guard lg(mImplMutex); std::lock_guard lg(mImplMutex);
ALOGD("mImplMutex locked");
if (mState != State::INIT) { if (mState != State::INIT) {
ALOGD("open: already opened"); ALOGD("open: already opened");
return ndk::ScopedAStatus::ok(); return ndk::ScopedAStatus::ok();
@ -149,11 +153,23 @@ ndk::ScopedAStatus ViPER4AndroidAIDL::open(const Parameter::Common &common,
size_t inBufferSizeInFloat = common.input.frameCount * mInputFrameSize / sizeof(float); size_t inBufferSizeInFloat = common.input.frameCount * mInputFrameSize / sizeof(float);
size_t outBufferSizeInFloat = common.output.frameCount * mOutputFrameSize / sizeof(float); size_t outBufferSizeInFloat = common.output.frameCount * mOutputFrameSize / sizeof(float);
ALOGD("open: inBufferSizeInFloat %zu, outBufferSizeInFloat %zu", inBufferSizeInFloat,
outBufferSizeInFloat);
// only status FMQ use the EventFlag // only status FMQ use the EventFlag
mStatusMQ = std::make_shared<StatusMQ>(1, true /*configureEventFlagWord*/); mStatusMQ = std::make_shared<StatusMQ>(1, true /*configureEventFlagWord*/);
mInputMQ = std::make_shared<DataMQ>(inBufferSizeInFloat); mInputMQ = std::make_shared<DataMQ>(inBufferSizeInFloat);
mOutputMQ = std::make_shared<DataMQ>(outBufferSizeInFloat); mOutputMQ = std::make_shared<DataMQ>(outBufferSizeInFloat);
if (!mStatusMQ || !mInputMQ || !mOutputMQ) {
ALOGE("open: failed to create message queues");
return ndk::ScopedAStatus::fromExceptionCode(EX_ILLEGAL_STATE);
}
ALOGD("message queues created");
ALOGD("open: mStatusMQ %p, mInputMQ %p, mOutputMQ %p", mStatusMQ.get(), mInputMQ.get(),
mOutputMQ.get());
if (!mStatusMQ->isValid() || !mInputMQ->isValid() || !mOutputMQ->isValid()) { if (!mStatusMQ->isValid() || !mInputMQ->isValid() || !mOutputMQ->isValid()) {
ALOGE("open: failed to create message queues"); ALOGE("open: failed to create message queues");
return ndk::ScopedAStatus::fromExceptionCode(EX_ILLEGAL_STATE); return ndk::ScopedAStatus::fromExceptionCode(EX_ILLEGAL_STATE);
@ -166,23 +182,33 @@ ndk::ScopedAStatus ViPER4AndroidAIDL::open(const Parameter::Common &common,
return ndk::ScopedAStatus::fromExceptionCode(EX_ILLEGAL_STATE); return ndk::ScopedAStatus::fromExceptionCode(EX_ILLEGAL_STATE);
} }
ALOGD("open: event flag created");
mWorkBuffer.resize(std::max(inBufferSizeInFloat, outBufferSizeInFloat)); mWorkBuffer.resize(std::max(inBufferSizeInFloat, outBufferSizeInFloat));
ALOGD("open: work buffer size %zu", mWorkBuffer.size());
if (specific.has_value()) { if (specific.has_value()) {
ALOGD("open: specific parameters provided, ignoring for now..."); ALOGD("open: specific parameters provided, ignoring for now...");
} }
mState = State::IDLE; mState = State::IDLE;
ALOGD("open: state set to IDLE");
ret->statusMQ = mStatusMQ->dupeDesc(); ret->statusMQ = mStatusMQ->dupeDesc();
ret->inputDataMQ = mInputMQ->dupeDesc(); ret->inputDataMQ = mInputMQ->dupeDesc();
ret->outputDataMQ = mOutputMQ->dupeDesc(); ret->outputDataMQ = mOutputMQ->dupeDesc();
ALOGD("open: mq descriptors set");
if (createThread(VIPER_NAME) != RetCode::SUCCESS) { if (createThread(VIPER_NAME) != RetCode::SUCCESS) {
ALOGE("open: failed to create thread"); ALOGE("open: failed to create thread");
return ndk::ScopedAStatus::fromExceptionCode(EX_UNSUPPORTED_OPERATION); return ndk::ScopedAStatus::fromExceptionCode(EX_UNSUPPORTED_OPERATION);
} }
ALOGD("open: thread created");
return ndk::ScopedAStatus::ok(); return ndk::ScopedAStatus::ok();
} }