diff --git a/ipc/native/src/core/framework/source/ipc_object_proxy.cpp b/ipc/native/src/core/framework/source/ipc_object_proxy.cpp index 7fdd1174e66b668123408593f1a270cb3cecd4d1..5425516758597c60f9d8898f7f59a6398fae48c5 100644 --- a/ipc/native/src/core/framework/source/ipc_object_proxy.cpp +++ b/ipc/native/src/core/framework/source/ipc_object_proxy.cpp @@ -203,8 +203,8 @@ int IPCObjectProxy::SendRequest(uint32_t code, MessageParcel &data, MessageParce #endif auto timeInterval = std::chrono::duration_cast(endTime - beginTime).count(); if (timeInterval > SEND_REQUEST_TIMEOUT) { - ZLOGW(LABEL, "DFX_BlockMonitor IPC cost %{public}lld ms, interface code:%{public}u, desc:%{public}s", - timeInterval, code, desc.c_str()); + ZLOGW(LABEL, "DFX_BlockMonitor proxy cost %{public}lld ms, code:%{public}u, desc:%{public}s", timeInterval, + code, desc.c_str()); } return err; } diff --git a/ipc/native/src/core/framework/source/ipc_object_stub.cpp b/ipc/native/src/core/framework/source/ipc_object_stub.cpp index a61c11c6654fb95ef47fd943273615085ff19c08..dbf73202a75bcb0a3b8ccb6259f0a16c859b220e 100644 --- a/ipc/native/src/core/framework/source/ipc_object_stub.cpp +++ b/ipc/native/src/core/framework/source/ipc_object_stub.cpp @@ -414,8 +414,8 @@ int IPCObjectStub::SendRequestInner(uint32_t code, MessageParcel &data, MessageP uint32_t duration = static_cast(std::chrono::duration_cast( finish - start).count()); if (duration >= IPC_CMD_PROCESS_WARN_TIME) { - ZLOGW(LABEL, "stub:%{public}s deal request code:%{public}u cost time:%{public}ums", - remoteDescriptor_.c_str(), code, duration / COEFF_MILLI_TO_MICRO); + ZLOGW(LABEL, "DFX_BlockMonitor stub cost %{public}ums, code:%{public}u, desc:%{public}s", + duration / COEFF_MILLI_TO_MICRO, code, remoteDescriptor_.c_str()); if (duration >= IPC_CMD_PROCESS_DFX_REPORT_TIME) { DfxReportRequestProcEvent(remoteDescriptor_.c_str(), static_cast(duration / COEFF_MILLI_TO_MICRO), static_cast(code), __FUNCTION__); @@ -619,7 +619,7 @@ int32_t IPCObjectStub::InvokerDataBusThread(MessageParcel &data, MessageParcel & } uint32_t selfTokenId = static_cast(IPCSkeleton::GetSelfTokenID()); - ZLOGI(LABEL, "invoke databus thread, local deviceId:%{public}s remote deviceId:%{public}s " + ZLOGI(LABEL, "local deviceId:%{public}s remote deviceId:%{public}s " "stubIndex:%{public}" PRIu64 " sessionName:%{public}s", IPCProcessSkeleton::ConvertToSecureString(deviceId).c_str(), IPCProcessSkeleton::ConvertToSecureString(remoteDeviceId).c_str(), stubIndex, sessionName.c_str()); diff --git a/ipc/native/src/core/framework/source/ipc_workthread.cpp b/ipc/native/src/core/framework/source/ipc_workthread.cpp index 56cdb8f62ec7026751cd2957717e69eda30eaec7..e30d296713921ab7031ea6e446e984d1e0e7e9bf 100644 --- a/ipc/native/src/core/framework/source/ipc_workthread.cpp +++ b/ipc/native/src/core/framework/source/ipc_workthread.cpp @@ -106,7 +106,7 @@ void *IPCWorkThread::ThreadHandler(void *args) } if (process->GetThreadStopFlag()) { - ZLOGW(LOG_LABEL, "the stop flag is true, thread start exit"); + ZLOGW(LOG_LABEL, "thread start exit"); delete param; return nullptr; } @@ -154,7 +154,7 @@ bool IPCWorkThread::Start(int policy, int proto, int threadIndex) } if (process->GetThreadStopFlag()) { - ZLOGW(LOG_LABEL, "the stop flag is true, can not create other thread"); + ZLOGW(LOG_LABEL, "can not create other thread"); return false; } diff --git a/ipc/native/src/core/framework/source/iremote_broker.cpp b/ipc/native/src/core/framework/source/iremote_broker.cpp index 5d94ce8463439ea7723adfc6c2a41cac48b46c56..3271f86c3cd5cfccbea7f089cc46a7f5c8706f25 100644 --- a/ipc/native/src/core/framework/source/iremote_broker.cpp +++ b/ipc/native/src/core/framework/source/iremote_broker.cpp @@ -94,7 +94,14 @@ void BrokerRegistration::Unregister(const std::u16string &descriptor) for (auto iter = objects_.begin(); iter != objects_.end();) { std::string soPath = GetObjectSoPath(iter->first); if (soPath.empty() || (soPath != iter->second)) { - ZLOGW(LABEL, "path:%{public}s is dlclosed", iter->second.c_str()); + std::string path = iter->second; + size_t found = path.find_last_of('/'); + if (found != std::string::npos) { + std::string soName = path.substr(found + 1); + ZLOGW(LABEL, "path:%{public}s is dlclosed", soName.c_str()); + } else { + ZLOGW(LABEL, "path:%{public}s is dlclosed", path.c_str()); + } iter = objects_.erase(iter); continue; } diff --git a/ipc/native/src/core/framework/source/process_skeleton.cpp b/ipc/native/src/core/framework/source/process_skeleton.cpp index 5d825452c4b2cbbdbecc2e54d6e4bc153867d4bf..4663c91be6ac31ada539bb18ecf3967dfe2d36d6 100644 --- a/ipc/native/src/core/framework/source/process_skeleton.cpp +++ b/ipc/native/src/core/framework/source/process_skeleton.cpp @@ -166,7 +166,7 @@ bool ProcessSkeleton::AttachObject(IRemoteObject *object, const std::u16string & if (object->IsProxyObject()) { uint64_t proxyObjectCountNum = proxyObjectCountNum_.fetch_add(1, std::memory_order_relaxed) + 1; if (ipcProxyCallback_ != nullptr && ipcProxyLimitNum_ > 0 && proxyObjectCountNum > ipcProxyLimitNum_) { - ZLOGW(LOG_LABEL, "ipc proxy num:%{public}" PRIu64 " exceeds limit:%{public}" PRIu64, proxyObjectCountNum, + ZLOGD(LOG_LABEL, "ipc proxy num:%{public}" PRIu64 " exceeds limit:%{public}" PRIu64, proxyObjectCountNum, ipcProxyLimitNum_); ipcProxyCallback_(proxyObjectCountNum); } @@ -490,8 +490,7 @@ void ProcessSkeleton::NotifyChildThreadStop() if (connector != nullptr) { connector->CloseDriverFd(); } - ZLOGI(LOG_LABEL, "start waiting for child thread to exit, child thread num:%{public}zu", - runningChildThreadNum_.load()); + ZLOGI(LOG_LABEL, "waiting child thread:%{public}zu to exit", runningChildThreadNum_.load()); std::unique_lock lockGuard(threadCountMutex_); threadCountCon_.wait_for(lockGuard, std::chrono::seconds(MAIN_THREAD_MAX_WAIT_TIME), [&threadNum = this->runningChildThreadNum_] { diff --git a/ipc/native/src/core/invoker/source/binder_invoker.cpp b/ipc/native/src/core/invoker/source/binder_invoker.cpp index e50d075533256dcd2a3b8933aba241d145b21428..0c40835a328cd58a1e6cb3b6c2983956c44025cd 100644 --- a/ipc/native/src/core/invoker/source/binder_invoker.cpp +++ b/ipc/native/src/core/invoker/source/binder_invoker.cpp @@ -75,6 +75,8 @@ static constexpr pid_t INVALID_PID = -1; static constexpr int32_t BINDER_ALIGN_BYTES = 8; #endif static constexpr int THREAD_IDLE_PRIORITY = 7; +static constexpr int PRINT_COUNT = 100; +static int g_count = 0; enum { GET_SERVICE_TRANSACTION = 0x1, @@ -447,10 +449,20 @@ bool BinderInvoker::UnFlattenDBinderObject(Parcel &parcel, dbinder_negotiation_d } #endif +void PrintLog() +{ + g_count++; + if (g_count == PRINT_COUNT) { + ZLOGE(LABEL, "died"); + g_count = 0; + } + return; +} + bool BinderInvoker::SetMaxWorkThread(int maxThreadNum) { if ((binderConnector_ == nullptr) || (!binderConnector_->IsDriverAlive())) { - ZLOGE(LABEL, "died"); + PrintLog(); return false; } @@ -466,7 +478,7 @@ bool BinderInvoker::SetMaxWorkThread(int maxThreadNum) int BinderInvoker::FlushCommands(IRemoteObject *object) { if ((binderConnector_ == nullptr) || (!binderConnector_->IsDriverAlive())) { - ZLOGE(LABEL, "died"); + PrintLog(); return IPC_INVOKER_CONNECT_ERR; } int error = TransactWithDriver(false); @@ -497,7 +509,7 @@ int BinderInvoker::FlushCommands(IRemoteObject *object) void BinderInvoker::ExitCurrentThread() { if ((binderConnector_ == nullptr) || (!binderConnector_->IsDriverAlive())) { - ZLOGE(LABEL, "died"); + PrintLog(); return; } binderConnector_->ExitCurrentThread(BINDER_THREAD_EXIT); @@ -507,7 +519,7 @@ void BinderInvoker::ExitCurrentThread() void BinderInvoker::StartWorkLoop() { if ((binderConnector_ == nullptr) || (!binderConnector_->IsDriverAlive())) { - ZLOGE(LABEL, "died"); + PrintLog(); return; } int error; @@ -537,8 +549,11 @@ void BinderInvoker::StartWorkLoop() if ((cmd == BR_TRANSACTION) || (cmd == BR_TRANSACTION_SEC_CTX)) { isFirstInvoke_ = STATUS_NOT_FIRST_INVOKE; } - if ((userError == -ERR_TIMED_OUT || userError == IPC_INVOKER_INVALID_DATA_ERR) && !isMainWorkThread) { - ZLOGW(LABEL, "exit, error:%{public}d", userError); + if (userError == -ERR_TIMED_OUT && !isMainWorkThread) { + break; + } + if (userError == IPC_INVOKER_INVALID_DATA_ERR && !isMainWorkThread) { + ZLOGW(LABEL, "exit"); break; } ProcDeferredDecRefs(); @@ -1023,7 +1038,7 @@ int BinderInvoker::HandleCommands(uint32_t cmd) int duration = static_cast(std::chrono::duration_cast( finish - start).count()); if (duration >= IPC_CMD_PROCESS_WARN_TIME) { - ZLOGW(LABEL, "HandleCommands cmd:%{public}u cost time:%{public}dms", cmd, duration); + ZLOGW(LABEL, "cmd:%{public}u cost time:%{public}dms", cmd, duration); } } return error; @@ -1038,7 +1053,7 @@ void BinderInvoker::JoinThread(bool initiative) output_.WriteUint32(BC_EXIT_LOOPER); // pass in nullptr directly FlushCommands(nullptr); - ZLOGE(LABEL, "Current Thread:%{public}d is leaving", getpid()); + ZLOGD(LABEL, "Current Thread:%{public}d is leaving", getpid()); } void BinderInvoker::JoinProcessThread(bool initiative) {} @@ -1245,7 +1260,7 @@ void BinderInvoker::DealWithCmd(MessageParcel *reply, bool &continueLoop, int32_ int BinderInvoker::WaitForCompletion(MessageParcel *reply) { if ((binderConnector_ == nullptr) || (!binderConnector_->IsDriverAlive())) { - ZLOGE(LABEL, "died"); + PrintLog(); return IPC_INVOKER_CONNECT_ERR; } uint32_t cmd; @@ -1658,7 +1673,7 @@ bool BinderInvoker::SetCallingIdentity(std::string &identity, bool flag) bool BinderInvoker::TriggerSystemIPCThreadReclaim() { if ((binderConnector_ == nullptr) || (!binderConnector_->IsDriverAlive())) { - ZLOGE(LABEL, "died"); + PrintLog(); return false; } @@ -1675,7 +1690,7 @@ bool BinderInvoker::TriggerSystemIPCThreadReclaim() bool BinderInvoker::EnableIPCThreadReclaim(bool enable) { if ((binderConnector_ == nullptr) || (!binderConnector_->IsDriverAlive())) { - ZLOGE(LABEL, "died"); + PrintLog(); return false; } diff --git a/ipc/native/src/napi/src/napi_ipc_skeleton.cpp b/ipc/native/src/napi/src/napi_ipc_skeleton.cpp index dcb8616c93d91bc7b5e26fc64dbcdab4e7786676..b4605bf0a5ee029eec70f91fd50f2bbf08edbcc5 100644 --- a/ipc/native/src/napi/src/napi_ipc_skeleton.cpp +++ b/ipc/native/src/napi/src/napi_ipc_skeleton.cpp @@ -149,6 +149,7 @@ napi_value NAPI_IPCSkeleton_flushCommands(napi_env env, napi_callback_info info) NAPI_ASSERT(env, valueType == napi_object, "type mismatch for parameter 1"); sptr target = NAPI_ohos_rpc_getNativeRemoteObject(env, argv[ARGV_INDEX_0]); + NAPI_ASSERT(env, target != nullptr, "remote is null"); int32_t result = IPCSkeleton::FlushCommands(target); napi_value napiValue = nullptr; NAPI_CALL(env, napi_create_int32(env, result, &napiValue)); @@ -175,6 +176,10 @@ napi_value NAPI_IPCSkeleton_flushCmdBuffer(napi_env env, napi_callback_info info } sptr target = NAPI_ohos_rpc_getNativeRemoteObject(env, argv[ARGV_INDEX_0]); + if (target == nullptr) { + ZLOGE(LOG_LABEL, "remote is null"); + return napiErr.ThrowError(env, errorDesc::CHECK_PARAM_ERROR); + } IPCSkeleton::FlushCommands(target); napi_value napiValue = nullptr; napi_get_undefined(env, &napiValue); diff --git a/ipc/native/src/napi_common/source/napi_remote_object.cpp b/ipc/native/src/napi_common/source/napi_remote_object.cpp index 6c90822a6970028194c5f117845a8b162459211d..670429b717e313b7a8057271e0a0882326b9187c 100644 --- a/ipc/native/src/napi_common/source/napi_remote_object.cpp +++ b/ipc/native/src/napi_common/source/napi_remote_object.cpp @@ -364,7 +364,7 @@ static void OnJsRemoteRequestCallBack(CallbackParam *param, std::string &desc) uint64_t curTime = static_cast(std::chrono::duration_cast( std::chrono::steady_clock::now().time_since_epoch()).count()); - ZLOGI(LOG_LABEL, "enter thread pool desc:%{public}s, time:%{public}" PRIu64, desc.c_str(), curTime); + ZLOGD(LOG_LABEL, "enter thread pool desc:%{public}s, time:%{public}" PRIu64, desc.c_str(), curTime); NapiScope napiScope(param->env); if (!napiScope.IsValid()) { @@ -973,7 +973,6 @@ sptr NAPI_ohos_rpc_getNativeRemoteObject(napi_env env, napi_value return holder != nullptr ? holder->object_ : nullptr; } } - ZLOGW(LOG_LABEL, "napi object is nullptr"); return nullptr; }