openharmony/resourceschedule_ffrt
1
0
Fork 0
mirror of https://gitee.com/openharmony/resourceschedule_ffrt synced 2024-12-02 10:26:58 +00:00
Code Issues Actions Packages Projects Releases Wiki Activity

task trace record

Browse Source 
Signed-off-by: linyu <yulin24@huawei.com>
This commit is contained in:
linyu 2024-08-10 18:15:24 +08:00
parent 33119b758a
commit d84feb6ab7
31 changed files with 946 additions and 169 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

3
BUILD.gn
View File

@ -57,6 +57,7 @@ config("ffrt_config") {
"FFRT_OH_TRACE_ENABLE",
"FFRT_TRACE_LEVEL=1",
"QOS_FRAME_RTG",
"FFRT_TRACE_RECORD_LEVEL=1",
]
#ffrt_release_defines = [
@ -90,6 +91,7 @@ config("ffrt_inner_config") {
"src",
"src/dfx/log",
"src/dfx/trace",
"src/dfx/trace_record",
"src/sched",
]
@ -119,6 +121,7 @@ ohos_shared_library("libffrt") {
"src/dfx/dump/dump.cpp",
"src/dfx/log/ffrt_log.cpp",
"src/dfx/trace/ffrt_trace.cpp",
"src/dfx/trace_record/ffrt_trace_record.cpp",
"src/dfx/watchdog/watchdog_util.cpp",
"src/dm/dependence_manager.cpp",
"src/dm/sdependence_manager.cpp",

3
CMakeLists.txt
View File

@ -92,6 +92,9 @@ if(FFRT_BBOX_ENABLE STREQUAL ON)
add_definitions("-DFFRT_BBOX_ENABLE")
endif()
# ffrt trace record level
add_definitions("-DFFRT_TRACE_RECORD_LEVEL=1")
# libffrt.so
add_subdirectory(src)
LINK_DIRECTORIES(${FFRT_BUILD_PATH}/src)

1
interfaces/inner_api/c/ffrt_dump.h
View File

@ -19,6 +19,7 @@
typedef enum {
DUMP_INFO_ALL = 0,
DUMP_TASK_STATISTIC_INFO
} ffrt_dump_cmd_t;
typedef void(*ffrt_task_timeout_cb)(uint64_t gid, const char *msg, uint32_t size);

1
src/CMakeLists.txt
View File

@ -15,6 +15,7 @@ file(GLOB_RECURSE FFRT_SRC_LIST
"${FFRT_CODE_PATH}/tm/*.cpp"
"${FFRT_CODE_PATH}/dm/*.cpp"
"${FFRT_CODE_PATH}/dfx/bbox/bbox.cpp"
"${FFRT_CODE_PATH}/dfx/trace_record/ffrt_trace_record.cpp"
"${FFRT_CODE_PATH}/dfx/log/ffrt_log.cpp"
"${FFRT_CODE_PATH}/dfx/log/${FFRT_LOG_PLAT}/log_base.cpp"
"${FFRT_CODE_PATH}/dfx/dump/dump.cpp"

7
src/core/task.cpp
View File

@ -26,6 +26,7 @@
#include "eu/osattr_manager.h"
#include "eu/worker_thread.h"
#include "dfx/log/ffrt_log_api.h"
#include "dfx/trace_record/ffrt_trace_record.h"
#include "dfx/watchdog/watchdog_util.h"
#include "eu/func_manager.h"
#include "util/ffrt_facade.h"
@ -574,7 +575,11 @@ int ffrt_executor_task_cancel(ffrt_executor_task_t* task, const ffrt_qos_t qos)
ffrt::LinkedList* node = reinterpret_cast<ffrt::LinkedList *>(&task->wq);
ffrt::FFRTFacade::GetDMInstance();
ffrt::FFRTScheduler* sch = ffrt::FFRTScheduler::Instance();
return static_cast<int>(sch->RemoveNode(node, _qos));
bool ret = sch->RemoveNode(node, _qos);
if (ret) {
ffrt::FFRTTraceRecord::TaskCancel<ffrt_uv_task>(qos);
}
return static_cast<int>(ret);
}
API_ATTRIBUTE((visibility("default")))

5
src/core/task_io.cpp
View File

@ -33,11 +33,6 @@ static void work_finish_callable(IOTaskExecutor* task)
{
task->status = ExecTaskStatus::ET_FINISH;
task->work.destroy(task->work.data);
#ifdef FFRT_BBOX_ENABLE
TaskDoneCounterInc();
#endif
delete task;
}

115
src/dfx/bbox/bbox.cpp
View File

@ -23,11 +23,13 @@
#include <sstream>
#include <vector>
#include "dfx/log/ffrt_log_api.h"
#include "dfx/trace_record/ffrt_trace_record.h"
#include "sched/scheduler.h"
#include "tm/queue_task.h"
#include "queue/queue_monitor.h"
#include "tm/task_factory.h"
#include "eu/cpuworker_manager.h"
#include "util/time_format.h"
#ifdef OHOS_STANDARD_SYSTEM
#include "dfx/bbox/fault_logger_fd_manager.h"
#endif
@ -35,12 +37,6 @@
using namespace ffrt;
static std::atomic<unsigned int> g_taskSubmitCounter(0);
static std::atomic<unsigned int> g_taskDoneCounter(0);
static std::atomic<unsigned int> g_taskEnQueueCounter(0);
static std::atomic<unsigned int> g_taskRunCounter(0);
static std::atomic<unsigned int> g_taskSwitchCounter(0);
static std::atomic<unsigned int> g_taskFinishCounter(0);
static std::atomic<unsigned int> g_taskPendingCounter(0);
static std::atomic<unsigned int> g_taskWakeCounter(0);
static CPUEUTask* g_cur_task;
@ -51,48 +47,16 @@ std::condition_variable bbox_handle_end;
static struct sigaction s_oldSa[SIGSYS + 1]; // SIGSYS = 31
void TaskSubmitCounterInc(void)
{
++g_taskSubmitCounter;
}
void TaskWakeCounterInc(void)
{
++g_taskWakeCounter;
}
void TaskDoneCounterInc(void)
{
++g_taskDoneCounter;
}
void TaskEnQueuCounterInc(void)
{
++g_taskEnQueueCounter;
}
void TaskRunCounterInc(void)
{
++g_taskRunCounter;
}
void TaskSwitchCounterInc(void)
{
++g_taskSwitchCounter;
}
void TaskFinishCounterInc(void)
{
++g_taskFinishCounter;
}
void TaskPendingCounterInc(void)
{
++g_taskPendingCounter;
}
static inline void SaveCurrent()
{
FFRT_BBOX_LOG("<<<=== current status ===>>>");
@ -105,21 +69,23 @@ static inline void SaveCurrent()
}
}
#if (FFRT_TRACE_RECORD_LEVEL >= FFRT_TRACE_RECORD_LEVEL_2)
static inline void SaveTaskCounter()
{
FFRT_BBOX_LOG("<<<=== task counter ===>>>");
FFRT_BBOX_LOG("FFRT BBOX TaskSubmitCounter:%u TaskEnQueueCounter:%u TaskDoneCounter:%u",
g_taskSubmitCounter.load(), g_taskEnQueueCounter.load(), g_taskDoneCounter.load());
FFRT_BBOX_LOG("FFRT BBOX TaskRunCounter:%u TaskSwitchCounter:%u TaskFinishCounter:%u", g_taskRunCounter.load(),
g_taskSwitchCounter.load(), g_taskFinishCounter.load());
FFRTTraceRecord::GetSubmitCount(), FFRTTraceRecord::GetEnqueueCount(), FFRTTraceRecord::GetDoneCount());
FFRT_BBOX_LOG("FFRT BBOX TaskRunCounter:%u TaskSwitchCounter:%u TaskFinishCounter:%u",
FFRTTraceRecord::GetRunCount(), FFRTTraceRecord::GetCoSwitchCount(), FFRTTraceRecord::GetFinishCount());
FFRT_BBOX_LOG("FFRT BBOX TaskWakeCounterInc:%u, TaskPendingCounter:%u",
g_taskWakeCounter.load(), g_taskPendingCounter.load());
if (g_taskSwitchCounter.load() + g_taskFinishCounter.load() == g_taskRunCounter.load()) {
if (FFRTTraceRecord::GetCoSwitchCount() + FFRTTraceRecord::GetFinishCount() == FFRTTraceRecord::GetRunCount()) {
FFRT_BBOX_LOG("TaskRunCounter equals TaskSwitchCounter + TaskFinishCounter");
} else {
FFRT_BBOX_LOG("TaskRunCounter is not equal to TaskSwitchCounter + TaskFinishCounter");
}
}
#endif
static inline void SaveWorkerStatus()
{
@ -272,13 +238,7 @@ unsigned int GetBboxEnableState(void)
bool FFRTIsWork()
{
if (g_taskSubmitCounter.load() == 0) {
return false;
} else if (g_taskSubmitCounter.load() == g_taskDoneCounter.load()) {
return false;
}
return true;
return FFRTTraceRecord::FfrtBeUsed();
}
void SaveTheBbox()
@ -294,7 +254,9 @@ void SaveTheBbox()
#endif
FFRT_BBOX_LOG("<<<=== ffrt black box(BBOX) start ===>>>");
SaveCurrent();
#if (FFRT_TRACE_RECORD_LEVEL >= FFRT_TRACE_RECORD_LEVEL_2)
SaveTaskCounter();
#endif
SaveWorkerStatus();
SaveReadyQueueStatus();
SaveNormalTaskStatus();
@ -407,23 +369,50 @@ __attribute__((destructor)) static void BBoxDeInit()
}
#ifdef FFRT_CO_BACKTRACE_OH_ENABLE
#if (FFRT_TRACE_RECORD_LEVEL >= FFRT_TRACE_RECORD_LEVEL_2)
std::string SaveTaskCounterInfo(void)
{
std::ostringstream ss;
ss << " |-> task counter" << std::endl;
ss << " FFRT BBOX TaskSubmitCounter:" << g_taskSubmitCounter.load() << " TaskEnQueueCounter:"
<< g_taskEnQueueCounter.load() << " TaskDoneCounter:" << g_taskDoneCounter.load() << std::endl;
ss << " TaskSubmitCounter:" << FFRTTraceRecord::GetSubmitCount() << " TaskEnQueueCounter:"
<< FFRTTraceRecord::GetEnqueueCount() << " TaskDoneCounter:" << FFRTTraceRecord::GetDoneCount() << std::endl;
ss << " FFRT BBOX TaskRunCounter:" << g_taskRunCounter.load() << " TaskSwitchCounter:"
<< g_taskSwitchCounter.load() << " TaskFinishCounter:" << g_taskFinishCounter.load() << std::endl;
ss << " TaskRunCounter:" << FFRTTraceRecord::GetRunCount() << " TaskSwitchCounter:"
<< FFRTTraceRecord::GetCoSwitchCount() << " TaskFinishCounter:" << FFRTTraceRecord::GetFinishCount()
<< std::endl;
if (g_taskSwitchCounter.load() + g_taskFinishCounter.load() == g_taskRunCounter.load()) {
if (FFRTTraceRecord::GetCoSwitchCount() + FFRTTraceRecord::GetFinishCount() == FFRTTraceRecord::GetRunCount()) {
ss << " TaskRunCounter equals TaskSwitchCounter + TaskFinishCounter" << std::endl;
} else {
ss << " TaskRunCounter is not equal to TaskSwitchCounter + TaskFinishCounter" << std::endl;
}
return ss.str();
}
#endif // FFRT_TRACE_RECORD_LEVEL >= FFRT_TRACE_RECORD_LEVEL_2
static inline std::string FormatDateString(uint64_t timeStamp)
{
#if defined(__aarch64__)
return FormatDateString4CntCt(timeStamp, microsecond);
#else
return FormatDateString4SteadyClock(timeStamp, microsecond);
#endif
}
void AppendTaskInfo(std::ostringstream& oss, TaskBase* task)
{
#if (FFRT_TRACE_RECORD_LEVEL >= FFRT_TRACE_RECORD_LEVEL_1)
if (task->fromTid) {
oss << " fromTid " << task->fromTid;
}
if (task->createTime) {
oss << " createTime " << FormatDateString(task->createTime);
}
if (task->executeTime) {
oss << " executeTime " << FormatDateString(task->executeTime);
}
#endif
}
std::string SaveWorkerStatusInfo(void)
{
@ -446,13 +435,15 @@ std::string SaveWorkerStatusInfo(void)
}
if (t->type == ffrt_normal_task || t->type == ffrt_queue_task) {
ss << " qos " << i << ": worker tid " << thread.first->Id()
<< " is running, task id " << t->gid << " name " << t->label.c_str() << std::endl;
<< " is running, task id " << t->gid << " name " << t->label.c_str();
AppendTaskInfo(ss, t);
ss << std::endl;
}
}
if (tidArr.size() == 0) {
continue;
}
oss << " qos " << i << ": worker num:" << tidArr.size() << "tid:";
oss << " qos " << i << ": worker num:" << tidArr.size() << " tid:";
std::for_each(tidArr.begin(), tidArr.end(), [&](const int &t) {
if (&t == &tidArr.back()) {
oss << t;
@ -489,7 +480,9 @@ std::string SaveReadyQueueStatusInfo()
}
if (t->type == ffrt_normal_task || t->type == ffrt_queue_task) {
ss << " qos " << i << ": ready queue task <" << j << "/" << nt << "> task id "
<< t->gid << " name " << t->label.c_str() << std::endl;
<< t->gid << " name " << t->label.c_str();
AppendTaskInfo(ss, t);
ss << std::endl;
}
FFRTScheduler::Instance()->GetScheduler(i).WakeupTask(t);
@ -521,7 +514,9 @@ std::string SaveNormalTaskStatusInfo(void)
ss.str("");
if (t->type == ffrt_normal_task) {
ss << " <" << idx++ << "/" << tmp.size() << ">" << "stack: task id " << t->gid << ",qos "
<< t->qos() << ",name " << t->label.c_str() << std::endl;
<< t->qos() << ",name " << t->label.c_str();
AppendTaskInfo(ss, t);
ss << std::endl;
}
ffrtStackInfo += ss.str();
if (t->coRoutine && (t->coRoutine->status.load() == static_cast<int>(CoStatus::CO_NOT_FINISH))) {
@ -570,7 +565,9 @@ std::string SaveQueueTaskStatusInfo()
ss.str("");
if (t->type == ffrt_queue_task) {
ss << "<" << idx++ << "/" << tmp.size() << ">" << "id" << t->gid << "qos"
<< t->GetQos() << "name" << t->label.c_str() << std::endl;
<< t->GetQos() << "name" << t->label.c_str();
AppendTaskInfo(ss, t);
ss << std::endl;
}
ffrtStackInfo += ss.str();
if (t->coRoutine && (t->coRoutine->status.load() == static_cast<int>(CoStatus::CO_NOT_FINISH))) {

8
src/dfx/bbox/bbox.h
View File

@ -18,12 +18,6 @@
#ifdef FFRT_CO_BACKTRACE_OH_ENABLE
#include <string>
#endif
extern void TaskSubmitCounterInc(void);
extern void TaskDoneCounterInc(void);
extern void TaskEnQueuCounterInc(void);
extern void TaskRunCounterInc(void);
extern void TaskSwitchCounterInc(void);
extern void TaskFinishCounterInc(void);
extern void TaskWakeCounterInc(void);
extern void TaskPendingCounterInc(void);
extern unsigned int GetBboxEnableState(void);
@ -42,7 +36,9 @@ static inline void BboxCheckAndFreeze(void)
bool FFRTIsWork(void);
#ifdef FFRT_CO_BACKTRACE_OH_ENABLE
#if (FFRT_TRACE_RECORD_LEVEL >= FFRT_TRACE_RECORD_LEVEL_2)
std::string SaveTaskCounterInfo(void);
#endif
std::string SaveWorkerStatusInfo(void);
std::string SaveReadyQueueStatusInfo(void);
std::string SaveNormalTaskStatusInfo(void);

16
src/dfx/dump/dump.cpp
View File

@ -23,6 +23,7 @@
#include "dfx/bbox/bbox.h"
#include "internal_inc/osal.h"
#include "dfx/log/ffrt_log_api.h"
#include "dfx/trace_record/ffrt_trace_record.h"
#include "dump.h"
#ifdef FFRT_CO_BACKTRACE_OH_ENABLE
@ -115,7 +116,9 @@ int dump_info_all(char *buf, uint32_t len)
if (FFRTIsWork()) {
std::string dumpInfo;
dumpInfo += "|-> Launcher proc ffrt, pid:" + std::to_string(GetPid()) + "\n";
#if (FFRT_TRACE_RECORD_LEVEL >= FFRT_TRACE_RECORD_LEVEL_2)
dumpInfo += SaveTaskCounterInfo();
#endif
dumpInfo += SaveWorkerStatusInfo();
dumpInfo += SaveReadyQueueStatusInfo();
dumpInfo += SaveNormalTaskStatusInfo();
@ -135,16 +138,21 @@ int dump_info_all(char *buf, uint32_t len)
API_ATTRIBUTE((visibility("default")))
int ffrt_dump(ffrt_dump_cmd_t cmd, char *buf, uint32_t len)
{
#ifdef FFRT_CO_BACKTRACE_OH_ENABLE
switch (cmd) {
case ffrt_dump_cmd_t::DUMP_INFO_ALL: {
case DUMP_INFO_ALL: {
return dump_info_all(buf, len);
}
case DUMP_TASK_STATISTIC_INFO: {
#if (FFRT_TRACE_RECORD_LEVEL >= FFRT_TRACE_RECORD_LEVEL_2)
return ffrt::FFRTTraceRecord::StatisticInfoDump(buf, len);
#else
return -1;
#endif
}
default: {
FFRT_LOGE("ffr_dump unsupport cmd[%d]", cmd);
FFRT_LOGE("ffrt_dump unsupport cmd[%d]", cmd);
}
}
#endif // FFRT_CO_BACKTRACE_OH_ENABLE
return -1;
}

207
src/dfx/trace_record/ffrt_trace_record.cpp Normal file
View File

@ -0,0 +1,207 @@
/*
* Copyright (c) 2023 Huawei Device Co., Ltd.
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
#include "dfx/trace_record/ffrt_trace_record.h"
#include <securec.h>
#include <sstream>
#include <fcntl.h>
#include <iomanip>
#include <sys/syscall.h>
#include <unistd.h>
#include "dfx/bbox/bbox.h"
namespace ffrt {
const int COLUMN_WIDTH_3 = 3;
const int COLUMN_WIDTH_9 = 9;
const int COLUMN_WIDTH_10 = 10;
const int COLUMN_WIDTH_12 = 12;
const int COLUMN_WIDTH_13 = 13;
const int COLUMN_WIDTH_16 = 16;
const int COLUMN_WIDTH_18 = 18;
const int COLUMN_WIDTH_19 = 19;
const int COLUMN_WIDTH_22 = 22;
bool FFRTTraceRecord::ffrt_be_used_ = false;
int FFRTTraceRecord::g_recordMaxWorkerNumber_[QoS::MaxNum()] = {};
ffrt_record_task_counter_t FFRTTraceRecord::g_recordTaskCounter_[FFRTTraceRecord::TASK_TYPE_NUM][QoS::MaxNum()] = {};
ffrt_record_task_time_t FFRTTraceRecord::g_recordTaskTime_[FFRTTraceRecord::TASK_TYPE_NUM][QoS::MaxNum()] = {};
#if (FFRT_TRACE_RECORD_LEVEL >= FFRT_TRACE_RECORD_LEVEL_2)
void FFRTTraceRecord::DumpNormalTaskStatisticInfo(std::ostringstream& oss)
{
for (size_t i = 0; i < QoS::MaxNum(); i++) {
if (g_recordTaskCounter_[ffrt_normal_task][i].submitCounter <= 0) {
continue;
}
oss << std::setw(COLUMN_WIDTH_3) << i
<< std::setw(COLUMN_WIDTH_9) << "normal"
<< std::setw(COLUMN_WIDTH_10) << g_recordTaskCounter_[ffrt_normal_task][i].submitCounter
<< std::setw(COLUMN_WIDTH_10) << g_recordTaskCounter_[ffrt_normal_task][i].enqueueCounter
<< std::setw(COLUMN_WIDTH_12) << g_recordTaskCounter_[ffrt_normal_task][i].coSwitchCounter
<< std::setw(COLUMN_WIDTH_10) << g_recordTaskCounter_[ffrt_normal_task][i].doneCounter
<< std::setw(COLUMN_WIDTH_10) << g_recordTaskCounter_[ffrt_normal_task][i].doneCounter;
#if (FFRT_TRACE_RECORD_LEVEL >= FFRT_TRACE_RECORD_LEVEL_3)
unsigned int doneCount = g_recordTaskCounter_[ffrt_normal_task][i].doneCounter.load();
if (doneCount > 0) {
oss << std::setw(COLUMN_WIDTH_13) << g_recordMaxWorkerNumber_[i]
<< std::setw(COLUMN_WIDTH_16) << g_recordTaskTime_[ffrt_normal_task][i].maxWaitTime
<< std::setw(COLUMN_WIDTH_19) << g_recordTaskTime_[ffrt_normal_task][i].maxRunDuration
<< std::setw(COLUMN_WIDTH_16) << (g_recordTaskTime_[ffrt_normal_task][i].waitTime/doneCount)
<< std::setw(COLUMN_WIDTH_19) << (g_recordTaskTime_[ffrt_normal_task][i].runDuration/doneCount)
<< std::setw(COLUMN_WIDTH_18) << g_recordTaskTime_[ffrt_normal_task][i].waitTime
<< std::setw(COLUMN_WIDTH_22) << g_recordTaskTime_[ffrt_normal_task][i].runDuration;
}
#endif
oss << "\n";
}
}
void FFRTTraceRecord::DumpQueueTaskStatisticInfo(std::ostringstream& oss)
{
for (size_t i = 0; i < QoS::MaxNum(); i++) {
if (g_recordTaskCounter_[ffrt_queue_task][i].submitCounter <= 0) {
continue;
}
oss << std::setw(COLUMN_WIDTH_3) << i
<< std::setw(COLUMN_WIDTH_9) << "queue"
<< std::setw(COLUMN_WIDTH_10) << g_recordTaskCounter_[ffrt_queue_task][i].submitCounter
<< std::setw(COLUMN_WIDTH_10) << g_recordTaskCounter_[ffrt_queue_task][i].submitCounter
<< std::setw(COLUMN_WIDTH_12) << g_recordTaskCounter_[ffrt_queue_task][i].coSwitchCounter
<< std::setw(COLUMN_WIDTH_10) << g_recordTaskCounter_[ffrt_queue_task][i].doneCounter
<< std::setw(COLUMN_WIDTH_10) << (g_recordTaskCounter_[ffrt_queue_task][i].doneCounter +
g_recordTaskCounter_[ffrt_queue_task][i].cancelCounter);
#if (FFRT_TRACE_RECORD_LEVEL >= FFRT_TRACE_RECORD_LEVEL_3)
unsigned int doneCount = g_recordTaskCounter_[ffrt_queue_task][i].doneCounter.load();
if (doneCount > 0) {
oss << std::setw(COLUMN_WIDTH_13) << g_recordMaxWorkerNumber_[i]
<< std::setw(COLUMN_WIDTH_16) << g_recordTaskTime_[ffrt_queue_task][i].maxWaitTime
<< std::setw(COLUMN_WIDTH_19) << g_recordTaskTime_[ffrt_queue_task][i].maxRunDuration
<< std::setw(COLUMN_WIDTH_16) << (g_recordTaskTime_[ffrt_queue_task][i].waitTime/doneCount)
<< std::setw(COLUMN_WIDTH_19) << (g_recordTaskTime_[ffrt_queue_task][i].runDuration/doneCount)
<< std::setw(COLUMN_WIDTH_18) << g_recordTaskTime_[ffrt_queue_task][i].waitTime
<< std::setw(COLUMN_WIDTH_22) << g_recordTaskTime_[ffrt_queue_task][i].runDuration;
}
#endif
oss << "\n";
}
}
void FFRTTraceRecord::DumpUVTaskStatisticInfo(std::ostringstream& oss)
{
for (size_t i = 0; i < QoS::MaxNum(); i++) {
if (g_recordTaskCounter_[ffrt_uv_task][i].submitCounter <= 0) {
continue;
}
oss << std::setw(COLUMN_WIDTH_3) << i
<< std::setw(COLUMN_WIDTH_9) << "uv"
<< std::setw(COLUMN_WIDTH_10) << g_recordTaskCounter_[ffrt_uv_task][i].submitCounter
<< std::setw(COLUMN_WIDTH_10) << g_recordTaskCounter_[ffrt_uv_task][i].enqueueCounter
<< std::setw(COLUMN_WIDTH_12) << 0
<< std::setw(COLUMN_WIDTH_10) << g_recordTaskCounter_[ffrt_uv_task][i].doneCounter
<< std::setw(COLUMN_WIDTH_10) << (g_recordTaskCounter_[ffrt_uv_task][i].doneCounter +
g_recordTaskCounter_[ffrt_uv_task][i].cancelCounter);
oss << "\n";
}
}
int FFRTTraceRecord::StatisticInfoDump(char* buf, uint32_t len)
{
std::ostringstream oss;
oss << "---\n" << "Qos TaskType SubmitNum EnueueNum CoSwitchNum DoneNum FinishNum";
#if (FFRT_TRACE_RECORD_LEVEL >= FFRT_TRACE_RECORD_LEVEL_3)
oss << " MaxWorkerNum MaxWaitTime(us) MaxRunDuration(us) AvgWaitTime(us) AvgRunDuration(us) TotalWaitTime(us)"
<< " TotalRunDuration(us)";
#endif
oss << "\n";
DumpNormalTaskStatisticInfo(oss);
DumpQueueTaskStatisticInfo(oss);
DumpUVTaskStatisticInfo(oss);
oss << "---\n";
return snprintf_s(buf, len, len - 1, "%s", oss.str().c_str());
}
unsigned int FFRTTraceRecord::GetSubmitCount()
{
int maxQos = QoS::MaxNum();
unsigned int totalCount = 0;
for (int i = 0; i < maxQos; i++) {
totalCount += g_recordTaskCounter_[ffrt_normal_task][i].submitCounter;
totalCount += g_recordTaskCounter_[ffrt_uv_task][i].submitCounter;
totalCount += g_recordTaskCounter_[ffrt_queue_task][i].submitCounter;
}
return totalCount;
}
unsigned int FFRTTraceRecord::GetEnqueueCount()
{
int maxQos = QoS::MaxNum();
unsigned int totalCount = 0;
for (int i = 0; i < maxQos; i++) {
totalCount += g_recordTaskCounter_[ffrt_normal_task][i].enqueueCounter;
totalCount += g_recordTaskCounter_[ffrt_uv_task][i].enqueueCounter;
totalCount += g_recordTaskCounter_[ffrt_queue_task][i].enqueueCounter;
}
return totalCount;
}
unsigned int FFRTTraceRecord::GetRunCount()
{
int maxQos = QoS::MaxNum();
unsigned int totalCount = 0;
for (int i = 0; i < maxQos; i++) {
totalCount += g_recordTaskCounter_[ffrt_normal_task][i].runCounter;
totalCount += g_recordTaskCounter_[ffrt_uv_task][i].runCounter;
totalCount += g_recordTaskCounter_[ffrt_queue_task][i].runCounter;
}
return totalCount;
}
unsigned int FFRTTraceRecord::GetDoneCount()
{
int maxQos = QoS::MaxNum();
unsigned int totalCount = 0;
for (int i = 0; i < maxQos; i++) {
totalCount += g_recordTaskCounter_[ffrt_normal_task][i].doneCounter;
totalCount += g_recordTaskCounter_[ffrt_uv_task][i].doneCounter;
totalCount += g_recordTaskCounter_[ffrt_queue_task][i].doneCounter;
}
return totalCount;
}
unsigned int FFRTTraceRecord::GetCoSwitchCount()
{
int maxQos = QoS::MaxNum();
unsigned int totalCount = 0;
for (int i = 0; i < maxQos; i++) {
totalCount += g_recordTaskCounter_[ffrt_normal_task][i].coSwitchCounter;
totalCount += g_recordTaskCounter_[ffrt_queue_task][i].coSwitchCounter;
}
return totalCount;
}
unsigned int FFRTTraceRecord::GetFinishCount()
{
int maxQos = QoS::MaxNum();
unsigned int totalCount = 0;
for (int i = 0; i < maxQos; i++) {
totalCount += g_recordTaskCounter_[ffrt_normal_task][i].doneCounter;
totalCount += g_recordTaskCounter_[ffrt_normal_task][i].cancelCounter;
totalCount += g_recordTaskCounter_[ffrt_uv_task][i].doneCounter;
totalCount += g_recordTaskCounter_[ffrt_uv_task][i].cancelCounter;
totalCount += g_recordTaskCounter_[ffrt_queue_task][i].doneCounter;
totalCount += g_recordTaskCounter_[ffrt_queue_task][i].cancelCounter;
}
return totalCount;
}
#endif // FFRT_TRACE_RECORD_LEVEL >= FFRT_TRACE_RECORD_LEVEL_2
}

210
src/dfx/trace_record/ffrt_trace_record.h Normal file
View File

@ -0,0 +1,210 @@
/*
* Copyright (c) 2023 Huawei Device Co., Ltd.
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
#ifndef FFRT_TRACE_RECORD_H
#define FFRT_TRACE_RECORD_H
#include "internal_inc/osal.h"
#include "tm/task_base.h"
#define FFRT_TRACE_RECORD_LEVEL_1 (1)
#define FFRT_TRACE_RECORD_LEVEL_2 (2)
#define FFRT_TRACE_RECORD_LEVEL_3 (3)
namespace ffrt {
typedef struct ffrt_record_task_counter {
std::atomic<unsigned int> submitCounter{0};
std::atomic<unsigned int> enqueueCounter{0};
std::atomic<unsigned int> coSwitchCounter{0};
std::atomic<unsigned int> runCounter{0};
std::atomic<unsigned int> doneCounter{0};
std::atomic<unsigned int> cancelCounter{0};
} ffrt_record_task_counter_t;
typedef struct ffrt_record_task_time {
std::atomic<uint64_t> waitTime{0};
std::atomic<uint64_t> runDuration{0};
std::atomic<uint64_t> executeTime{0};
uint64_t maxWaitTime{0};
uint64_t maxRunDuration{0};
} ffrt_record_task_time_t;
class FFRTTraceRecord {
public:
static const int TASK_TYPE_NUM = ffrt_queue_task + 1;
static bool ffrt_be_used_;
static int g_recordMaxWorkerNumber_[QoS::MaxNum()];
static ffrt_record_task_counter_t g_recordTaskCounter_[TASK_TYPE_NUM][QoS::MaxNum()];
static ffrt_record_task_time_t g_recordTaskTime_[TASK_TYPE_NUM][QoS::MaxNum()];
public:
FFRTTraceRecord() = default;
~FFRTTraceRecord() = default;
static inline uint64_t TimeStamp(void)
{
#if defined(__aarch64__)
uint64_t tsc = 1;
asm volatile("mrs %0, cntvct_el0" : "=r" (tsc));
return tsc;
#else
return static_cast<uint64_t>(std::chrono::time_point_cast<std::chrono::microseconds>(
std::chrono::steady_clock::now()).time_since_epoch().count());
#endif
}
static inline bool FfrtBeUsed()
{
return ffrt_be_used_;
}
template<ffrt_executor_task_type_t taskType>
static inline void AddSubmitCounter(int qos)
{
#if (FFRT_TRACE_RECORD_LEVEL >= FFRT_TRACE_RECORD_LEVEL_2)
g_recordTaskCounter_[taskType][qos].submitCounter.fetch_add(1, std::memory_order_relaxed);
#endif
}
static inline void RecordCreateTimeAndTid(uint64_t* createTime, int32_t* fromTid)
{
#if (FFRT_TRACE_RECORD_LEVEL >= FFRT_TRACE_RECORD_LEVEL_1)
*createTime = TimeStamp();
*fromTid = ExecuteCtx::Cur()->tid;
#endif
}
template<ffrt_executor_task_type_t taskType>
static inline void TaskSubmit(int qos)
{
if (unlikely(!ffrt_be_used_)) {
ffrt_be_used_ = true;
}
AddSubmitCounter<taskType>(qos);
}
static inline void TaskSubmit(uint64_t* createTime, int32_t* fromTid)
{
if (unlikely(!ffrt_be_used_)) {
ffrt_be_used_ = true;
}
RecordCreateTimeAndTid(createTime, fromTid);
}
template<ffrt_executor_task_type_t taskType>
static inline void TaskSubmit(int qos, uint64_t* createTime, int32_t* fromTid)
{
if (unlikely(!ffrt_be_used_)) {
ffrt_be_used_ = true;
}
AddSubmitCounter<taskType>(qos);
RecordCreateTimeAndTid(createTime, fromTid);
}
static inline void TaskExecute(uint64_t* executeTime)
{
#if (FFRT_TRACE_RECORD_LEVEL >= FFRT_TRACE_RECORD_LEVEL_1)
*executeTime = TimeStamp();
#endif
}
template<ffrt_executor_task_type_t taskType>
static inline void TaskExecute(int qos)
{
#if (FFRT_TRACE_RECORD_LEVEL >= FFRT_TRACE_RECORD_LEVEL_2)
g_recordTaskCounter_[taskType][qos].runCounter.fetch_add(1, std::memory_order_relaxed);
#endif
}
template<ffrt_executor_task_type_t taskType>
static inline void TaskDone(int qos)
{
#if (FFRT_TRACE_RECORD_LEVEL >= FFRT_TRACE_RECORD_LEVEL_2)
g_recordTaskCounter_[taskType][qos].doneCounter.fetch_add(1, std::memory_order_relaxed);
#endif
}
template<ffrt_executor_task_type_t taskType>
static inline void TaskDone(int qos, TaskBase* task)
{
#if (FFRT_TRACE_RECORD_LEVEL >= FFRT_TRACE_RECORD_LEVEL_3)
auto runDuration = TimeStamp() - task->executeTime;
g_recordTaskTime_[taskType][qos].runDuration += runDuration;
if (g_recordTaskTime_[taskType][qos].maxRunDuration < runDuration) {
g_recordTaskTime_[taskType][qos].maxRunDuration = runDuration;
}
auto waitTime = task->executeTime - task->createTime;
g_recordTaskTime_[taskType][qos].waitTime += waitTime;
if (g_recordTaskTime_[taskType][qos].maxWaitTime < waitTime) {
g_recordTaskTime_[taskType][qos].maxWaitTime = waitTime;
}
#endif
}
template<ffrt_executor_task_type_t taskType>
static inline void TaskEnqueue(int qos)
{
#if (FFRT_TRACE_RECORD_LEVEL >= FFRT_TRACE_RECORD_LEVEL_2)
g_recordTaskCounter_[taskType][qos].enqueueCounter.fetch_add(1, std::memory_order_relaxed);
#endif
}
template<ffrt_executor_task_type_t taskType>
static inline void TaskCancel(int qos)
{
#if (FFRT_TRACE_RECORD_LEVEL >= FFRT_TRACE_RECORD_LEVEL_2)
g_recordTaskCounter_[taskType][qos].cancelCounter.fetch_add(1, std::memory_order_relaxed);
#endif
}
static inline void TaskRun(int qos, TaskBase* task)
{
#if (FFRT_TRACE_RECORD_LEVEL >= FFRT_TRACE_RECORD_LEVEL_2)
g_recordTaskCounter_[task->type][qos].runCounter.fetch_add(1, std::memory_order_relaxed);
#endif
}
static inline void TaskCoSwitchOut(int qos, TaskBase* task)
{
#if (FFRT_TRACE_RECORD_LEVEL >= FFRT_TRACE_RECORD_LEVEL_2)
g_recordTaskCounter_[task->type][qos].coSwitchCounter.fetch_add(1, std::memory_order_relaxed);
#endif
}
static inline void WorkRecord(int qos, int workerNum)
{
#if (FFRT_TRACE_RECORD_LEVEL >= FFRT_TRACE_RECORD_LEVEL_3)
if (g_recordMaxWorkerNumber_[qos] < workerNum) {
g_recordMaxWorkerNumber_[qos] = workerNum;
}
#endif
}
#if (FFRT_TRACE_RECORD_LEVEL >= FFRT_TRACE_RECORD_LEVEL_2)
static int StatisticInfoDump(char* buf, uint32_t len);
static void DumpNormalTaskStatisticInfo(std::ostringstream& oss);
static void DumpQueueTaskStatisticInfo(std::ostringstream& oss);
static void DumpUVTaskStatisticInfo(std::ostringstream& oss);
static unsigned int GetSubmitCount();
static unsigned int GetEnqueueCount();
static unsigned int GetRunCount();
static unsigned int GetDoneCount();
static unsigned int GetCoSwitchCount();
static unsigned int GetFinishCount();
#endif
};
}
#endif // FFRT_TRACE_RECORD_H

11
src/dm/dependence_manager.h
View File

@ -31,6 +31,7 @@
#include "eu/execute_unit.h"
#include "core/entity.h"
#include "dfx/watchdog/watchdog_util.h"
#include "dfx/trace_record/ffrt_trace_record.h"
#include "tm/cpu_task.h"
#include "sync/poller.h"
@ -86,21 +87,15 @@ public:
{
FFRT_EXECUTOR_TASK_SUBMIT_MARKER(task);
FFRT_TRACE_SCOPE(1, onSubmitUV);
#ifdef FFRT_BBOX_ENABLE
TaskSubmitCounterInc();
#endif
QoS qos = (attr == nullptr ? QoS() : QoS(attr->qos_));
FFRTTraceRecord::TaskSubmit<ffrt_uv_task>(qos);
LinkedList* node = reinterpret_cast<LinkedList *>(&task->wq);
FFRTScheduler* sch = FFRTScheduler::Instance();
if (!sch->InsertNode(node, qos)) {
FFRT_LOGE("Submit UV task failed!");
return;
}
#ifdef FFRT_BBOX_ENABLE
TaskEnQueuCounterInc();
#endif
FFRTTraceRecord::TaskEnqueue<ffrt_uv_task>(qos);
}
virtual void onWait() = 0;

16
src/dm/sdependence_manager.cpp
View File

@ -14,6 +14,7 @@
*/
#include "sdependence_manager.h"
#include "dfx/trace_record/ffrt_trace_record.h"
#include "util/worker_monitor.h"
#include "util/ffrt_facade.h"
@ -104,9 +105,8 @@ void SDependenceManager::onSubmit(bool has_handle, ffrt_task_handle_t &handle, f
}
#endif
#ifdef FFRT_BBOX_ENABLE
TaskSubmitCounterInc();
#endif
QoS qos = (attr == nullptr ? QoS() : QoS(attr->qos_));
FFRTTraceRecord::TaskSubmit<ffrt_normal_task>(qos, &(task->createTime), &(task->fromTid));
std::vector<const void*> insNoDup;
std::vector<const void*> outsNoDup;
@ -124,7 +124,6 @@ void SDependenceManager::onSubmit(bool has_handle, ffrt_task_handle_t &handle, f
handle = static_cast<ffrt_task_handle_t>(task);
outsNoDup.push_back(handle); // handle作为任务的输出signature
}
QoS qos = (attr == nullptr ? QoS() : QoS(attr->qos_));
task->SetQos(qos);
/* The parent's number of subtasks to be completed increases by one,
* and decreases by one after the subtask is completed
@ -176,9 +175,7 @@ void SDependenceManager::onSubmit(bool has_handle, ffrt_task_handle_t &handle, f
FFRT_LOGD("Submit completed, enter ready queue, task[%lu], name[%s]", task->gid, task->label.c_str());
task->UpdateState(TaskState::READY);
#ifdef FFRT_BBOX_ENABLE
TaskEnQueuCounterInc();
#endif
FFRTTraceRecord::TaskEnqueue<ffrt_normal_task>(qos);
FFRT_TRACE_END();
}
@ -290,9 +287,8 @@ int SDependenceManager::onExecResults(const ffrt_deps_t *deps)
void SDependenceManager::onTaskDone(CPUEUTask* task)
{
auto sTask = static_cast<SCPUEUTask*>(task);
#ifdef FFRT_BBOX_ENABLE
TaskDoneCounterInc();
#endif
FFRTTraceRecord::TaskDone<ffrt_normal_task>(task->GetQos());
FFRTTraceRecord::TaskDone<ffrt_normal_task>(task->GetQos(), task);
FFRT_TRACE_SCOPE(1, ontaskDone);
sTask->DecChildRef();
if (!(sTask->ins.empty() && sTask->outs.empty())) {

15
src/eu/co_routine.cpp
View File

@ -30,6 +30,7 @@
#include "sync/perf_counter.h"
#include "sync/io_poller.h"
#include "dfx/bbox/bbox.h"
#include "dfx/trace_record/ffrt_trace_record.h"
#include "co_routine_factory.h"
#ifdef FFRT_TASK_LOCAL_ENABLE
#include "pthread_ffrt.h"
@ -404,9 +405,7 @@ void CoStart(ffrt::CPUEUTask* task)
CoCreat(task);
auto co = task->coRoutine;
#ifdef FFRT_BBOX_ENABLE
TaskRunCounterInc();
#endif
FFRTTraceRecord::TaskRun(task->GetQos(), task);
#ifdef FFRT_HITRACE_ENABLE
using namespace OHOS::HiviewDFX;
@ -436,9 +435,6 @@ void CoStart(ffrt::CPUEUTask* task)
if (co->isTaskDone) {
task->UpdateState(ffrt::TaskState::EXITED);
co->isTaskDone = false;
#ifdef FFRT_BBOX_ENABLE
TaskFinishCounterInc();
#endif
return;
}
@ -446,9 +442,6 @@ void CoStart(ffrt::CPUEUTask* task)
// need suspend the coroutine task or continue to execute the coroutine task.
auto pending = GetCoEnv()->pending;
if (pending == nullptr) {
#ifdef FFRT_BBOX_ENABLE
TaskFinishCounterInc();
#endif
return;
}
GetCoEnv()->pending = nullptr;
@ -456,9 +449,7 @@ void CoStart(ffrt::CPUEUTask* task)
if ((*pending)(task)) {
// The ownership of the task belongs to other host(cv/mutex/epoll etc)
// And the task cannot be accessed any more.
#ifdef FFRT_BBOX_ENABLE
TaskSwitchCounterInc();
#endif
FFRTTraceRecord::TaskCoSwitchOut(task->GetQos(), task);
#ifdef FFRT_HITRACE_ENABLE
HiTraceChain::Tracepoint(HITRACE_TP_SS, HiTraceChain::GetId(), "ffrt::CoStart");
HiTraceChain::Restore(currentId);

2
src/eu/cpu_monitor.cpp
View File

@ -21,6 +21,7 @@
#include "sched/scheduler.h"
#include "eu/execute_unit.h"
#include "dfx/log/ffrt_log_api.h"
#include "dfx/trace_record/ffrt_trace_record.h"
#include "internal_inc/config.h"
#include "util/name_manager.h"
#include "sync/poller.h"
@ -281,6 +282,7 @@ void CPUMonitor::Poke(const QoS& qos, uint32_t taskCount, TaskNotifyType notifyT
ops.WakeupWorkers(qos);
} else if ((runningNum < workerCtrl.maxConcurrency) && (totalNum < workerCtrl.hardLimit)) {
workerCtrl.executionNum++;
FFRTTraceRecord::WorkRecord((int)qos, workerCtrl.executionNum);
workerCtrl.lock.unlock();
ops.IncWorker(qos);
} else {

9
src/eu/cpu_worker.cpp
View File

@ -69,9 +69,6 @@ void CPUWorker::Run(CPUEUTask* task)
void CPUWorker::Run(ffrt_executor_task_t* task, ffrt_qos_t qos)
{
#ifdef FFRT_BBOX_ENABLE
TaskRunCounterInc();
#endif
if (task == nullptr) {
FFRT_LOGE("task is nullptr");
return;
@ -87,16 +84,14 @@ void CPUWorker::Run(ffrt_executor_task_t* task, ffrt_qos_t qos)
FFRT_LOGE("Static func is nullptr");
return;
}
FFRTTraceRecord::TaskExecute<ffrt_uv_task>(qos);
FFRT_EXECUTOR_TASK_BEGIN(task);
func(task, qos);
FFRT_EXECUTOR_TASK_END();
if (type != ffrt_io_task) {
FFRT_EXECUTOR_TASK_FINISH_MARKER(task); // task finish marker for uv task
}
#ifdef FFRT_BBOX_ENABLE
TaskFinishCounterInc();
#endif
FFRTTraceRecord::TaskDone<ffrt_uv_task>(qos);
}
void* CPUWorker::WrapDispatch(void* worker)

22
src/queue/eventhandler_adapter_queue.cpp
View File

@ -29,11 +29,11 @@ void DumpRunningTaskInfo(const char* tag, const ffrt::HistoryTask& currentRunnin
if (currentRunningTask.beginTime_ == std::numeric_limits<uint64_t>::max()) {
oss << "{}";
} else {
oss << "start at " << ffrt::FormatDateString(currentRunningTask.beginTime_) << ", ";
oss << "start at " << ffrt::FormatDateString4SteadyClock(currentRunningTask.beginTime_) << ", ";
oss << "Event { ";
oss << "send thread = " << currentRunningTask.senderKernelThreadId_;
oss << ", send time = " << ffrt::FormatDateString(currentRunningTask.sendTime_);
oss << ", handle time = " << ffrt::FormatDateString(currentRunningTask.handleTime_);
oss << ", send time = " << ffrt::FormatDateString4SteadyClock(currentRunningTask.sendTime_);
oss << ", handle time = " << ffrt::FormatDateString4SteadyClock(currentRunningTask.handleTime_);
oss << ", task name = " << currentRunningTask.taskName_;
oss << " }\n";
}
@ -50,10 +50,10 @@ void DumpHistoryTaskInfo(const char* tag, const std::vector<ffrt::HistoryTask>&
oss << tag << " No. " << (i + 1) << " : Event { ";
oss << "send thread = " << historyTask.senderKernelThreadId_;
oss << ", send time = " << ffrt::FormatDateString(historyTask.sendTime_);
oss << ", handle time = " << ffrt::FormatDateString(historyTask.handleTime_);
oss << ", trigger time = " << ffrt::FormatDateString(historyTask.triggerTime_);
oss << ", complete time = " << ffrt::FormatDateString(historyTask.completeTime_);
oss << ", send time = " << ffrt::FormatDateString4SteadyClock(historyTask.sendTime_);
oss << ", handle time = " << ffrt::FormatDateString4SteadyClock(historyTask.handleTime_);
oss << ", trigger time = " << ffrt::FormatDateString4SteadyClock(historyTask.triggerTime_);
oss << ", complete time = " << ffrt::FormatDateString4SteadyClock(historyTask.completeTime_);
oss << ", task name = " << historyTask.taskName_;
oss << " }\n";
}
@ -77,9 +77,9 @@ void DumpUnexecutedTaskInfo(const char* tag,
auto taskDumpFun = [&](int n, ffrt::QueueTask* task) {
oss << tag << " No. " << n << " : Event { ";
oss << "send thread = " << task->GetSenderKernelThreadId();
oss << ", send time = " << ffrt::FormatDateString(task->GetUptime() - task->GetDelay());
oss << ", handle time = " << ffrt::FormatDateString(task->GetUptime());
oss << "send thread = " << task->fromTid;
oss << ", send time = " << ffrt::FormatDateString4SteadyClock(task->GetUptime() - task->GetDelay());
oss << ", handle time = " << ffrt::FormatDateString4SteadyClock(task->GetUptime());
oss << ", task name = " << task->label;
oss << " }\n";
dumpSize--;
@ -201,7 +201,7 @@ void EventHandlerAdapterQueue::SetCurrentRunningTask(QueueTask* task)
void EventHandlerAdapterQueue::PushHistoryTask(QueueTask* task, uint64_t triggerTime, uint64_t completeTime)
{
HistoryTask historyTask;
historyTask.senderKernelThreadId_ = task->GetSenderKernelThreadId();
historyTask.senderKernelThreadId_ = task->fromTid;
historyTask.taskName_ = task->label;
historyTask.sendTime_ = task->GetUptime() - task->GetDelay();
historyTask.handleTime_ = task->GetUptime();

4
src/queue/eventhandler_adapter_queue.h
View File

@ -21,7 +21,7 @@
namespace ffrt {
struct HistoryTask {
uint64_t senderKernelThreadId_{0};
int32_t senderKernelThreadId_{0};
std::string taskName_{0};
uint64_t sendTime_{0};
uint64_t handleTime_{0};
@ -37,7 +37,7 @@ struct HistoryTask {
HistoryTask(uint64_t beginTime, QueueTask* task)
{
beginTime_ = beginTime;
senderKernelThreadId_ = task->GetSenderKernelThreadId();
senderKernelThreadId_ = task->fromTid;
sendTime_ = task->GetUptime() - task->GetDelay();
taskName_ = task->label;
handleTime_ = task->GetUptime();

11
src/queue/queue_handler.cpp
View File

@ -16,6 +16,7 @@
#include <sys/syscall.h>
#include <sstream>
#include "dfx/log/ffrt_log_api.h"
#include "dfx/trace_record/ffrt_trace_record.h"
#include "queue_monitor.h"
#include "util/event_handler_adapter.h"
#include "tm/queue_task.h"
@ -118,10 +119,12 @@ void QueueHandler::Submit(QueueTask* task)
uint64_t gid = task->gid;
FFRT_SERIAL_QUEUE_TASK_SUBMIT_MARKER(GetQueueId(), gid);
FFRTTraceRecord::TaskSubmit(&(task->createTime), &(task->fromTid));
#if (FFRT_TRACE_RECORD_LEVEL < FFRT_TRACE_RECORD_LEVEL_1)
if (queue_->GetQueueType() == ffrt_queue_eventhandler_adapter) {
task->SetSenderKernelThreadId(syscall(SYS_gettid));
task->fromTid = ExecuteCtx::Cur()->tid;
}
#endif
int ret = queue_->Push(task);
if (ret == SUCC) {
FFRT_LOGD("submit task[%lu] into %s", gid, name_.c_str());
@ -195,7 +198,7 @@ void QueueHandler::Dispatch(QueueTask* inTask)
FFRT_LOGD("run task [gid=%llu], queueId=%u", task->gid, GetQueueId());
auto f = reinterpret_cast<ffrt_function_header_t*>(task->func_storage);
FFRT_SERIAL_QUEUE_TASK_EXECUTE_MARKER(task->gid);
FFRTTraceRecord::TaskExecute(&(task->executeTime));
uint64_t triggerTime{0};
if (queue_->GetQueueType() == ffrt_queue_eventhandler_adapter) {
triggerTime = static_cast<uint64_t>(std::chrono::duration_cast<std::chrono::microseconds>(
@ -203,7 +206,7 @@ void QueueHandler::Dispatch(QueueTask* inTask)
}
f->exec(f);
FFRTTraceRecord::TaskDone<ffrt_queue_task>(task->GetQos(), task);
if (queue_->GetQueueType() == ffrt_queue_eventhandler_adapter) {
uint64_t completeTime = static_cast<uint64_t>(std::chrono::duration_cast<std::chrono::microseconds>(
std::chrono::steady_clock::now().time_since_epoch()).count());

3
src/sched/execute_ctx.cpp
View File

@ -13,6 +13,8 @@
* limitations under the License.
*/
#include "execute_ctx.h"
#include <sys/syscall.h>
#include <unistd.h>
pthread_key_t g_executeCtxTlsKey = 0;
pthread_once_t g_executeCtxKeyOnce = PTHREAD_ONCE_INIT;
@ -36,6 +38,7 @@ ExecuteCtx::ExecuteCtx()
{
task = nullptr;
wn.weType = 2;
tid = syscall(SYS_gettid);
}
ExecuteCtx::~ExecuteCtx()

1
src/sched/execute_ctx.h
View File

@ -92,6 +92,7 @@ struct ExecuteCtx {
CPUEUTask* task; // 当前正在执行的Task
WaitUntilEntry wn;
uint64_t lastGid_ = 0;
pid_t tid;
inline bool PushTaskToPriorityStack(ffrt_executor_task_t* task)
{

3
src/sched/scheduler.cpp
View File

@ -77,9 +77,6 @@ bool FFRTScheduler::RemoveNode(LinkedList* node, const QoS qos)
}
fifoQue[static_cast<unsigned short>(level)]->RemoveNode(node);
lock->unlock();
#ifdef FFRT_BBOX_ENABLE
TaskFinishCounterInc();
#endif
return true;
}

8
src/tm/cpu_task.cpp
View File

@ -12,13 +12,14 @@
* See the License for the specific language governing permissions and
* limitations under the License.
*/
#include "tm/cpu_task.h"
#include <securec.h>
#include "dfx/trace_record/ffrt_trace_record.h"
#include "dm/dependence_manager.h"
#include "util/slab.h"
#include "internal_inc/osal.h"
#include "tm/task_factory.h"
#include "tm/cpu_task.h"
#include "util/slab.h"
namespace {
const int TSD_SIZE = 128;
@ -49,6 +50,7 @@ void CPUEUTask::FreeMem()
void CPUEUTask::Execute()
{
FFRT_LOGD("Execute task[%lu], name[%s]", gid, label.c_str());
FFRTTraceRecord::TaskExecute(&(this->executeTime));
UpdateState(TaskState::RUNNING);
auto f = reinterpret_cast<ffrt_function_header_t*>(func_storage);
auto exp = ffrt::SkipStatus::SUBMITTED;

6
src/tm/cpu_task.h
View File

@ -74,6 +74,12 @@ public:
bool taskLocal = false;
QoS qos;
int GetQos() const override
{
return qos;
}
void SetQos(QoS& newQos);
uint64_t reserved[8];

13
src/tm/queue_task.h
View File

@ -39,7 +39,7 @@ public:
uint32_t GetQueueId() const;
inline int GetQos() const
inline int GetQos() const override
{
return qos_;
}
@ -100,16 +100,6 @@ public:
return insertHead_;
}
inline uint64_t GetSenderKernelThreadId()
{
return senderKernelThreadId_;
}
inline void SetSenderKernelThreadId(uint64_t senderKernelThreadId)
{
senderKernelThreadId_ = senderKernelThreadId;
}
uint8_t func_storage[ffrt_auto_managed_function_storage_size];
private:
@ -128,7 +118,6 @@ private:
std::condition_variable cond_;
ffrt_queue_priority_t prio_ = ffrt_queue_priority_low;
uint64_t senderKernelThreadId_{0};
};
} // namespace ffrt

9
src/tm/scpu_task.cpp
View File

@ -17,6 +17,7 @@
#include <sstream>
#include "backtrace_local.h"
#endif
#include "dfx/trace_record/ffrt_trace_record.h"
#include "dm/dependence_manager.h"
#include "util/slab.h"
#include "internal_inc/osal.h"
@ -47,9 +48,7 @@ void SCPUEUTask::DecDepRef()
FFRT_LOGD("Undependency completed, enter ready queue, task[%lu], name[%s]", gid, label.c_str());
FFRT_WAKE_TRACER(this->gid);
this->UpdateState(TaskState::READY);
#ifdef FFRT_BBOX_ENABLE
TaskEnQueuCounterInc();
#endif
FFRTTraceRecord::TaskEnqueue<ffrt_normal_task>(GetQos());
}
}
@ -117,9 +116,7 @@ void SCPUEUTask::DecWaitDataRef()
} else {
FFRT_WAKE_TRACER(this->gid);
this->UpdateState(TaskState::READY);
#ifdef FFRT_BBOX_ENABLE
TaskEnQueuCounterInc();
#endif
FFRTTraceRecord::TaskEnqueue<ffrt_normal_task>(GetQos());
}
}

12
src/tm/task_base.h
View File

@ -18,6 +18,7 @@
#include <atomic>
#include <vector>
#include "eu/co_routine.h"
#include "qos.h"
#include "sched/execute_ctx.h"
#include "util/task_deleter.h"
@ -34,6 +35,17 @@ public:
#ifdef FFRT_ASYNC_STACKTRACE
uint64_t stackId = 0;
#endif
virtual int GetQos() const
{
return qos_default;
}
#if (FFRT_TRACE_RECORD_LEVEL >= FFRT_TRACE_RECORD_LEVEL_1)
uint64_t createTime;
uint64_t executeTime;
#endif
int32_t fromTid;
};
class CoTask : public TaskBase, public TaskDeleter {

77
src/util/time_format.h
View File

@ -20,19 +20,37 @@
#include <securec.h>
namespace ffrt {
std::string FormatDateString(const std::chrono::system_clock::time_point& timePoint)
typedef enum {
millisecond,
microsecond,
} time_unit_t;
static std::string FormatDateString(const std::chrono::system_clock::time_point& timePoint,
time_unit_t timeUnit = millisecond)
{
constexpr int MaxMsLength = 3;
constexpr int MsPerSecond = 1000;
constexpr int DatetimeStringLength = 80;
constexpr int MaxUsLength = 6;
constexpr int UsPerSecond = 1000 * 1000;
auto tp = std::chrono::time_point_cast<std::chrono::milliseconds>(timePoint);
auto tt = std::chrono::system_clock::to_time_t(timePoint);
auto ms = tp.time_since_epoch().count() % MsPerSecond;
auto msString = std::to_string(ms);
if (msString.length() < MaxMsLength) {
msString = std::string(MaxMsLength - msString.length(), '0') + msString;
std::string remainder;
if (microsecond == timeUnit) {
auto tp = std::chrono::time_point_cast<std::chrono::microseconds>(timePoint);
auto us = tp.time_since_epoch().count() % UsPerSecond;
remainder = std::to_string(us);
if (remainder.length() < MaxUsLength) {
remainder = std::string(MaxUsLength - remainder.length(), '0') + remainder;
}
} else {
auto tp = std::chrono::time_point_cast<std::chrono::milliseconds>(timePoint);
auto ms = tp.time_since_epoch().count() % MsPerSecond;
remainder = std::to_string(ms);
if (remainder.length() < MaxMsLength) {
remainder = std::string(MaxMsLength - remainder.length(), '0') + remainder;
}
}
auto tt = std::chrono::system_clock::to_time_t(timePoint);
struct tm curTime;
if (memset_s(&curTime, sizeof(curTime), 0, sizeof(curTime)) != EOK) {
FFRT_LOGE("Fail to memset");
@ -40,17 +58,46 @@ std::string FormatDateString(const std::chrono::system_clock::time_point& timePo
}
localtime_r(&tt, &curTime);
char sysTime[DatetimeStringLength];
std::strftime(sysTime, sizeof(char) * DatetimeStringLength, "%Y-%m-%d %I:%M:%S.", &curTime);
return std::string(sysTime) + msString;
std::strftime(sysTime, sizeof(char) * DatetimeStringLength, "%Y-%m-%d %H:%M:%S.", &curTime);
return std::string(sysTime) + remainder;
}
std::string FormatDateString(uint64_t steadyClockTimeStamp)
static std::string FormatDateString4SteadyClock(uint64_t steadyClockTimeStamp, time_unit_t timeUnit = millisecond)
{
std::chrono::microseconds ms(steadyClockTimeStamp - std::chrono::duration_cast<std::chrono::microseconds>(
std::chrono::steady_clock::now().time_since_epoch()).count());
auto tp = std::chrono::system_clock::now() + ms;
return FormatDateString(tp);
}
static uint64_t globalTimeStamp = std::chrono::duration_cast<std::chrono::microseconds>(
std::chrono::steady_clock::now().time_since_epoch()).count();
static auto globalTp = std::chrono::system_clock::now();
std::chrono::microseconds us((int64_t)(steadyClockTimeStamp - globalTimeStamp));
return FormatDateString(globalTp + us, timeUnit);
}
static inline uint64_t Arm64CntFrq(void)
{
uint64_t freq = 1;
asm volatile("mrs %0, cntfrq_el0" : "=r" (freq));
return freq;
}
static inline uint64_t Arm64CntCt(void)
{
uint64_t tsc = 1;
asm volatile("mrs %0, cntvct_el0" : "=r" (tsc));
return tsc;
}
static std::string FormatDateString4CntCt(uint64_t cntCtTimeStamp, time_unit_t timeUnit = millisecond)
{
constexpr int Ratio = 1000 * 1000;
static int64_t globalFreq = Arm64CntFrq();
if (globalFreq == 0) {
return "";
}
static uint64_t globalCntCt = Arm64CntCt();
static auto globalTp = std::chrono::system_clock::now();
std::chrono::microseconds us((int64_t)(cntCtTimeStamp - globalCntCt) * Ratio / globalFreq);
return FormatDateString(globalTp + us, timeUnit);
}
}
#endif // UTIL_TIME_FORAMT_H

28
test/ut/BUILD.gn
View File

@ -38,6 +38,7 @@ config("ffrt_test_config") {
"../../src",
"../../src/dfx/log",
"../../src/dfx/trace",
"../../src/dfx/trace_record",
"../../src/sched",
]
@ -831,6 +832,32 @@ ohos_unittest("worker_manager_test") {
part_name = "ffrt"
}
ohos_unittest("ut_queue_dump") {
module_out_path = module_output_path
configs = [ ":ffrt_test_config" ]
include_dirs = [ "../testfunc" ]
cflags_cc = [
"-frtti",
"-Xclang",
"-fcxx-exceptions",
"-std=c++11",
"-DFFRT_PERF_EVENT_ENABLE",
]
sources = [ "testcase/ut_queue_dump.cpp" ]
deps = ffrt_ut_base_deps
external_deps = ffrt_ut_base_external_deps
if (is_standard_system) {
public_external_deps = gtest_public_external_deps
}
install_enable = true
part_name = "ffrt"
}
group("ffrt_unittest_ffrt") {
testonly = true
@ -861,6 +888,7 @@ group("ffrt_unittest_ffrt") {
":ut_loop",
":ut_mem",
":ut_queue",
":ut_queue_dump",
":ut_rtg",
":ut_scheduler",
":ut_thread",

2
test/ut/testcase/ut_core.cpp
View File

@ -114,5 +114,5 @@ HWTEST_F(CoreTest, ffrt_get_cur_cached_task_id_test, TestSize.Level1)
ffrt::CPUEUTask* task = new ffrt::SCPUEUTask(nullptr, nullptr, 20, ffrt::QoS(2));
ctx->task = task;
EXPECT_EQ(ffrt_get_cur_cached_task_id(), 1);
EXPECT_NE(ffrt_get_cur_cached_task_id(), 0);
}

287
test/ut/testcase/ut_queue_dump.cpp Normal file
View File

@ -0,0 +1,287 @@
/*
* Copyright (c) 2023 Huawei Device Co., Ltd.
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
#include <array>
#include <gtest/gtest.h>
#include <regex>
#include <thread>
#include "c/ffrt_dump.h"
#include "dfx/log/ffrt_log_api.h"
#include "ffrt_inner.h"
#include "securec.h"
#include "util.h"
static const int BUFFER_SIZE = 120000;
static const int SLEEP_MS = 3 * 1000;
static const int TASK_NUM_9 = 9;
static const int TASK_NUM_10 = 10;
static const int TASK_NUM_29 = 29;
static const int TASK_NUM_40 = 40;
static const int TASK_NUM_600 = 600;
static const int TASK_NUM_610 = 610;
using namespace std;
using namespace ffrt;
using namespace testing;
class QueueDumpTest : public testing::Test {
protected:
static void SetUpTestCase()
{
}
static void TearDownTestCase()
{
}
virtual void SetUp()
{
}
virtual void TearDown()
{
}
};
int g_cnt = 0;
std::function<void()>&& basicFunc = []() { g_cnt += 1; };
std::function<void()>&& sleepFunc = []() { std::this_thread::sleep_for(std::chrono::milliseconds(SLEEP_MS)); };
static void QueueDumpTask1Test(ffrt_queue_t& queue_handle, char* buf)
{
ffrt_task_attr_t task_attr;
(void)ffrt_task_attr_init(&task_attr);
ffrt_task_attr_set_name(&task_attr, "task1");
for (int i = 0; i < TASK_NUM_9; ++i) {
ffrt_queue_submit(queue_handle, create_function_wrapper(basicFunc, ffrt_function_kind_queue), &task_attr);
}
ffrt_task_handle_t t =
ffrt_queue_submit_h(queue_handle, create_function_wrapper(basicFunc, ffrt_function_kind_queue), &task_attr);
ffrt_queue_wait(t);
EXPECT_EQ(g_cnt, TASK_NUM_10);
// dump队列信息
int ret = ffrt_queue_dump(queue_handle, "eventHandler1", buf, BUFFER_SIZE, true);
EXPECT_TRUE(ret > 0);
// 预期dump信息:
// 1.tag为eventHandler1
// 2.当前执行任务名称为task1
// 3.有10条历史执行的任务，且任务名称都是task1
// 4.无剩余未执行的任务
std::string str(buf);
std::regex pattern(R"(eventHandler1 Current Running: start at (\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}), Event \{ send thread = (\d+), send time = (\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}), handle time = (\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}), task name = (.*task1.*) \}
eventHandler1 History event queue information:
(eventHandler1 No. (\d+) : Event \{ send thread = (\d+), send time = (\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}), handle time = (\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}), trigger time = (\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}), complete time = (\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}), task name = (.*task1.*) \}
){10}eventHandler1 Immediate priority event queue information:
eventHandler1 Total size of Immediate events : 0
eventHandler1 High priority event queue information:
eventHandler1 Total size of High events : 0
eventHandler1 Low priority event queue information:
eventHandler1 Total size of Low events : 0
eventHandler1 Idle priority event queue information:
eventHandler1 Total size of Idle events : 0
eventHandler1 Vip priority event queue information:
eventHandler1 Total size of Vip events : 0
eventHandler1 Total event size : 0
)");
EXPECT_TRUE(std::regex_match(str, pattern));
ffrt_task_handle_destroy(t);
ffrt_task_attr_destroy(&task_attr);
}
static void QueueDumpTask2Test(ffrt_queue_t& queue_handle, char* buf)
{
ffrt_task_attr_t task_attr;
(void)ffrt_task_attr_init(&task_attr);
ffrt_task_attr_set_name(&task_attr, "task2");
for (int i = 0; i < TASK_NUM_29; ++i) {
ffrt_queue_submit(queue_handle, create_function_wrapper(basicFunc, ffrt_function_kind_queue), &task_attr);
}
ffrt_task_handle_t t =
ffrt_queue_submit_h(queue_handle, create_function_wrapper(basicFunc, ffrt_function_kind_queue), &task_attr);
ffrt_queue_wait(t);
EXPECT_EQ(g_cnt, TASK_NUM_40);
// dump队列信息
memset_s(buf, sizeof(char) * BUFFER_SIZE, 0, sizeof(char) * BUFFER_SIZE);
int ret = ffrt_queue_dump(queue_handle, "eventHandler2", buf, BUFFER_SIZE, true);
EXPECT_TRUE(ret > 0);
// 预期dump信息:
// 1.tag为eventHandler2
// 2.当前执行任务名称为task2
// 3.有32条历史执行的任务
// 4.无剩余未执行的任务
std::string str(buf);
std::regex pattern(R"(eventHandler2 Current Running: start at (\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}), Event \{ send thread = (\d+), send time = (\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}), handle time = (\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}), task name = (.*task2.*) \}
eventHandler2 History event queue information:
(eventHandler2 No. (\d+) : Event \{ send thread = (\d+), send time = (\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}), handle time = (\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}), trigger time = (\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}), complete time = (\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}), task name = ([^\}]*?) \}
){32}eventHandler2 Immediate priority event queue information:
eventHandler2 Total size of Immediate events : 0
eventHandler2 High priority event queue information:
eventHandler2 Total size of High events : 0
eventHandler2 Low priority event queue information:
eventHandler2 Total size of Low events : 0
eventHandler2 Idle priority event queue information:
eventHandler2 Total size of Idle events : 0
eventHandler2 Vip priority event queue information:
eventHandler2 Total size of Vip events : 0
eventHandler2 Total event size : 0
)");
EXPECT_TRUE(std::regex_match(str, pattern));
ffrt_task_handle_destroy(t);
ffrt_task_attr_destroy(&task_attr);
}
static void QueueDumpTask3Test(ffrt_queue_t& queue_handle, char* buf)
{
ffrt_task_attr_t task_attr;
(void)ffrt_task_attr_init(&task_attr);
ffrt_task_attr_set_name(&task_attr, "task3");
ffrt_queue_submit(queue_handle, create_function_wrapper(sleepFunc, ffrt_function_kind_queue), &task_attr);
// dump队列信息
memset_s(buf, sizeof(char) * BUFFER_SIZE, 0, sizeof(char) * BUFFER_SIZE);
int ret = ffrt_queue_dump(queue_handle, "eventHandler3", buf, BUFFER_SIZE, true);
EXPECT_TRUE(ret > 0);
// 预期dump信息:
// 1.tag为eventHandler3
// 2.当前执行任务名称为task3
// 3.有32条历史执行的任务
// 4.无剩余未执行的任务
std::string str(buf);
std::regex pattern(R"(eventHandler3 Current Running: start at (\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}), Event \{ send thread = (\d+), send time = (\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}), handle time = (\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}), task name = (.*task3.*) \}
eventHandler3 History event queue information:
(eventHandler3 No. (\d+) : Event \{ send thread = (\d+), send time = (\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}), handle time = (\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}), trigger time = (\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}), complete time = (\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}), task name = ([^\}]*?) \}
){32}eventHandler3 Immediate priority event queue information:
eventHandler3 Total size of Immediate events : 0
eventHandler3 High priority event queue information:
eventHandler3 Total size of High events : 0
eventHandler3 Low priority event queue information:
eventHandler3 Total size of Low events : 0
eventHandler3 Idle priority event queue information:
eventHandler3 Total size of Idle events : 0
eventHandler3 Vip priority event queue information:
eventHandler3 Total size of Vip events : 0
eventHandler3 Total event size : 0
)");
EXPECT_TRUE(std::regex_match(str, pattern));
ffrt_task_attr_destroy(&task_attr);
}
static void QueueDumpPriorityTest(ffrt_queue_t& queue_handle, ffrt_task_attr_t& task_attr,
ffrt_inner_queue_priority_t priority, const char* name)
{
(void)ffrt_task_attr_init(&task_attr);
ffrt_task_attr_set_queue_priority(&task_attr, static_cast<ffrt_queue_priority_t>(priority));
ffrt_task_attr_set_name(&task_attr, name);
for (int i = 0; i < TASK_NUM_10; ++i) {
ffrt_queue_submit(queue_handle, create_function_wrapper(basicFunc, ffrt_function_kind_queue), &task_attr);
}
}
static void QueueDumpPriorityTest(ffrt_queue_t& queue_handle, char* buf)
{
ffrt_task_attr_t task_attr4;
QueueDumpPriorityTest(queue_handle, task_attr4, ffrt_inner_queue_priority_immediate, "task4");
ffrt_task_attr_t task_attr5;
QueueDumpPriorityTest(queue_handle, task_attr5, ffrt_inner_queue_priority_high, "task5");
ffrt_task_attr_t task_attr6;
QueueDumpPriorityTest(queue_handle, task_attr6, ffrt_inner_queue_priority_low, "task6");
ffrt_task_attr_t task_attr7;
QueueDumpPriorityTest(queue_handle, task_attr7, ffrt_inner_queue_priority_idle, "task7");
ffrt_task_attr_t task_attr8;
QueueDumpPriorityTest(queue_handle, task_attr8, ffrt_inner_queue_priority_vip, "task8");
memset_s(buf, sizeof(char) * BUFFER_SIZE, 0, sizeof(char) * BUFFER_SIZE);
int ret = ffrt_queue_dump(queue_handle, "eventHandler4", buf, BUFFER_SIZE, true);
EXPECT_TRUE(ret > 0);
// 预期dump信息:
// 1.tag为eventHandler4
// 2.当前执行任务名称为task3
// 3.有32条历史执行的任务
// 4.5种优先级各有10条任务
std::string str(buf);
std::regex pattern(R"(eventHandler4 Current Running: start at (\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}), Event \{ send thread = (\d+), send time = (\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}), handle time = (\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}), task name = (.*task3.*) \}
eventHandler4 History event queue information:
(eventHandler4 No. (\d+) : Event \{ send thread = (\d+), send time = (\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}), handle time = (\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}), trigger time = (\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}), complete time = (\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}), task name = ([^\}]*?) \}
){32}eventHandler4 Immediate priority event queue information:
(eventHandler4 No. (\d+) : Event \{ send thread = (\d+), send time = (\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}), handle time = (\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}), task name = (.*task4.*) \}
){10}eventHandler4 Total size of Immediate events : 10
eventHandler4 High priority event queue information:
(eventHandler4 No. (\d+) : Event \{ send thread = (\d+), send time = (\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}), handle time = (\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}), task name = (.*task5.*) \}
){10}eventHandler4 Total size of High events : 10
eventHandler4 Low priority event queue information:
(eventHandler4 No. (\d+) : Event \{ send thread = (\d+), send time = (\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}), handle time = (\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}), task name = (.*task6.*) \}
){10}eventHandler4 Total size of Low events : 10
eventHandler4 Idle priority event queue information:
(eventHandler4 No. (\d+) : Event \{ send thread = (\d+), send time = (\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}), handle time = (\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}), task name = (.*task7.*) \}
){10}eventHandler4 Total size of Idle events : 10
eventHandler4 Vip priority event queue information:
(eventHandler4 No. (\d+) : Event \{ send thread = (\d+), send time = (\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}), handle time = (\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}), task name = (.*task8.*) \}
){10}eventHandler4 Total size of Vip events : 10
eventHandler4 Total event size : 50
)");
EXPECT_TRUE(std::regex_match(str, pattern));
ffrt_task_attr_destroy(&task_attr4);
ffrt_task_attr_destroy(&task_attr5);
ffrt_task_attr_destroy(&task_attr6);
ffrt_task_attr_destroy(&task_attr7);
ffrt_task_attr_destroy(&task_attr8);
}
static void QueueDumpMaxDumpSizeTest(ffrt_queue_t& queue_handle, char* buf)
{
ffrt_task_attr_t task_attr;
(void)ffrt_task_attr_init(&task_attr);
ffrt_task_attr_set_queue_priority(&task_attr, static_cast<ffrt_queue_priority_t>(ffrt_inner_queue_priority_high));
ffrt_task_attr_set_name(&task_attr, "task9");
for (int i = 0; i < TASK_NUM_600; ++i) {
ffrt_queue_submit(queue_handle, create_function_wrapper(basicFunc, ffrt_function_kind_queue), &task_attr);
}
// dump队列信息
memset_s(buf, sizeof(char) * BUFFER_SIZE, 0, sizeof(char) * BUFFER_SIZE);
int ret = ffrt_queue_dump(queue_handle, "eventHandler9", buf, BUFFER_SIZE, false);
EXPECT_TRUE(ret > 0);
ffrt_task_attr_destroy(&task_attr);
}
/**
* @brief queue dump interface user cases
*/
TEST_F(QueueDumpTest, queue_dump_case)
{
// 创建类型为ffrt_queue_eventhandler_adapter的队列
ffrt_queue_attr_t queue_attr;
(void)ffrt_queue_attr_init(&queue_attr);
ffrt_queue_attr_set_max_concurrency(&queue_attr, 1);
ffrt_queue_t queue_handle = ffrt_queue_create(static_cast<ffrt_queue_type_t>(ffrt_queue_eventhandler_adapter),
"queue_dump", &queue_attr);
char* buf = new char[BUFFER_SIZE];
// 提交10个任务并等待任务执行完成（任务名称：task1）
QueueDumpTask1Test(queue_handle, buf);
// 提交30个任务并等待任务执行完成（任务名称：task2）
QueueDumpTask2Test(queue_handle, buf);
// 提交1个睡眠3s的任务（任务名称：task3）
QueueDumpTask3Test(queue_handle, buf);
// 5种优先级各提交10个任务
QueueDumpPriorityTest(queue_handle, buf);
// 提交600个优先级为ffrt_inner_queue_priority_high的任务
QueueDumpMaxDumpSizeTest(queue_handle, buf);
// 验证ffrt_queue_size_dump结果
EXPECT_EQ(ffrt_queue_size_dump(queue_handle, ffrt_inner_queue_priority_immediate), TASK_NUM_10);
EXPECT_EQ(ffrt_queue_size_dump(queue_handle, ffrt_inner_queue_priority_high), TASK_NUM_610);
EXPECT_EQ(ffrt_queue_size_dump(queue_handle, ffrt_inner_queue_priority_low), TASK_NUM_10);
EXPECT_EQ(ffrt_queue_size_dump(queue_handle, ffrt_inner_queue_priority_idle), TASK_NUM_10);
EXPECT_EQ(ffrt_queue_size_dump(queue_handle, ffrt_inner_queue_priority_vip), TASK_NUM_10);
delete[] buf;
ffrt_queue_destroy(queue_handle);
ffrt_queue_attr_destroy(&queue_attr);
}