diff --git a/frameworks/native/appkit/dfr/appfreeze_inner.cpp b/frameworks/native/appkit/dfr/appfreeze_inner.cpp index a98723eea8..bfc3b75d7c 100644 --- a/frameworks/native/appkit/dfr/appfreeze_inner.cpp +++ b/frameworks/native/appkit/dfr/appfreeze_inner.cpp @@ -179,6 +179,8 @@ int AppfreezeInner::AppfreezeHandle(const FaultData& faultData, bool onlyMainThr handlinglist_.emplace_back(faultData); constexpr int HANDLING_MIN_SIZE = 1; if (handlinglist_.size() <= HANDLING_MIN_SIZE) { + TAG_LOGW(AAFwkTag::APPDFR, "submit reportAppFreeze, eventName:%{public}s, startTime:%{public}s\n", + faultData.errorObject.name.c_str(), AbilityRuntime::TimeUtil::DefaultCurrentTimeStr().c_str()); ffrt::submit(reportFreeze, {}, {}, ffrt::task_attr().name("reportAppFreeze")); } } @@ -199,7 +201,12 @@ int AppfreezeInner::AcquireStack(const FaultData& info, bool onlyMainThread) HITRACE_METER_FMT(HITRACE_TAG_APP, "AppfreezeInner::AcquireStack name:%s", info.errorObject.name.c_str()); std::string stack = ""; std::string msgContent; + int64_t startTime = AbilityRuntime::TimeUtil::CurrentTimeMillis(); GetMainHandlerDump(msgContent); + TAG_LOGW(AAFwkTag::APPDFR, "get mainhandler dump, eventName:%{public}s, endTime:%{public}s, " + "interval:%{public}lld ms", info.errorObject.name.c_str(), + AbilityRuntime::TimeUtil::DefaultCurrentTimeStr().c_str(), + AbilityRuntime::TimeUtil::CurrentTimeMillis() - startTime); std::lock_guard lock(handlingMutex_); for (auto it = handlinglist_.begin(); it != handlinglist_.end(); it = handlinglist_.erase(it)) { @@ -261,8 +268,9 @@ int AppfreezeInner::NotifyANR(const FaultData& faultData) } int32_t pid = static_cast(getpid()); - TAG_LOGW(AAFwkTag::APPDFR, "NotifyAppFault:%{public}s, pid:%{public}d, bundleName:%{public}s", - faultData.errorObject.name.c_str(), pid, applicationInfo->bundleName.c_str()); + TAG_LOGW(AAFwkTag::APPDFR, "NotifyAppFault:%{public}s, pid:%{public}d, bundleName:%{public}s " + "currentTime:%{public}s\n", faultData.errorObject.name.c_str(), pid, applicationInfo->bundleName.c_str(), + AbilityRuntime::TimeUtil::DefaultCurrentTimeStr().c_str()); int ret = DelayedSingleton::GetInstance()->NotifyAppFault(faultData); if (ret != 0) { diff --git a/services/appdfr/src/appfreeze_manager.cpp b/services/appdfr/src/appfreeze_manager.cpp index 0bac16e613..36496cd2b9 100644 --- a/services/appdfr/src/appfreeze_manager.cpp +++ b/services/appdfr/src/appfreeze_manager.cpp @@ -156,7 +156,13 @@ void AppfreezeManager::CollectFreezeSysMemory(std::string& memoryContent) int AppfreezeManager::MergeNotifyInfo(FaultData& faultNotifyData, const AppfreezeManager::AppInfo& appInfo) { std::string memoryContent = ""; + int64_t startTime = AbilityRuntime::TimeUtil::CurrentTimeMillis(); CollectFreezeSysMemory(memoryContent); + TAG_LOGW(AAFwkTag::APPDFR, "collect memory info, eventName:%{public}s, bundleName:%{public}s, " + "endTime:%{public}s, interval:%{public}lld ms", faultNotifyData.errorObject.name.c_str(), + appInfo.bundleName.c_str(), AbilityRuntime::TimeUtil::DefaultCurrentTimeStr().c_str(), + AbilityRuntime::TimeUtil::CurrentTimeMillis() - startTime); + std::string fileName = faultNotifyData.errorObject.name + "_" + AbilityRuntime::TimeUtil::FormatTime("%Y%m%d%H%M%S") + "_" + std::to_string(appInfo.pid) + "_stack"; std::string catcherStack = ""; @@ -168,12 +174,16 @@ int AppfreezeManager::MergeNotifyInfo(FaultData& faultNotifyData, const Appfreez fullStackPath = WriteToFile(fileName, catcherStack); faultNotifyData.errorObject.stack = fullStackPath; } else { - auto start = GetMilliseconds(); - std::string timeStamp = "\nTimestamp:" + AbilityRuntime::TimeUtil::FormatTime("%Y-%m-%d %H:%M:%S") + - ":" + std::to_string(start % SEC_TO_MILLISEC); - faultNotifyData.errorObject.message += timeStamp; + std::string currentTime = AbilityRuntime::TimeUtil::DefaultCurrentTimeStr(); + int64_t startTime = AbilityRuntime::TimeUtil::CurrentTimeMillis(); + faultNotifyData.errorObject.message += "\nTimestamp:" + currentTime; catchJsonStack += CatchJsonStacktrace(appInfo.pid, faultNotifyData.errorObject.name, faultNotifyData.errorObject.stack); + TAG_LOGW(AAFwkTag::APPDFR, "catch stack, eventName:%{public}s, bundleName:%{public}s, " + "endTime:%{public}s, interval:%{public}lld ms", faultNotifyData.errorObject.name.c_str(), + appInfo.bundleName.c_str(), AbilityRuntime::TimeUtil::DefaultCurrentTimeStr().c_str(), + AbilityRuntime::TimeUtil::CurrentTimeMillis() - startTime); + fullStackPath = WriteToFile(fileName, catchJsonStack); faultNotifyData.errorObject.stack = fullStackPath; } @@ -191,8 +201,9 @@ int AppfreezeManager::MergeNotifyInfo(FaultData& faultNotifyData, const Appfreez int AppfreezeManager::AppfreezeHandleWithStack(const FaultData& faultData, const AppfreezeManager::AppInfo& appInfo) { - TAG_LOGD(AAFwkTag::APPDFR, "called %{public}s, bundleName %{public}s, name_ %{public}s", - faultData.errorObject.name.c_str(), appInfo.bundleName.c_str(), name_.c_str()); + TAG_LOGW(AAFwkTag::APPDFR, "NotifyAppFaultTask called, eventName:%{public}s, bundleName:%{public}s, " + "name_:%{public}s, currentTime:%{public}s", faultData.errorObject.name.c_str(), appInfo.bundleName.c_str(), + name_.c_str(), AbilityRuntime::TimeUtil::DefaultCurrentTimeStr().c_str()); if (!IsHandleAppfreeze(appInfo.bundleName)) { return -1; } @@ -343,6 +354,7 @@ int AppfreezeManager::NotifyANR(const FaultData& faultData, const AppfreezeManag DelayedSingleton::GetInstance()->GetAppRunningUniqueIdByPid(appInfo.pid, appRunningUniqueId); int ret = 0; + int64_t startTime = AbilityRuntime::TimeUtil::CurrentTimeMillis(); if (faultData.errorObject.name == AppFreezeType::APP_INPUT_BLOCK) { ret = HiSysEventWrite(OHOS::HiviewDFX::HiSysEvent::Domain::AAFWK, faultData.errorObject.name, OHOS::HiviewDFX::HiSysEvent::EventType::FAULT, EVENT_UID, appInfo.uid, EVENT_PID, appInfo.pid, @@ -358,11 +370,12 @@ int AppfreezeManager::NotifyANR(const FaultData& faultData, const AppfreezeManag faultData.errorObject.message, EVENT_STACK, faultData.errorObject.stack, BINDER_INFO, binderInfo, APP_RUNNING_UNIQUE_ID, appRunningUniqueId, FREEZE_MEMORY, memoryContent); } - TAG_LOGI(AAFwkTag::APPDFR, + TAG_LOGW(AAFwkTag::APPDFR, "reportEvent:%{public}s, pid:%{public}d, tid:%{public}d, bundleName:%{public}s, appRunningUniqueId:%{public}s" - ", eventId:%{public}d hisysevent write ret: %{public}d", + ", endTime:%{public}s, interval:%{public}lld ms, eventId:%{public}d hisysevent write ret: %{public}d", faultData.errorObject.name.c_str(), appInfo.pid, faultData.tid, appInfo.bundleName.c_str(), - appRunningUniqueId.c_str(), faultData.eventId, ret); + appRunningUniqueId.c_str(), AbilityRuntime::TimeUtil::DefaultCurrentTimeStr().c_str(), + AbilityRuntime::TimeUtil::CurrentTimeMillis() - startTime, faultData.eventId, ret); return 0; } diff --git a/services/appmgr/src/app_mgr_service_inner.cpp b/services/appmgr/src/app_mgr_service_inner.cpp index 7e686effd8..63d75743cb 100644 --- a/services/appmgr/src/app_mgr_service_inner.cpp +++ b/services/appmgr/src/app_mgr_service_inner.cpp @@ -6476,9 +6476,13 @@ int32_t AppMgrServiceInner::SubmitDfxFaultTask(const FaultData &faultData, const TAG_LOGW(AAFwkTag::APPMGR, "get dfx handler fail"); return ERR_INVALID_VALUE; } - TAG_LOGI(AAFwkTag::APPMGR, "dfx submit freeze task start."); + int64_t startTime = AbilityRuntime::TimeUtil::CurrentTimeMillis(); dfxTaskHandler_->SubmitTask(notifyAppTask, "NotifyAppFaultTask"); - TAG_LOGI(AAFwkTag::APPMGR, "dfx submit freeze task end."); + TAG_LOGW(AAFwkTag::APPDFR, "submit NotifyAppFaultTask, eventName:%{public}s, bundleName:%{public}s, " + "endTime:%{public}s, interval:%{public}lld ms", faultData.errorObject.name.c_str(), + bundleName.c_str(), AbilityRuntime::TimeUtil::DefaultCurrentTimeStr().c_str(), + AbilityRuntime::TimeUtil::CurrentTimeMillis() - startTime); + constexpr int delayTime = 15 * 1000; // 15s auto task = [pid]() { AppExecFwk::AppfreezeManager::GetInstance()->DeleteStack(pid); @@ -6503,6 +6507,10 @@ int32_t AppMgrServiceInner::NotifyAppFault(const FaultData &faultData) return ERR_OK; } std::string bundleName = appRecord->GetBundleName(); + + TAG_LOGW(AAFwkTag::APPDFR, "called, eventName:%{public}s, bundleName:%{public}s, currentTime:%{public}s", + faultData.errorObject.name.c_str(), bundleName.c_str(), + AbilityRuntime::TimeUtil::DefaultCurrentTimeStr().c_str()); if (AppExecFwk::AppfreezeManager::GetInstance()->IsProcessDebug(pid, bundleName)) { TAG_LOGW(AAFwkTag::APPMGR, "don't report event and kill:%{public}s, pid:%{public}d, bundleName:%{public}s",