Line data Source code
1 : /**
2 : * Copyright (c) 2025 Huawei Technologies Co., Ltd.
3 : * This program is free software, you can redistribute it and/or modify it under the terms and conditions of
4 : * CANN Open Software License Agreement Version 2.0 (the "License").
5 : * Please refer to the License for details. You may not use this file except in compliance with the License.
6 : * THIS SOFTWARE IS PROVIDED ON AN "AS IS" BASIS, WITHOUT WARRANTIES OF ANY KIND, EITHER EXPRESS OR IMPLIED,
7 : * INCLUDING BUT NOT LIMITED TO NON-INFRINGEMENT, MERCHANTABILITY, OR FITNESS FOR A PARTICULAR PURPOSE.
8 : * See LICENSE in the root of the software repository for the full text of the License.
9 : */
10 :
11 : #include "aicpu_kfc_prof.h"
12 :
13 : #include "common/aicpu_hccl_common.h"
14 : #include "common/aicpu_kfc_def.h"
15 : #include "profiling_manager_device.h"
16 :
17 : thread_local static uint32_t g_curLoopCnt = 0;
18 : thread_local static AicpuComProf g_acprof[AC_MAX_PROF_LOOP];
19 : uint8_t AicpuKfcProf::debugMode_ = 0;
20 :
21 41 : AicpuComProf* AicpuKfcProf::GetCurrentAicpuProf() { return &g_acprof[g_curLoopCnt]; }
22 :
23 2 : void AicpuKfcProf::SetCurrentProf(uint64_t launchTime)
24 : {
25 2 : g_acprof[g_curLoopCnt].tid = syscall(__NR_gettid);
26 2 : g_acprof[g_curLoopCnt].launchEntryTime = launchTime;
27 2 : }
28 :
29 3 : void AicpuKfcProf::SetKfcTimeLine(KfcTimeLine kfcTimeLine)
30 : {
31 3 : if (!AicpuKfcProf::NeedRecordTimeTaken()) {
32 3 : return;
33 : }
34 0 : AicpuComProf* acprof = AicpuKfcProf::GetCurrentAicpuProf();
35 0 : uint32_t recordIndex = acprof->workCnt;
36 0 : recordIndex = (recordIndex >= AC_MAX_PROF_COMM_CNT) ? (AC_MAX_PROF_COMM_CNT - 1) : recordIndex;
37 0 : switch (kfcTimeLine) {
38 0 : case KfcTimeLine::HCC_EXEC_START_TIME:
39 0 : acprof->commLoop[recordIndex].hccExecStartTime = GetCurCpuTimestamp(true);
40 0 : break;
41 0 : case KfcTimeLine::SEND_TASK_START_TIME:
42 0 : acprof->commLoop[recordIndex].sendTaskStartTime = GetCurCpuTimestamp(true);
43 0 : break;
44 0 : case KfcTimeLine::SEND_SQE_FINISH_TIME:
45 0 : acprof->commLoop[recordIndex].sendSqeFinishTime = GetCurCpuTimestamp(true);
46 0 : break;
47 0 : default:
48 0 : break;
49 : }
50 0 : return;
51 : }
52 :
53 10 : void AicpuKfcProf::SetDebugMode(uint8_t debugMode) { debugMode_ = debugMode; }
54 :
55 121 : bool AicpuKfcProf::IsDebugModeEquals(const uint8_t mode) { return debugMode_ == mode; }
56 :
57 9 : bool AicpuKfcProf::NeedRecordTimeTaken()
58 : {
59 9 : return IsDebugModeEquals(MC2_DEBUG_TIME_TAKEN) || dfx::ProfilingManager::GetProfL1State();
60 : }
61 :
62 6 : AicpuComProf* AicpuKfcProf::GetaicpuProfInst() { return &g_acprof[0]; }
63 :
64 48 : void AicpuKfcProf::AddProfLoopCnt(u32 addCnt)
65 : {
66 48 : g_curLoopCnt = (g_curLoopCnt + addCnt) % AC_MAX_PROF_LOOP;
67 48 : HCCL_INFO("g_curLoopCnt set to %u", g_curLoopCnt);
68 48 : }
69 :
70 48 : void AicpuKfcProf::OutputProfLog(bool debugFlag, AicpuComProf* profInfo, AicpuComProf* backupProfInfo)
71 : {
72 48 : if (!debugFlag || g_curLoopCnt < AC_MAX_PROF_LOOP - 1) {
73 47 : return;
74 : }
75 : thread_local static u32 profIdx = 0U;
76 30 : for (u32 i = 0; i < AC_MAX_PROF_LOOP - 1; i++) {
77 29 : AicpuComProf* prof = &(profInfo[i]);
78 29 : if (prof->workCnt <= 0 && backupProfInfo != nullptr) {
79 29 : prof = &(backupProfInfo[i]);
80 : }
81 29 : u32 workRcdCnt = prof->workCnt > AC_MAX_PROF_COMM_CNT ? AC_MAX_PROF_COMM_CNT : prof->workCnt;
82 29 : HCCL_RUN_INFO(
83 : "OP %u: clusterID %u, tid %lu, rankId %u, workCnt %u, serverStartTime %lu, waitMsgStartTime "
84 : "%lu, rtsqExeEndTime %lu, serverEndTime %lu, StartServer %lu, Finalize %lu, E2E %lu",
85 : profIdx + i, prof->clusterId, prof->tid, prof->rankId, prof->workCnt, prof->launchEntryTime,
86 : prof->commInitEndTime, prof->receiveFinalizeTime, prof->endTime,
87 : prof->commInitEndTime - prof->launchEntryTime, prof->endTime - prof->receiveFinalizeTime,
88 : prof->endTime - prof->launchEntryTime);
89 :
90 29 : for (u32 j = 0; j < workRcdCnt; j++) {
91 0 : AicpuComProfCommLoop* commRcd = &prof->commLoop[j];
92 0 : HCCL_RUN_INFO(
93 : "Turn %u: kfcAlgExeStartTime %lu, sendTaskStartTime %lu, sendSqeFinishTime %lu, "
94 : "TaskWaitRequest %lu, TaskOrchestration %lu, TaskLaunch %lu, TaskExecute %lu",
95 : j + 1, commRcd->hccExecStartTime, commRcd->sendTaskStartTime, commRcd->sendSqeFinishTime,
96 : commRcd->hccExecStartTime - prof->commInitEndTime,
97 : commRcd->sendTaskStartTime - commRcd->hccExecStartTime,
98 : commRcd->sendSqeFinishTime - commRcd->sendTaskStartTime,
99 : prof->receiveFinalizeTime - commRcd->sendSqeFinishTime);
100 : }
101 :
102 29 : prof->fillSqeCnt = 0;
103 29 : prof->fillSqeTimes = 0;
104 29 : prof->sendSqeBatch = 0;
105 29 : prof->sendSqeTimes = 0;
106 29 : prof->workCnt = 0;
107 29 : prof->traceSubmitTime = 0;
108 29 : prof->traceCtxTime = 0;
109 29 : prof->traceSqeTime = 0;
110 : }
111 1 : profIdx += AC_MAX_PROF_LOOP;
112 : }
113 :
114 522 : AicpuComProf& AicpuKfcProf::GetProInst(AicpuComContext& ctx) { return ctx.acprof[g_curLoopCnt]; }
|