!961 订阅流程增加耗时打印

Merge pull request !961 from Mark_Yao/yzy_dev_0525

services/include/inner_common_event_manager.h

@@ -72,7 +72,7 @@ public:
     EXPORT bool SubscribeCommonEvent(const CommonEventSubscribeInfo &subscribeInfo,
         const sptr<IRemoteObject> &commonEventListener, const struct tm &recordTime, const pid_t &pid, const uid_t &uid,
         const Security::AccessToken::AccessTokenID &callerToken, const std::string &bundleName,
-        const int32_t instanceKey = 0);
+        const int32_t instanceKey = 0, const int64_t startTime = 0);
 
     /**
      * Unsubscribes from common events.

services/src/common_event_manager_service.cpp

@@ -30,6 +30,7 @@
 #include "system_ability_definition.h"
 #include "xcollie/watchdog.h"
 #include "ces_inner_error_code.h"
+#include "system_time.h"
 #include <mutex>
 #include <new>
 
@@ -235,6 +236,7 @@ int32_t CommonEventManagerService::SubscribeCommonEvent(const CommonEventSubscri
     std::string bundleName = DelayedSingleton<BundleManagerHelper>::GetInstance()->GetBundleName(callingUid);
     Security::AccessToken::AccessTokenID callerToken = IPCSkeleton::GetCallingTokenID();
     std::weak_ptr<InnerCommonEventManager> wp = innerCommonEventManager_;
+    int64_t startTime = SystemTime::GetNowSysTime();
     std::function<void()> subscribeCommonEventFunc = [wp,
         subscribeInfo,
         commonEventListener,
@@ -243,7 +245,8 @@ int32_t CommonEventManagerService::SubscribeCommonEvent(const CommonEventSubscri
         callingUid,
         callerToken,
         bundleName,
-        instanceKey] () {
+        instanceKey,
+        startTime] () {
         std::shared_ptr<InnerCommonEventManager> innerCommonEventManager = wp.lock();
         if (innerCommonEventManager == nullptr) {
             EVENT_LOGE("innerCommonEventManager not exist");
@@ -256,7 +259,8 @@ int32_t CommonEventManagerService::SubscribeCommonEvent(const CommonEventSubscri
             callingUid,
             callerToken,
             bundleName,
-            instanceKey);
+            instanceKey,
+            startTime);
         if (!ret) {
             EVENT_LOGE("failed to subscribe event");
         }

services/src/inner_common_event_manager.cpp

@@ -161,9 +161,10 @@ bool InnerCommonEventManager::PublishCommonEvent(const CommonEventData &data, co
 bool InnerCommonEventManager::SubscribeCommonEvent(const CommonEventSubscribeInfo &subscribeInfo,
     const sptr<IRemoteObject> &commonEventListener, const struct tm &recordTime,
     const pid_t &pid, const uid_t &uid, const Security::AccessToken::AccessTokenID &callerToken,
-    const std::string &bundleName, const int32_t instanceKey)
+    const std::string &bundleName, const int32_t instanceKey, const int64_t startTime)
 {
     HITRACE_METER_NAME(HITRACE_TAG_NOTIFICATION, __PRETTY_FUNCTION__);
+    int64_t taskStartTime = SystemTime::GetNowSysTime();
     EVENT_LOGD("enter %{public}s(pid = %{public}d, uid = %{public}d, userId = %{public}d)",
         bundleName.c_str(), pid, uid, subscribeInfo.GetUserId());
 
@@ -203,8 +204,10 @@ bool InnerCommonEventManager::SubscribeCommonEvent(const CommonEventSubscribeInf
     subCount.fetch_add(1);
     eventRecordInfo.subId = subId;
     EVENT_LOGI("SubscribeCommonEvent %{public}s(pid = %{public}d, uid = %{public}d, "
-        "userId = %{public}d, instanceKey = %{public}d, subId = %{public}s)",
+        "userId = %{public}d, instanceKey = %{public}d, subId = %{public}s, "
-        bundleName.c_str(), pid, uid, subscribeInfo.GetUserId(), instanceKey, subId.c_str());
+        "ffrtCost = %{public}s, taskCost = %{public}s",
+        bundleName.c_str(), pid, uid, subscribeInfo.GetUserId(), instanceKey, subId.c_str(),
+        std::to_string(taskStartTime - startTime).c_str(), std::to_string(now - taskStartTime).c_str());
 
     auto record = DelayedSingleton<CommonEventSubscriberManager>::GetInstance()->InsertSubscriber(
         sp, commonEventListener, recordTime, eventRecordInfo);

services/test/unittest/common_event_dump_test.cpp

@@ -349,6 +349,7 @@ bool CommonEventDumpTest::SubscribeCommonEvent(const std::shared_ptr<CommonEvent
         callingUid,
         tokenID,
         bundleName,
+        0,
         0);
     return handler_->PostTask(SubscribeCommonEventFunc);
 }

services/test/unittest/common_event_freeze_test.cpp

@@ -300,6 +300,7 @@ bool CommonEventFreezeTest::SubscribeCommonEvent(const std::shared_ptr<CommonEve
         callingUid,
         tokenID,
         bundleName,
+        0,
         0);
     return handler_->PostTask(SubscribeCommonEventFunc);
 }