diff --git a/include/perf_events.h b/include/perf_events.h index 98b5e36fbc0fb60b457c00d1ceccd9f3cd0cd078..029077c5ee62f2fa8e7a7ada261b690797246965 100644 --- a/include/perf_events.h +++ b/include/perf_events.h @@ -538,6 +538,7 @@ public: void SetHM(const bool isHM); void SetConfig(std::map &speOptMaps); private: + using SteadyTimePoint = std::chrono::steady_clock::time_point; size_t recordEventCount_ = 0; // only for debug time #ifdef HIPERF_DEBUG_TIME std::chrono::microseconds recordCallBackTime_ = std::chrono::microseconds::zero(); @@ -558,6 +559,16 @@ private: bool isLowPriorityThread_ = false; void RecordLoop(); void StatLoop(); + void HandleLoopExit(const SteadyTimePoint& startTime, __u64 durationInSec); + void HandleReporting(const SteadyTimePoint& startTime, + const SteadyTimePoint& endTime, + SteadyTimePoint& nextReportTime, + const SteadyTimePoint& thisTime, + __u64& durationInSec); + bool CheckExitConditions(const SteadyTimePoint& startTime, + const SteadyTimePoint& endTime, + const SteadyTimePoint& thisTime, + __u64& durationInSec); bool IsRecordInMmap(const int timeout); void ReadRecordsFromMmaps(); void ReadRecordsFromSpeMmaps(MmapFd& mmapFd, const u64 auxOffset, u64 auxSize, const u32 pid, const u32 tid); @@ -574,7 +585,7 @@ private: size_t CalcBufferSize(); bool PrepareRecordThread(); void WaitRecordThread(); - bool HaveTargetsExit(const std::chrono::steady_clock::time_point &startTime); + bool HaveTargetsExit(const SteadyTimePoint &startTime); void ExitReadRecordBufThread(); #ifdef CONFIG_HAS_CCM diff --git a/include/subcommand_stat.h b/include/subcommand_stat.h index 83ba5f1f82943ad734f297951af9ce0b44b1cb6b..fb40367a9f4fb682a23fc83a23913f40ef8a1ca0 100644 --- a/include/subcommand_stat.h +++ b/include/subcommand_stat.h @@ -213,8 +213,11 @@ private: std::string controlCmd_ = {}; bool ProcessControl(); bool CreateFifoServer(); + bool HandleParentProcess(pid_t pid); + bool HandleChildProcess(); bool ParseControlCmd(const std::string& cmd); void CloseClientThread(); + void HandleCommunicationError(int fd, pid_t pid, const std::string& reply); }; bool RegisterSubCommandStat(void); diff --git a/src/perf_events.cpp b/src/perf_events.cpp index 5f47bd5edbf35868388f723aa3d95c07b4a4ac49..5ddf52bbfa53139637d4aca92ccf2606fc0bd212 100644 --- a/src/perf_events.cpp +++ b/src/perf_events.cpp @@ -1791,7 +1791,7 @@ void PerfEvents::ReadRecordFromBuf() HLOGD("read all records from buffer"); } -bool PerfEvents::HaveTargetsExit(const std::chrono::steady_clock::time_point &startTime) +bool PerfEvents::HaveTargetsExit(const SteadyTimePoint &startTime) { if (systemTarget_) { return false; @@ -1865,81 +1865,106 @@ void PerfEvents::RecordLoop() } } +void PerfEvents::HandleReporting(const SteadyTimePoint& startTime, + const SteadyTimePoint& endTime, + SteadyTimePoint& nextReportTime, + const SteadyTimePoint& thisTime, + __u64& durationInSec) +{ + if (timeReport_ == milliseconds::zero()) { + return; + } + + if (thisTime < nextReportTime) { + return; + } + + const auto usedTimeMsTick = duration_cast(thisTime - startTime); + const auto lefTimeMsTick = duration_cast(endTime - thisTime); + const uint64_t usedMs = static_cast(usedTimeMsTick.count()); + const uint64_t leftMs = static_cast(lefTimeMsTick.count()); + durationInSec = usedMs; + + if (reportPtr_ == nullptr) { + printf("\nReport at %" PRIu64 " ms (%" PRIu64 " ms left):\n", usedMs, leftMs); + } else { + fprintf(reportPtr_, "\nReport at %" PRIu64 " ms (%" PRIu64 " ms left):\n", usedMs, leftMs); + } + + nextReportTime += timeReport_; + StatReport(usedMs); +} + +bool PerfEvents::CheckExitConditions(const SteadyTimePoint& startTime, + const SteadyTimePoint& endTime, + const SteadyTimePoint& thisTime, + __u64& durationInSec) +{ + if (HaveTargetsExit(startTime)) { + return true; + } + + if (thisTime < endTime) { + return false; + } + + const auto usedTimeMsTick = duration_cast(thisTime - startTime); + const uint64_t usedMs = static_cast(usedTimeMsTick.count()); + durationInSec = usedMs; + + if (reportPtr_ == nullptr) { + printf("Timeout exit (total %" PRIu64 " ms)\n", usedMs); + } else { + fprintf(reportPtr_, "Timeout exit (total %" PRIu64 " ms)\n", usedMs); + } + + if (trackedCommand_) { + trackedCommand_->Stop(); + } + return true; +} + +void PerfEvents::HandleLoopExit(const SteadyTimePoint& startTime, __u64 durationInSec) +{ + const auto usedTimeMsTick = duration_cast(steady_clock::now() - startTime); + const uint64_t usedMs = static_cast(usedTimeMsTick.count()); + + if (!g_trackRunning) { + printf("User interrupt exit (total %" PRIu64 " ms)\n", usedMs); + } + + if (timeReport_ == milliseconds::zero()) { + StatReport(durationInSec); + } +} + void PerfEvents::StatLoop() { - // calc the time const auto startTime = steady_clock::now(); const auto endTime = startTime + timeOut_; auto nextReportTime = startTime + timeReport_; - milliseconds usedTimeMsTick {}; - __u64 durationInSec = 0; int64_t thresholdTimeInMs = 2 * HUNDREDS; + __u64 durationInSec = 0; while (g_trackRunning) { - // time check point const auto thisTime = steady_clock::now(); - if (timeReport_ != milliseconds::zero()) { - // stat cmd - if (thisTime >= nextReportTime) { - // only for log or debug? - usedTimeMsTick = duration_cast(thisTime - startTime); - durationInSec = usedTimeMsTick.count(); - auto lefTimeMsTick = duration_cast(endTime - thisTime); - if (reportPtr_ == nullptr) { - printf("\nReport at %" PRIu64 " ms (%" PRIu64 " ms left):\n", - static_cast(usedTimeMsTick.count()), - static_cast(lefTimeMsTick.count())); - } else { - fprintf(reportPtr_, "\nReport at %" PRIu64 " ms (%" PRIu64 " ms left):\n", - static_cast(usedTimeMsTick.count()), - static_cast(lefTimeMsTick.count())); - } - // end of comments - nextReportTime += timeReport_; - StatReport(durationInSec); - } - } - - if (HaveTargetsExit(startTime)) { + HandleReporting(startTime, endTime, nextReportTime, thisTime, durationInSec); + if (CheckExitConditions(startTime, endTime, thisTime, durationInSec)) { break; } - if (thisTime >= endTime) { - usedTimeMsTick = duration_cast(thisTime - startTime); - durationInSec = usedTimeMsTick.count(); - if (reportPtr_ == nullptr) { - printf("Timeout exit (total %" PRIu64 " ms)\n", static_cast(usedTimeMsTick.count())); - } else { - fprintf(reportPtr_, "Timeout exit (total %" PRIu64 " ms)\n", - static_cast(usedTimeMsTick.count())); - } - if (trackedCommand_) { - trackedCommand_->Stop(); + uint64_t sleepUs = 2 * HUNDREDS; // 200us + if (timeReport_ == milliseconds::zero() && (timeOut_.count() * THOUSANDS > thresholdTimeInMs)) { + const auto leftTimeMs = duration_cast(endTime - thisTime); + if (leftTimeMs.count() > thresholdTimeInMs) { + sleepUs = HUNDREDS * THOUSANDS; // 100ms } - break; } - // lefttime > 200ms sleep 100ms, else sleep 200us - uint64_t defaultSleepUs = 2 * HUNDREDS; // 200us - if (timeReport_ == milliseconds::zero() - && (timeOut_.count() * THOUSANDS) > thresholdTimeInMs) { - milliseconds leftTimeMsTmp = duration_cast(endTime - thisTime); - if (leftTimeMsTmp.count() > thresholdTimeInMs) { - defaultSleepUs = HUNDREDS * THOUSANDS; // 100ms - } - } - std::this_thread::sleep_for(microseconds(defaultSleepUs)); + std::this_thread::sleep_for(microseconds(sleepUs)); } - if (!g_trackRunning) { - // for user interrupt situation, print time statistic - usedTimeMsTick = duration_cast(steady_clock::now() - startTime); - printf("User interrupt exit (total %" PRIu64 " ms)\n", static_cast(usedTimeMsTick.count())); - } - - if (timeReport_ == milliseconds::zero()) { - StatReport(durationInSec); - } + HandleLoopExit(startTime, durationInSec); } const std::string PerfEvents::GetTypeName(const perf_type_id type_id) diff --git a/src/subcommand_stat.cpp b/src/subcommand_stat.cpp index bfbdc9eb146ff7fb815d30505579894355ab7b09..b1f497112a9ce868b07313cdcfca627b85d6bf30 100644 --- a/src/subcommand_stat.cpp +++ b/src/subcommand_stat.cpp @@ -708,77 +708,84 @@ void SubCommandStat::SetPerfEvent() bool SubCommandStat::CreateFifoServer() { - char errInfo[ERRINFOLEN] = { 0 }; if (!perfPipe_.CreateFifoFile()) { return false; } CheckIpcBeforeFork(); + char errInfo[ERRINFOLEN] = { 0 }; pid_t pid = fork(); + strerror_r(errno, errInfo, ERRINFOLEN); allowIpc_ = true; + CHECK_TRUE(pid != -1, false, 1, "[CreateFifoServer] fork failed. %d:%s", errno, errInfo); + return (pid == 0) ? HandleChildProcess() : HandleParentProcess(pid); +} - if (pid == -1) { - strerror_r(errno, errInfo, ERRINFOLEN); - HLOGE("fork failed. %d:%s", errno, errInfo); +bool SubCommandStat::HandleChildProcess() +{ + char errInfo[ERRINFOLEN] = {0}; + close(STDIN_FILENO); + close(STDERR_FILENO); + isFifoServer_ = true; + + clientPipeOutput_ = open(fifoFileS2C_.c_str(), O_WRONLY); + strerror_r(errno, errInfo, ERRINFOLEN); + CHECK_TRUE(clientPipeOutput_ != -1, false, LOG_TYPE_WITH_HILOG, + "[HandleChildProcess] open fifo file(%s) failed. %d:%s", fifoFileS2C_.c_str(), errno, errInfo); + + nullFd_ = open("/dev/null", O_WRONLY); + (void)dup2(nullFd_, STDOUT_FILENO); // redirect stdout to /dev/null + + std::string err = OHOS::Developtools::HiPerf::HandleAppInfo(appPackage_, inputPidTidArgs_); + if (!err.empty()) { + ClientCommandResponse(err); return false; - } else if (pid == 0) { // child process - close(STDIN_FILENO); - close(STDERR_FILENO); - isFifoServer_ = true; - clientPipeOutput_ = open(fifoFileS2C_.c_str(), O_WRONLY); - if (clientPipeOutput_ == -1) { - strerror_r(errno, errInfo, ERRINFOLEN); - HLOGE("open fifo file(%s) failed. %d:%s", fifoFileS2C_.c_str(), errno, errInfo); - HIPERF_HILOGE(MODULE_DEFAULT, "open fifo file(%{public}s) failed. %d:%s", - fifoFileS2C_.c_str(), errno, errInfo); - return false; - } - nullFd_ = open("/dev/null", O_WRONLY); - (void)dup2(nullFd_, STDOUT_FILENO); // redirect stdout to /dev/null - std::string err = OHOS::Developtools::HiPerf::HandleAppInfo(appPackage_, inputPidTidArgs_); - if (!err.empty()) { - ClientCommandResponse(err); - return false; - } - } else { // parent process - isFifoClient_ = true; - int fd = open(fifoFileS2C_.c_str(), O_RDONLY | O_NONBLOCK); - std::string reply = ""; - if (fd != -1) { - perfPipe_.WaitFifoReply(fd, CONTROL_WAITREPY_TIMEOUT, reply); - } - if (fd == -1 || reply != HiperfClient::ReplyOK) { - if (reply != HiperfClient::ReplyOK) { - printf("%s", reply.c_str()); - HLOGE("reply is %s", reply.c_str()); - HIPERF_HILOGE(MODULE_DEFAULT, "reply is %{public}s", reply.c_str()); - } - HLOGI("fd is %d", fd); - HIPERF_HILOGI(MODULE_DEFAULT, "fd is %{public}d", fd); - close(fd); - if (kill(pid, SIGTERM) != 0) { - HLOGE("Failed to send SIGTERM: %d", pid); - HIPERF_HILOGE(MODULE_DEFAULT, "Failed to send SIGTERM to pid: %{public}d", pid); - } - // wait for process exit - if (waitpid(pid, nullptr, 0) == -1) { - HLOGE("Failed to wait for pid: %d", pid); - HIPERF_HILOGE(MODULE_DEFAULT, "Failed to wait for pid: %{public}d", pid); - } - remove(fifoFileC2S_.c_str()); - remove(fifoFileS2C_.c_str()); - strerror_r(errno, errInfo, ERRINFOLEN); - printf("create control hiperf counting failed.\n"); - HLOGI("errno is %d:%s", errno, errInfo); - HIPERF_HILOGI(MODULE_DEFAULT, "errno is %{public}d:%{public}s", errno, errInfo); - return false; - } - close(fd); - printf("%s control hiperf counting success.\n", restart_ ? "start" : "create"); - printf("stat result will saved in %s.\n", outputFilename_ .c_str()); } + + return true; +} + +bool SubCommandStat::HandleParentProcess(pid_t pid) +{ + isFifoClient_ = true; + int fd = open(fifoFileS2C_.c_str(), O_RDONLY | O_NONBLOCK); + std::string reply = ""; + if (fd != -1) { + perfPipe_.WaitFifoReply(fd, CONTROL_WAITREPY_TIMEOUT, reply); + } + + if (fd == -1 || reply != HiperfClient::ReplyOK) { + HandleCommunicationError(fd, pid, reply); + return false; + } + + close(fd); + printf("%s control hiperf counting success.\n", restart_ ? "start" : "create"); + printf("stat result will saved in %s.\n", outputFilename_.c_str()); return true; } +void SubCommandStat::HandleCommunicationError(int fd, pid_t pid, const std::string& reply) +{ + if (reply != HiperfClient::ReplyOK) { + printf("%s", reply.c_str()); + HLOGE("reply is %s", reply.c_str()); + HIPERF_HILOGE(MODULE_DEFAULT, "reply is %{public}s", reply.c_str()); + } + HLOGI("fd is %d", fd); + HIPERF_HILOGI(MODULE_DEFAULT, "fd is %{public}d", fd); + close(fd); + if (kill(pid, SIGTERM) != 0) { + HLOGE("Failed to send SIGTERM to %d", pid); + HIPERF_HILOGE(MODULE_DEFAULT, "Failed to send SIGTERM to %{public}d", pid); + } + if (waitpid(pid, nullptr, 0) == -1) { + HLOGE("Failed to wait for pid %d", pid); + HIPERF_HILOGE(MODULE_DEFAULT, "Failed to wait for pid %{public}d", pid); + } + perfPipe_.RemoveFifoFile(); + printf("create control hiperf counting failed.\n"); +} + bool SubCommandStat::ClientCommandResponse(const bool response) { return ClientCommandResponse(response ? HiperfClient::ReplyOK : HiperfClient::ReplyFAIL); @@ -1094,57 +1101,35 @@ bool SubCommandStat::CheckSelectCpuPidOption() bool SubCommandStat::CheckOptions(const std::vector &pids) { - if (targetSystemWide_) { - if (!pids.empty() || !selectTids_.empty()) { - printf("You cannot specify -a and -t/-p at the same time\n"); - return false; - } - if (!appPackage_.empty()) { - printf("You cannot specify -a and --app at the same time\n"); - return false; - } - } - if (!appPackage_.empty() && (!pids.empty() || !selectTids_.empty())) { - printf("You cannot specify --app and -t/-p at the same time\n"); - return false; - } - if (!targetSystemWide_ && trackedCommand_.empty() && pids.empty() && appPackage_.empty() - && selectTids_.empty()) { - printf("You need to set the -p option or --app option.\n"); - return false; - } - if (targetSystemWide_ && !trackedCommand_.empty()) { - printf("You cannot specify -a and a cmd at the same time\n"); - return false; - } - if (!trackedCommand_.empty()) { - if (!pids.empty() || !selectTids_.empty()) { - printf("You cannot specify a cmd and -t/-p at the same time\n"); - return false; - } - if (!appPackage_.empty()) { - printf("You cannot specify a cmd and --app at the same time\n"); - return false; - } - if (!IsRoot()) { - printf("%s options needs root privilege, please check usage\n", - VectorToString(trackedCommand_).c_str()); - return false; - } - } - if (checkAppMs_ < MIN_CHECK_APP_MS || checkAppMs_ > MAX_CHECK_APP_MS) { - printf("Invalid --chkms value '%d', the milliseconds should be in %d~%d \n", checkAppMs_, - MIN_CHECK_APP_MS, MAX_CHECK_APP_MS); - return false; - } - if (timeStopSec_ < 0) { - printf("monitoring duration should be positive but %f is given\n", timeStopSec_); - return false; - } - if (timeReportMs_ < 0) { - printf("print interval should be non-negative but %d is given\n", timeReportMs_); - return false; - } + CHECK_TRUE(!(targetSystemWide_ && (!pids.empty() || !selectTids_.empty())), false, LOG_TYPE_PRINTF, + "You cannot specify -a and -t/-p at the same time\n"); + + CHECK_TRUE(!(targetSystemWide_ && !appPackage_.empty()), false, LOG_TYPE_PRINTF, + "You cannot specify -a and --app at the same time\n"); + + CHECK_TRUE(!(!targetSystemWide_ && trackedCommand_.empty() && + pids.empty() && appPackage_.empty() && selectTids_.empty()), false, LOG_TYPE_PRINTF, + "You need to set the -p option or --app option.\n"); + + CHECK_TRUE(!(targetSystemWide_ && !trackedCommand_.empty()), false, LOG_TYPE_PRINTF, + "You cannot specify -a and a cmd at the same time\n"); + + CHECK_TRUE(!(!trackedCommand_.empty() && !appPackage_.empty()), false, LOG_TYPE_PRINTF, + "You cannot specify a cmd and --app at the same time\n"); + + CHECK_TRUE(!(!trackedCommand_.empty() && !IsRoot()), false, LOG_TYPE_PRINTF, + "%s options needs root privilege, please check usage\n", + VectorToString(trackedCommand_).c_str()); + + CHECK_TRUE(!(checkAppMs_ < MIN_CHECK_APP_MS || checkAppMs_ > MAX_CHECK_APP_MS), false, LOG_TYPE_PRINTF, + "Invalid --chkms value '%d', the milliseconds should be in %d~%d \n", checkAppMs_, + MIN_CHECK_APP_MS, MAX_CHECK_APP_MS); + + CHECK_TRUE(!(timeStopSec_ < 0), false, LOG_TYPE_PRINTF, + "monitoring duration should be positive but %f is given\n", timeStopSec_); + + CHECK_TRUE(!(timeReportMs_ < 0), false, LOG_TYPE_PRINTF, + "print interval should be non-negative but %d is given\n", timeReportMs_); return true; }