1 /*
2 * Copyright (c) 2023 Huawei Device Co., Ltd.
3 * Licensed under the Apache License, Version 2.0 (the "License");
4 * you may not use this file except in compliance with the License.
5 * You may obtain a copy of the License at
6 *
7 * http://www.apache.org/licenses/LICENSE-2.0
8 *
9 * Unless required by applicable law or agreed to in writing, software
10 * distributed under the License is distributed on an "AS IS" BASIS,
11 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
12 * See the License for the specific language governing permissions and
13 * limitations under the License.
14 */
15 #ifdef FFRT_BBOX_ENABLE
16
17 #include "dfx/bbox/bbox.h"
18 #include <sys/syscall.h>
19 #include <sys/wait.h>
20 #include <unistd.h>
21 #include <csignal>
22 #include <cstdlib>
23 #include <string>
24 #include <sstream>
25 #include <vector>
26 #include "dfx/log/ffrt_log_api.h"
27 #include "dfx/trace_record/ffrt_trace_record.h"
28 #include "sched/scheduler.h"
29 #include "tm/queue_task.h"
30 #include "queue/queue_monitor.h"
31 #include "queue/traffic_record.h"
32 #include "tm/task_factory.h"
33 #include "eu/execute_unit.h"
34 #include "util/time_format.h"
35 #include "tm/uv_task.h"
36 #include "tm/io_task.h"
37 #ifdef OHOS_STANDARD_SYSTEM
38 #include "dfx/bbox/fault_logger_fd_manager.h"
39 #endif
40 #include "dfx/dump/dump.h"
41 #include "util/ffrt_facade.h"
42 #include "util/slab.h"
43
44 using namespace ffrt;
45
46 constexpr static size_t EACH_QUEUE_TASK_DUMP_SIZE = 64;
47 constexpr static unsigned int WAIT_PID_SLEEP_MS = 2;
48 constexpr static unsigned int WAIT_PID_MAX_RETRIES = 1000;
49 static std::atomic<unsigned int> g_taskPendingCounter(0);
50 static std::atomic<unsigned int> g_taskWakeCounter(0);
51 static TaskBase* g_cur_task;
52 static unsigned int g_cur_pid;
53 static unsigned int g_cur_tid;
54 static const char* g_cur_signame;
55
56 static struct sigaction s_oldSa[SIGSYS + 1]; // SIGSYS = 31
57
58 static FuncSaveKeyStatusInfo saveKeyStatusInfo = nullptr;
59 static FuncSaveKeyStatus saveKeyStatus = nullptr;
60 static FuncGetKeyStatus getKeyStatus = nullptr;
SetFuncSaveKeyStatus(FuncGetKeyStatus getFunc,FuncSaveKeyStatus saveFunc,FuncSaveKeyStatusInfo infoFunc)61 void SetFuncSaveKeyStatus(FuncGetKeyStatus getFunc, FuncSaveKeyStatus saveFunc, FuncSaveKeyStatusInfo infoFunc)
62 {
63 getKeyStatus = getFunc;
64 saveKeyStatus = saveFunc;
65 saveKeyStatusInfo = infoFunc;
66 }
67
TaskWakeCounterInc(void)68 void TaskWakeCounterInc(void)
69 {
70 ++g_taskWakeCounter;
71 }
72
TaskPendingCounterInc(void)73 void TaskPendingCounterInc(void)
74 {
75 ++g_taskPendingCounter;
76 }
77
SignalUnReg(int signo)78 static void SignalUnReg(int signo)
79 {
80 sigaction(signo, &s_oldSa[signo], nullptr);
81 }
82
BBoxDeInit()83 __attribute__((destructor)) static void BBoxDeInit()
84 {
85 SignalUnReg(SIGABRT);
86 SignalUnReg(SIGBUS);
87 SignalUnReg(SIGFPE);
88 SignalUnReg(SIGILL);
89 SignalUnReg(SIGSTKFLT);
90 SignalUnReg(SIGSYS);
91 SignalUnReg(SIGTRAP);
92 SignalUnReg(SIGINT);
93 SignalUnReg(SIGKILL);
94 }
95
SaveCurrent()96 static inline void SaveCurrent()
97 {
98 FFRT_BBOX_LOG("<<<=== current status ===>>>");
99 FFRT_BBOX_LOG("signal %s triggered: source pid %d, tid %d", g_cur_signame, g_cur_pid, g_cur_tid);
100 auto t = g_cur_task;
101 if (t) {
102 FFRT_BBOX_LOG("task id %lu, qos %d, name %s, status %s",
103 t->gid, t->qos_(), t->GetLabel().c_str(), StatusToString(t->curStatus));
104 }
105 }
106
107 #if (FFRT_TRACE_RECORD_LEVEL >= FFRT_TRACE_RECORD_LEVEL_2)
SaveTaskCounter()108 static inline void SaveTaskCounter()
109 {
110 FFRT_BBOX_LOG("<<<=== task counter ===>>>");
111 FFRT_BBOX_LOG("FFRT BBOX TaskSubmitCounter:%u TaskEnQueueCounter:%u TaskDoneCounter:%u",
112 FFRTTraceRecord::GetSubmitCount(), FFRTTraceRecord::GetEnqueueCount(), FFRTTraceRecord::GetDoneCount());
113 FFRT_BBOX_LOG("FFRT BBOX TaskRunCounter:%u TaskSwitchCounter:%u TaskFinishCounter:%u",
114 FFRTTraceRecord::GetRunCount(), FFRTTraceRecord::GetCoSwitchCount(), FFRTTraceRecord::GetFinishCount());
115 FFRT_BBOX_LOG("FFRT BBOX TaskWakeCounterInc:%u, TaskPendingCounter:%u",
116 g_taskWakeCounter.load(), g_taskPendingCounter.load());
117 if (FFRTTraceRecord::GetCoSwitchCount() + FFRTTraceRecord::GetFinishCount() == FFRTTraceRecord::GetRunCount()) {
118 FFRT_BBOX_LOG("TaskRunCounter equals TaskSwitchCounter + TaskFinishCounter");
119 } else {
120 FFRT_BBOX_LOG("TaskRunCounter is not equal to TaskSwitchCounter + TaskFinishCounter");
121 }
122 }
123 #endif
124
SaveLocalFifoStatus(int qos,CPUWorker * worker)125 static inline void SaveLocalFifoStatus(int qos, CPUWorker* worker)
126 {
127 auto sched = FFRTFacade::GetSchedInstance();
128 if (sched->GetTaskSchedMode(qos) == TaskSchedMode::DEFAULT_TASK_SCHED_MODE) { return; }
129 TaskBase* t = reinterpret_cast<TaskBase*>(sched->GetWorkerLocalQueue(qos, worker->Id())->PopHead());
130 while (t != nullptr) {
131 FFRT_BBOX_LOG("qos %d: worker tid %d is localFifo task id %lu name %s",
132 qos, worker->Id(), t->gid, t->GetLabel().c_str());
133 t = reinterpret_cast<TaskBase*>(sched->GetWorkerLocalQueue(qos, worker->Id())->PopHead());
134 }
135 }
136
SaveWorkerStatus()137 static inline void SaveWorkerStatus()
138 {
139 FFRT_BBOX_LOG("<<<=== worker status ===>>>");
140 for (int i = 0; i < QoS::MaxNum(); i++) {
141 CPUWorkerGroup& workerGroup = FFRTFacade::GetEUInstance().GetWorkerGroup(i);
142 std::shared_lock lck(workerGroup.tgMutex); /* acquire the lock in RO */
143 for (auto& thread : workerGroup.threads) {
144 SaveLocalFifoStatus(i, thread.first);
145 TaskBase* t = thread.first->curTask;
146 if (t == nullptr) {
147 FFRT_BBOX_LOG("qos %d: worker tid %d is running nothing", i, thread.first->Id());
148 continue;
149 }
150 FFRT_BBOX_LOG("qos %d: worker tid %d is running task", i, thread.first->Id());
151 }
152 }
153 }
154
SaveKeyStatus()155 static inline void SaveKeyStatus()
156 {
157 FFRT_BBOX_LOG("<<<=== key status ===>>>");
158 if (saveKeyStatus == nullptr) {
159 FFRT_BBOX_LOG("no key status");
160 return;
161 }
162 saveKeyStatus();
163 }
164
SaveNormalTaskStatus()165 static inline void SaveNormalTaskStatus()
166 {
167 TaskFactory<CPUEUTask>::LockMem();
168 auto unfree = TaskFactory<CPUEUTask>::GetUnfreedMem();
169 TaskFactory<CPUEUTask>::UnlockMem();
170 auto apply = [&](const char* tag, const std::function<bool(CPUEUTask*)>& filter) {
171 std::vector<CPUEUTask*> tmp;
172 for (auto task : unfree) {
173 auto t = reinterpret_cast<CPUEUTask*>(task);
174 auto f = reinterpret_cast<ffrt_function_header_t*>(t->func_storage);
175 if (((f->reserve[0] & MASK_FOR_HCS_TASK) != MASK_FOR_HCS_TASK) && filter(t)) {
176 tmp.emplace_back(t);
177 }
178 }
179 if (tmp.size() > 0) {
180 FFRT_BBOX_LOG("<<<=== %s ===>>>", tag);
181 }
182 size_t idx = 1;
183 for (auto t : tmp) {
184 if (t->type == ffrt_normal_task) {
185 FFRT_BBOX_LOG("<%zu/%lu> id %lu qos %d name %s", idx,
186 tmp.size(), t->gid, t->qos_(), t->GetLabel().c_str());
187 idx++;
188 }
189 if (t->coRoutine && (t->coRoutine->status.load() == static_cast<int>(CoStatus::CO_NOT_FINISH)) &&
190 t != g_cur_task) {
191 #ifdef FFRT_CO_BACKTRACE_OH_ENABLE
192 std::string dumpInfo;
193 DumpTask(t, dumpInfo, 1);
194 if (!dumpInfo.empty()) {
195 FFRT_BBOX_LOG("%s", dumpInfo.c_str());
196 }
197 #else
198 CoStart(t, GetCoRoutineEnv());
199 #endif // FFRT_CO_BACKTRACE_OH_ENABLE
200 }
201 }
202 };
203 // Do not dump tasks marked with a final status (e.g., FINISH or CANCELED),
204 // as they may be allocated by another submit and not initialized yet.
205 apply("pending task", [](CPUEUTask* t) {
206 return t->curStatus == TaskStatus::SUBMITTED;
207 });
208 apply("ready task", [](CPUEUTask* t) {
209 return t->curStatus == TaskStatus::READY;
210 });
211 apply("POPPED task", [](CPUEUTask* t) {
212 return t->curStatus == TaskStatus::POPPED;
213 });
214 apply("executing task", [](CPUEUTask* t) {
215 return t->curStatus == TaskStatus::EXECUTING;
216 });
217 apply("blocked by synchronization primitive(mutex etc) or wait dependence", [](CPUEUTask* t) {
218 return (t->curStatus == TaskStatus::THREAD_BLOCK) || (t->curStatus == TaskStatus::COROUTINE_BLOCK);
219 });
220 }
221
DumpQueueTask(const char * tag,const std::vector<QueueTask * > & tasks,const std::function<bool (QueueTask *)> & filter,size_t limit=EACH_QUEUE_TASK_DUMP_SIZE)222 static void DumpQueueTask(const char* tag, const std::vector<QueueTask*>& tasks,
223 const std::function<bool(QueueTask*)>& filter, size_t limit = EACH_QUEUE_TASK_DUMP_SIZE)
224 {
225 std::vector<QueueTask*> tmp;
226 for (auto t : tasks) {
227 if (tmp.size() < limit && filter(t)) {
228 tmp.emplace_back(t);
229 }
230 }
231 if (tmp.size() == 0) {
232 return;
233 }
234
235 FFRT_BBOX_LOG("<<<=== %s ===>>>", tag);
236 size_t idx = 1;
237 for (auto t : tmp) {
238 if (t->type == ffrt_queue_task) {
239 FFRT_BBOX_LOG("<%zu/%lu> id %lu qos %d name %s", idx, tmp.size(), t->gid, t->GetQos(), t->label.c_str());
240 idx++;
241 }
242 if (t->coRoutine && (t->coRoutine->status.load() == static_cast<int>(CoStatus::CO_NOT_FINISH))) {
243 #ifdef FFRT_CO_BACKTRACE_OH_ENABLE
244 std::string dumpInfo;
245 DumpTask(t, dumpInfo, 1);
246 if (!dumpInfo.empty()) {
247 FFRT_BBOX_LOG("%s", dumpInfo.c_str());
248 }
249 #else
250 CoStart(reinterpret_cast<CPUEUTask*>(t), GetCoRoutineEnv());
251 #endif // FFRT_CO_BACKTRACE_OH_ENABLE
252 }
253 }
254 }
255
SaveQueueTaskStatus()256 static inline void SaveQueueTaskStatus()
257 {
258 TaskFactory<QueueTask>::LockMem();
259 auto unfreeQueueTask = TaskFactory<QueueTask>::GetUnfreedMem();
260 TaskFactory<QueueTask>::UnlockMem();
261 if (unfreeQueueTask.size() == 0) {
262 return;
263 }
264
265 std::map<QueueHandler*, std::vector<QueueTask*>> taskMap;
266 for (auto t : unfreeQueueTask) {
267 auto task = reinterpret_cast<QueueTask*>(t);
268 if (task->type == ffrt_queue_task && task->curStatus != TaskStatus::FINISH && task->GetHandler() != nullptr) {
269 taskMap[task->GetHandler()].push_back(task);
270 }
271 }
272 if (taskMap.empty()) {
273 return;
274 }
275
276 for (auto entry : taskMap) {
277 std::sort(entry.second.begin(), entry.second.end(), [](QueueTask* first, QueueTask* second) {
278 return first->GetUptime() < second->GetUptime();
279 });
280 }
281
282 // Do not dump tasks marked with a final status (e.g., FINISH or CANCELLED),
283 // as they may be allocated by another submit and not initialized yet.
284 for (auto entry : taskMap) {
285 DumpQueueTask("queue task enqueued", entry.second, [](QueueTask* t) {
286 return t->curStatus == TaskStatus::ENQUEUED;
287 });
288 DumpQueueTask("queue task dequeued", entry.second, [](QueueTask* t) {
289 return t->curStatus == TaskStatus::DEQUEUED;
290 });
291 DumpQueueTask("queue task ready", entry.second, [](QueueTask* t) {
292 return t->curStatus == TaskStatus::READY;
293 });
294 DumpQueueTask("queue task POPPED", entry.second, [](QueueTask* t) {
295 return t->curStatus == TaskStatus::POPPED;
296 });
297 DumpQueueTask("queue task executing", entry.second, [](QueueTask* t) {
298 return t->curStatus == TaskStatus::EXECUTING;
299 });
300 DumpQueueTask("queue task blocked by synchronization primitive(mutex etc)", entry.second,
301 [](QueueTask* t) {
302 return (t->curStatus == TaskStatus::THREAD_BLOCK) || (t->curStatus == TaskStatus::COROUTINE_BLOCK);
303 });
304 }
305 }
306
SaveTimeoutTask()307 static inline void SaveTimeoutTask()
308 {
309 FFRT_BBOX_LOG("<<<=== Timeout Task Info ===>>>");
310
311 std::string normaltskTimeoutInfo = FFRTFacade::GetWMInstance().DumpTimeoutInfo();
312 std::string queueTimeoutInfo = FFRTFacade::GetQMInstance().DumpQueueTimeoutInfo();
313 std::stringstream ss;
314 ss << normaltskTimeoutInfo << queueTimeoutInfo;
315 FFRT_BBOX_LOG("%s", ss.str().c_str());
316 }
317
SaveQueueTrafficRecord()318 static inline void SaveQueueTrafficRecord()
319 {
320 FFRT_BBOX_LOG("<<<=== Queue Traffic Record ===>>>");
321
322 std::string trafficInfo = TrafficRecord::DumpTrafficInfo(false);
323 std::stringstream ss;
324 ss << trafficInfo;
325 FFRT_BBOX_LOG("%s", ss.str().c_str());
326 }
327
328 static std::atomic_uint g_bbox_tid_is_dealing {0};
329 static std::atomic_uint g_bbox_called_times {0};
330
BboxFreeze()331 void BboxFreeze()
332 {
333 while (g_bbox_tid_is_dealing.load() != 0) {
334 std::this_thread::sleep_for(std::chrono::milliseconds(WAIT_PID_SLEEP_MS));
335 }
336 }
337
backtrace(int ignoreDepth)338 void backtrace(int ignoreDepth)
339 {
340 #ifdef FFRT_CO_BACKTRACE_OH_ENABLE
341 std::string dumpInfo;
342 DumpTask(nullptr, dumpInfo, 1);
343 if (!dumpInfo.empty()) {
344 FFRT_BBOX_LOG("%s", dumpInfo.c_str());
345 }
346 #endif // FFRT_CO_BACKTRACE_OH_ENABLE
347 }
348
GetBboxEnableState(void)349 unsigned int GetBboxEnableState(void)
350 {
351 return g_bbox_tid_is_dealing.load();
352 }
353
GetBboxCalledTimes(void)354 unsigned int GetBboxCalledTimes(void)
355 {
356 return g_bbox_called_times.load();
357 }
358
FFRTIsWork()359 bool FFRTIsWork()
360 {
361 return FFRTTraceRecord::FfrtBeUsed();
362 }
363
RecordDebugInfo(void)364 void RecordDebugInfo(void)
365 {
366 auto t = ExecuteCtx::Cur()->task;
367 FFRT_BBOX_LOG("<<<=== ffrt debug log start ===>>>");
368
369 if (t != nullptr) {
370 FFRT_BBOX_LOG("debug log: tid %d, task id %lu, qos %d, name %s, status %s", gettid(), t->gid, t->qos_(),
371 t->GetLabel().c_str(), StatusToString(t->curStatus));
372 }
373 FFRT_BBOX_LOG("<<<=== key status ===>>>");
374 if (saveKeyStatusInfo == nullptr) {
375 FFRT_BBOX_LOG("no key status");
376 } else {
377 FFRT_BBOX_LOG("%s", saveKeyStatusInfo().c_str());
378 }
379 FFRT_BBOX_LOG("<<<=== ffrt debug log finish ===>>>");
380 }
381
382 /**
383 * @brief BBOX信息记录,包括task、queue、worker相关信息
384 *
385 * @param void
386 * @return void
387 * @约束:
388 * 1、FFRT模块收到信号,记录BBOX信息,支持信号如下:
389 * SIGABRT、SIGBUS、SIGFPE、SIGILL、SIGSTKFLT、SIGSTOP、SIGSYS、SIGTRAP
390 * @规格:
391 * 1.调用时机:FFRT模块收到信号时
392 * 2.影响:1)FFRT功能不可用,FFRT任务不再执行
393 * 2)影响范围仅影响FFRT任务运行,不能造成处理过程中的空指针等异常,如ffrt处理过程造成进行Crash
394 */
SaveTheBbox()395 void SaveTheBbox()
396 {
397 FFRT_BBOX_LOG("<<<=== ffrt black box(BBOX) start ===>>>");
398 SaveCurrent();
399 #if (FFRT_TRACE_RECORD_LEVEL >= FFRT_TRACE_RECORD_LEVEL_2)
400 SaveTaskCounter();
401 #endif
402 SaveWorkerStatus();
403 SaveKeyStatus();
404 SaveNormalTaskStatus();
405 SaveQueueTaskStatus();
406 SaveTimeoutTask();
407 SaveQueueTrafficRecord();
408 FFRT_BBOX_LOG("<<<=== ffrt black box(BBOX) finish ===>>>");
409 }
410
ResendSignal(siginfo_t * info)411 static void ResendSignal(siginfo_t* info)
412 {
413 int rc = syscall(SYS_rt_tgsigqueueinfo, getpid(), syscall(SYS_gettid), info->si_signo, info);
414 if (rc != 0) {
415 FFRT_LOGE("ffrt failed to resend signal during crash");
416 }
417 }
418
GetSigName(const siginfo_t * info)419 static const char* GetSigName(const siginfo_t* info)
420 {
421 switch (info->si_signo) {
422 case SIGABRT: return "SIGABRT";
423 case SIGBUS: return "SIGBUS";
424 case SIGFPE: return "SIGFPE";
425 case SIGILL: return "SIGILL";
426 case SIGSTKFLT: return "SIGSTKFLT";
427 case SIGSTOP: return "SIGSTOP";
428 case SIGSYS: return "SIGSYS";
429 case SIGTRAP: return "SIGTRAP";
430 default: return "?";
431 }
432 }
433
HandleChildProcess()434 static void HandleChildProcess()
435 {
436 BBoxDeInit();
437 pid_t childPid = (pid_t)syscall(SYS_clone, SIGCHLD, 0);
438 if (childPid == 0) {
439 // init is false to avoid deadlock occurs in the signal handling function due to memory allocation calls.
440 auto ctx = ExecuteCtx::Cur(false);
441 g_cur_task = ctx != nullptr ? ctx->task : nullptr;
442 g_bbox_tid_is_dealing.store(gettid());
443 SaveTheBbox();
444 g_bbox_tid_is_dealing.store(0);
445 #ifdef OHOS_STANDARD_SYSTEM
446 FaultLoggerFdManager::CloseFd();
447 #endif
448 _exit(0);
449 } else if (childPid > 0) {
450 pid_t wpid;
451 unsigned int remainingRetries = WAIT_PID_MAX_RETRIES;
452 while ((wpid = waitpid(childPid, nullptr, WNOHANG)) == 0 && remainingRetries-- > 0) {
453 std::this_thread::sleep_for(std::chrono::milliseconds(WAIT_PID_SLEEP_MS));
454 }
455 if (wpid == 0) {
456 (void)kill(childPid, SIGKILL);
457 }
458 }
459 }
460
SignalHandler(int signo,siginfo_t * info,void * context)461 static void SignalHandler(int signo, siginfo_t* info, void* context __attribute__((unused)))
462 {
463 unsigned int pid = static_cast<unsigned int>(getpid());
464 unsigned int tid = static_cast<unsigned int>(gettid());
465 unsigned int defaultTid = 0;
466 if (g_bbox_tid_is_dealing.compare_exchange_strong(defaultTid, tid)&&
467 FFRTIsWork() && g_bbox_called_times.fetch_add(1) == 0) { // only save once
468 g_cur_pid = pid;
469 g_cur_tid = tid;
470 g_cur_signame = GetSigName(info);
471 if (getKeyStatus != nullptr) {
472 getKeyStatus();
473 }
474 #ifdef OHOS_STANDARD_SYSTEM
475 FaultLoggerFdManager::InitFaultLoggerFd();
476 #endif
477 pid_t childPid = static_cast<pid_t>(syscall(SYS_clone, SIGCHLD, 0));
478 if (childPid == 0) {
479 HandleChildProcess();
480 _exit(0);
481 } else if (childPid > 0) {
482 waitpid(childPid, nullptr, 0);
483 g_bbox_tid_is_dealing.store(0);
484 }
485 } else {
486 struct timespec ts;
487 ts.tv_sec = 0;
488 ts.tv_nsec = WAIT_PID_SLEEP_MS * 1000000;
489 if (tid == g_bbox_tid_is_dealing.load()) {
490 g_bbox_tid_is_dealing.store(0);
491 } else {
492 while (g_bbox_tid_is_dealing.load() != 0) {
493 nanosleep(&ts, nullptr);
494 }
495 }
496 }
497 // we need to deregister our signal handler for that signal before continuing.
498 sigaction(signo, &s_oldSa[signo], nullptr);
499 ResendSignal(info);
500 }
501
SignalReg(int signo)502 static void SignalReg(int signo)
503 {
504 sigaction(signo, nullptr, &s_oldSa[signo]);
505 struct sigaction newAction = {};
506 newAction.sa_flags = SA_RESTART | SA_SIGINFO;
507 newAction.sa_sigaction = SignalHandler;
508 sigaction(signo, &newAction, nullptr);
509 }
510
BBoxInit()511 __attribute__((constructor)) static void BBoxInit()
512 {
513 SignalReg(SIGABRT);
514 SignalReg(SIGBUS);
515 SignalReg(SIGFPE);
516 SignalReg(SIGILL);
517 SignalReg(SIGSTKFLT);
518 SignalReg(SIGSYS);
519 SignalReg(SIGTRAP);
520 SignalReg(SIGINT);
521 SignalReg(SIGKILL);
522 }
523
GetDumpPreface(void)524 std::string GetDumpPreface(void)
525 {
526 std::ostringstream ss;
527 ss << "|-> Launcher proc ffrt, now:" << FormatDateToString(TimeStamp()) << " pid:" << GetPid()
528 << std::endl;
529 return ss.str();
530 }
531
532 #ifdef FFRT_CO_BACKTRACE_OH_ENABLE
533 #if (FFRT_TRACE_RECORD_LEVEL >= FFRT_TRACE_RECORD_LEVEL_2)
SaveTaskCounterInfo(void)534 std::string SaveTaskCounterInfo(void)
535 {
536 std::ostringstream ss;
537 ss << " |-> task counter" << std::endl;
538 ss << " TaskSubmitCounter:" << FFRTTraceRecord::GetSubmitCount() << " TaskEnQueueCounter:"
539 << FFRTTraceRecord::GetEnqueueCount() << " TaskDoneCounter:" << FFRTTraceRecord::GetDoneCount() << std::endl;
540
541 ss << " TaskRunCounter:" << FFRTTraceRecord::GetRunCount() << " TaskSwitchCounter:"
542 << FFRTTraceRecord::GetCoSwitchCount() << " TaskFinishCounter:" << FFRTTraceRecord::GetFinishCount()
543 << std::endl;
544
545 if (FFRTTraceRecord::GetCoSwitchCount() + FFRTTraceRecord::GetFinishCount() == FFRTTraceRecord::GetRunCount()) {
546 ss << " TaskRunCounter equals TaskSwitchCounter + TaskFinishCounter" << std::endl;
547 } else {
548 ss << " TaskRunCounter is not equal to TaskSwitchCounter + TaskFinishCounter" << std::endl;
549 }
550 return ss.str();
551 }
552 #endif // FFRT_TRACE_RECORD_LEVEL >= FFRT_TRACE_RECORD_LEVEL_2
553
AppendTaskInfo(std::ostringstream & oss,TaskBase * task)554 void AppendTaskInfo(std::ostringstream& oss, TaskBase* task)
555 {
556 if (task->fromTid) {
557 oss << " fromTid " << task->fromTid;
558 }
559 if (task->createTime) {
560 oss << " createTime " << FormatDateToString(task->createTime);
561 }
562 if (task->executeTime) {
563 oss << " executeTime " << FormatDateToString(task->executeTime);
564 }
565 }
566
SaveKeyInfo(void)567 std::string SaveKeyInfo(void)
568 {
569 std::ostringstream oss;
570
571 ffrt::FFRTFacade::GetEUInstance().WorkerInit();
572 oss << " |-> key status" << std::endl;
573 if (saveKeyStatusInfo == nullptr) {
574 oss << "no key status info" << std::endl;
575 return oss.str();
576 }
577 oss << saveKeyStatusInfo();
578 return oss.str();
579 }
580
DumpNormalTaskInfo(std::ostringstream & ss,int qos,pid_t tid,TaskBase * t)581 void DumpNormalTaskInfo(std::ostringstream& ss, int qos, pid_t tid, TaskBase* t)
582 {
583 {
584 TaskMemScopedLock<CPUEUTask> lock;
585 if (TaskFactory<CPUEUTask>::HasBeenFreed(static_cast<CPUEUTask*>(t))) {
586 return;
587 }
588 if (t->curStatus == TaskStatus::FINISH) {
589 return;
590 }
591 if (!IncDeleteRefIfPositive(t)) {
592 return;
593 }
594 }
595 ss << " qos " << qos
596 << ": worker tid " << tid
597 << " normal task is running, task id " << t->gid
598 << " name " << t->GetLabel().c_str()
599 << " status " << StatusToString(t->curStatus);
600 AppendTaskInfo(ss, t);
601 t->DecDeleteRef();
602 ss << std::endl;
603 }
604
DumpQueueTaskInfo(std::ostringstream & ss,int qos,pid_t tid,TaskBase * t)605 void DumpQueueTaskInfo(std::ostringstream& ss, int qos, pid_t tid, TaskBase* t)
606 {
607 {
608 TaskMemScopedLock<QueueTask> lock;
609 auto queueTask = reinterpret_cast<QueueTask*>(t);
610 if (TaskFactory<QueueTask>::HasBeenFreed(queueTask)) {
611 return;
612 }
613 if (queueTask->GetFinishStatus()) {
614 return;
615 }
616 if (!IncDeleteRefIfPositive(queueTask)) {
617 return;
618 }
619 }
620 ss << " qos " << qos
621 << ": worker tid " << tid
622 << " queue task is running, task id " << t->gid
623 << " name " << t->GetLabel().c_str()
624 << " status " << StatusToString(t->curStatus);
625 AppendTaskInfo(ss, t);
626 t->DecDeleteRef();
627 ss << std::endl;
628 }
629
DumpThreadTaskInfo(CPUWorker * thread,int qos,std::ostringstream & ss)630 void DumpThreadTaskInfo(CPUWorker* thread, int qos, std::ostringstream& ss)
631 {
632 TaskBase* t = thread->curTask;
633 pid_t tid = thread->Id();
634 if (t == nullptr) {
635 ss << " qos " << qos << ": worker tid " << tid << " is running nothing" << std::endl;
636 return;
637 }
638
639 switch (thread->curTaskType_.load(std::memory_order_relaxed)) {
640 case ffrt_normal_task: {
641 DumpNormalTaskInfo(ss, qos, tid, t);
642 return;
643 }
644 case ffrt_queue_task: {
645 DumpQueueTaskInfo(ss, qos, tid, t);
646 return;
647 }
648 case ffrt_io_task: {
649 ss << " qos "
650 << qos << ": worker tid "
651 << tid << " io task is running"
652 << std::endl;
653 return;
654 }
655 case ffrt_uv_task: {
656 ss << " qos " << qos
657 << ": worker tid " << tid
658 << " uv task is running"
659 << std::endl;
660 return;
661 }
662 default: {
663 return;
664 }
665 }
666 }
667
SaveWorkerStatusInfo(void)668 std::string SaveWorkerStatusInfo(void)
669 {
670 std::ostringstream ss;
671 std::ostringstream oss;
672 oss << " |-> worker count" << std::endl;
673 ss << " |-> worker status" << std::endl;
674 for (int i = 0; i < QoS::MaxNum(); i++) {
675 std::vector<int> tidArr;
676 CPUWorkerGroup& workerGroup = FFRTFacade::GetEUInstance().GetWorkerGroup(i);
677 std::shared_lock<std::shared_mutex> lck(workerGroup.tgMutex);
678 for (auto& thread : workerGroup.threads) {
679 tidArr.push_back(thread.first->Id());
680 DumpThreadTaskInfo(thread.first, i, ss);
681 }
682 if (tidArr.size() == 0) {
683 continue;
684 }
685 oss << " qos " << i << ": worker num:" << tidArr.size() << " tid:";
686 std::for_each(tidArr.begin(), tidArr.end(), [&](const int &t) {
687 if (&t == &tidArr.back()) {
688 oss << t;
689 } else {
690 oss << t << ", ";
691 }
692 });
693 oss << std::endl;
694 }
695 oss << ss.str();
696 return oss.str();
697 }
698
DumpCoYieldTaskBacktrace(CoTask * coTask,std::ostringstream & oss)699 void DumpCoYieldTaskBacktrace(CoTask* coTask, std::ostringstream& oss)
700 {
701 std::string dumpInfo;
702 std::unique_lock<std::mutex> lck(coTask->mutex_);
703 if (coTask->coRoutine && (coTask->coRoutine->status.load() == static_cast<int>(CoStatus::CO_NOT_FINISH))) {
704 DumpTask(coTask, dumpInfo, 1);
705 lck.unlock();
706 oss << dumpInfo.c_str();
707 }
708 }
709
SaveNormalTaskStatusInfo(void)710 std::string SaveNormalTaskStatusInfo(void)
711 {
712 std::string ffrtStackInfo;
713 std::ostringstream ss;
714 std::vector<void*> unfree = TaskFactory<CPUEUTask>::GetUnfreedTasksFiltered();
715 if (unfree.size() == 0) {
716 return ffrtStackInfo;
717 }
718
719 auto apply = [&](const char* tag, const std::function<bool(CPUEUTask*)>& filter) {
720 std::vector<CPUEUTask*> tmp;
721 for (auto task : unfree) {
722 auto t = reinterpret_cast<CPUEUTask*>(task);
723 auto f = reinterpret_cast<ffrt_function_header_t*>(t->func_storage);
724 if (((f->reserve[0] & MASK_FOR_HCS_TASK) != MASK_FOR_HCS_TASK) && filter(t)) {
725 tmp.emplace_back(reinterpret_cast<CPUEUTask*>(t));
726 }
727 }
728
729 if (tmp.size() > 0) {
730 ss << " |-> " << tag << std::endl;
731 ffrtStackInfo += ss.str();
732 }
733 size_t idx = 1;
734 for (auto t : tmp) {
735 ss.str("");
736 if (t->type == ffrt_normal_task) {
737 ss << " <" << idx++ << "/" << tmp.size() << ">" << "stack: task id " << t->gid << ",qos "
738 << t->qos_() << ",name " << t->GetLabel().c_str();
739 AppendTaskInfo(ss, t);
740 ss << std::endl;
741 }
742 DumpCoYieldTaskBacktrace(t, ss);
743 ffrtStackInfo += ss.str();
744 }
745 };
746
747 // Do not dump tasks marked with a final status (e.g., FINISH or CANCELLED),
748 // as they may be allocated by another submit and not initialized yet.
749 apply("pending task", [](CPUEUTask* t) {
750 return t->curStatus == TaskStatus::SUBMITTED;
751 });
752 apply("ready task", [](CPUEUTask* t) {
753 return t->curStatus == TaskStatus::READY;
754 });
755 apply("POPPED task", [](CPUEUTask* t) {
756 return t->curStatus == TaskStatus::POPPED;
757 });
758 apply("executing task", [](CPUEUTask* t) {
759 return t->curStatus == TaskStatus::EXECUTING;
760 });
761 apply("blocked by synchronization primitive(mutex etc) or wait dependence", [](CPUEUTask* t) {
762 return (t->curStatus == TaskStatus::THREAD_BLOCK) || (t->curStatus == TaskStatus::COROUTINE_BLOCK);
763 });
764 for (auto& task : unfree) {
765 reinterpret_cast<CPUEUTask*>(task)->DecDeleteRef();
766 }
767 return ffrtStackInfo;
768 }
769
DumpQueueTaskInfo(std::string & ffrtStackInfo,const char * tag,const std::vector<QueueTask * > & tasks,const std::function<bool (QueueTask *)> & filter,size_t limit=EACH_QUEUE_TASK_DUMP_SIZE)770 void DumpQueueTaskInfo(std::string& ffrtStackInfo, const char* tag, const std::vector<QueueTask*>& tasks,
771 const std::function<bool(QueueTask*)>& filter, size_t limit = EACH_QUEUE_TASK_DUMP_SIZE)
772 {
773 std::vector<QueueTask*> tmp;
774 for (auto t : tasks) {
775 if (tmp.size() < limit && filter(t)) {
776 tmp.emplace_back(t);
777 }
778 }
779 if (tmp.size() == 0) {
780 return;
781 }
782 std::ostringstream ss;
783 ss << "<<<=== " << tag << "===>>>" << std::endl;
784 ffrtStackInfo += ss.str();
785
786 size_t idx = 1;
787 for (auto t : tmp) {
788 ss.str("");
789 if (t->type == ffrt_queue_task) {
790 ss << "<" << idx++ << "/" << tmp.size() << ">" << "id " << t->gid << " qos "
791 << t->GetQos() << " name " << t->GetLabel().c_str();
792 AppendTaskInfo(ss, t);
793 ss << std::endl;
794 }
795 DumpCoYieldTaskBacktrace(t, ss);
796 ffrtStackInfo += ss.str();
797 }
798 }
799
SaveQueueTaskStatusInfo()800 std::string SaveQueueTaskStatusInfo()
801 {
802 std::string ffrtStackInfo;
803 std::vector<void*> unfree = TaskFactory<QueueTask>::GetUnfreedTasksFiltered();
804 if (unfree.size() == 0) {
805 return ffrtStackInfo;
806 }
807
808 std::map<QueueHandler*, std::vector<QueueTask*>> taskMap;
809 for (auto t : unfree) {
810 auto task = reinterpret_cast<QueueTask*>(t);
811 if (task->type == ffrt_queue_task && task->GetFinishStatus() == false && task->GetHandler() != nullptr) {
812 taskMap[task->GetHandler()].push_back(task);
813 }
814 }
815
816 for (auto entry : taskMap) {
817 std::sort(entry.second.begin(), entry.second.end(), [](QueueTask* first, QueueTask* second) {
818 return first->GetUptime() < second->GetUptime();
819 });
820 }
821
822 // Do not dump tasks marked with a final status (e.g., FINISH or CANCELLED),
823 // as they may be allocated by another submit and not initialized yet.
824 for (auto entry : taskMap) {
825 ffrtStackInfo += "\n";
826 DumpQueueTaskInfo(ffrtStackInfo, "queue task enqueued", entry.second, [](QueueTask* t) {
827 return t->curStatus == TaskStatus::ENQUEUED;
828 });
829 DumpQueueTaskInfo(ffrtStackInfo, "queue task dequeued", entry.second, [](QueueTask* t) {
830 return t->curStatus == TaskStatus::DEQUEUED;
831 });
832 DumpQueueTaskInfo(ffrtStackInfo, "queue task ready", entry.second, [](QueueTask* t) {
833 return t->curStatus == TaskStatus::READY;
834 });
835 DumpQueueTaskInfo(ffrtStackInfo, "queue task POPPED", entry.second, [](QueueTask* t) {
836 return t->curStatus == TaskStatus::POPPED;
837 });
838 DumpQueueTaskInfo(ffrtStackInfo, "queue task executing", entry.second, [](QueueTask* t) {
839 return t->curStatus == TaskStatus::EXECUTING;
840 });
841 DumpQueueTaskInfo(ffrtStackInfo, "queue task blocked by synchronization primitive(mutex etc)", entry.second,
842 [](QueueTask* t) {
843 return (t->curStatus == TaskStatus::THREAD_BLOCK) || (t->curStatus == TaskStatus::COROUTINE_BLOCK);
844 });
845 }
846
847 for (auto& task : unfree) {
848 reinterpret_cast<QueueTask*>(task)->DecDeleteRef();
849 }
850 return ffrtStackInfo;
851 }
852
SaveTimeoutTaskInfo()853 std::string SaveTimeoutTaskInfo()
854 {
855 std::string ffrtStackInfo;
856 std::ostringstream ss;
857 ss << "<<<=== Timeout Task Info ===>>>" << std::endl;
858 ffrtStackInfo += ss.str();
859 std::string timeoutInfo = FFRTFacade::GetWMInstance().DumpTimeoutInfo();
860 std::string queueTimeoutInfo = FFRTFacade::GetQMInstance().DumpQueueTimeoutInfo();
861 ffrtStackInfo += timeoutInfo;
862 ffrtStackInfo += queueTimeoutInfo;
863 return ffrtStackInfo;
864 }
865
SaveQueueTrafficRecordInfo()866 std::string SaveQueueTrafficRecordInfo()
867 {
868 std::string ffrtStackInfo;
869 std::ostringstream ss;
870 ss << "<<<=== Queue Traffic Record ===>>>" << std::endl;
871 ffrtStackInfo += ss.str();
872 std::string trafficInfo = TrafficRecord::DumpTrafficInfo();
873 ffrtStackInfo += trafficInfo;
874 return ffrtStackInfo;
875 }
876 #endif
877 #endif /* FFRT_BBOX_ENABLE */
878