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()
22 : {
23 41 : return &g_acprof[g_curLoopCnt];
24 : }
25 :
26 2 : void AicpuKfcProf::SetCurrentProf(uint64_t launchTime)
27 : {
28 2 : g_acprof[g_curLoopCnt].tid = syscall(__NR_gettid);
29 2 : g_acprof[g_curLoopCnt].launchEntryTime = launchTime;
30 2 : }
31 :
32 3 : void AicpuKfcProf::SetKfcTimeLine(KfcTimeLine kfcTimeLine)
33 : {
34 3 : if (!AicpuKfcProf::NeedRecordTimeTaken()) {
35 3 : return;
36 : }
37 0 : AicpuComProf *acprof = AicpuKfcProf::GetCurrentAicpuProf();
38 0 : uint32_t recordIndex = acprof->workCnt;
39 0 : recordIndex = (recordIndex >= AC_MAX_PROF_COMM_CNT) ? (AC_MAX_PROF_COMM_CNT - 1) : recordIndex;
40 0 : switch (kfcTimeLine) {
41 0 : case KfcTimeLine::HCC_EXEC_START_TIME:
42 0 : acprof->commLoop[recordIndex].hccExecStartTime = GetCurCpuTimestamp(true);
43 0 : break;
44 0 : case KfcTimeLine::SEND_TASK_START_TIME:
45 0 : acprof->commLoop[recordIndex].sendTaskStartTime = GetCurCpuTimestamp(true);
46 0 : break;
47 0 : case KfcTimeLine::SEND_SQE_FINISH_TIME:
48 0 : acprof->commLoop[recordIndex].sendSqeFinishTime = GetCurCpuTimestamp(true);
49 0 : break;
50 0 : default:
51 0 : break;
52 : }
53 0 : return;
54 : }
55 :
56 10 : void AicpuKfcProf::SetDebugMode(uint8_t debugMode)
57 : {
58 10 : debugMode_ = debugMode;
59 10 : }
60 :
61 121 : bool AicpuKfcProf::IsDebugModeEquals(const uint8_t mode)
62 : {
63 121 : return debugMode_ == mode;
64 : }
65 :
66 9 : bool AicpuKfcProf::NeedRecordTimeTaken()
67 : {
68 9 : return IsDebugModeEquals(MC2_DEBUG_TIME_TAKEN) || dfx::ProfilingManager::GetProfL1State();
69 : }
70 :
71 6 : AicpuComProf *AicpuKfcProf::GetaicpuProfInst() {
72 6 : return &g_acprof[0];
73 : }
74 :
75 48 : void AicpuKfcProf::AddProfLoopCnt(u32 addCnt)
76 : {
77 48 : g_curLoopCnt = (g_curLoopCnt + addCnt) % AC_MAX_PROF_LOOP;
78 48 : HCCL_INFO("g_curLoopCnt set to %u", g_curLoopCnt);
79 48 : }
80 :
81 48 : void AicpuKfcProf::OutputProfLog(bool debugFlag, AicpuComProf *profInfo, AicpuComProf *backupProfInfo)
82 : {
83 48 : if (!debugFlag || g_curLoopCnt < AC_MAX_PROF_LOOP - 1) {
84 47 : return;
85 : }
86 : thread_local static u32 profIdx = 0U;
87 30 : for (u32 i = 0; i < AC_MAX_PROF_LOOP - 1; i++) {
88 29 : AicpuComProf *prof = &(profInfo[i]);
89 29 : if (prof->workCnt <= 0 && backupProfInfo != nullptr) {
90 29 : prof = &(backupProfInfo[i]);
91 : }
92 29 : u32 workRcdCnt = prof->workCnt > AC_MAX_PROF_COMM_CNT ? AC_MAX_PROF_COMM_CNT : prof->workCnt;
93 29 : HCCL_RUN_INFO("OP %u: clusterID %u, tid %lu, rankId %u, workCnt %u, serverStartTime %lu, waitMsgStartTime "
94 : "%lu, rtsqExeEndTime %lu, serverEndTime %lu, StartServer %lu, Finalize %lu, E2E %lu",
95 : profIdx + i, prof->clusterId, prof->tid, prof->rankId, prof->workCnt,
96 : prof->launchEntryTime, prof->commInitEndTime, prof->receiveFinalizeTime,
97 : prof->endTime, prof->commInitEndTime - prof->launchEntryTime,
98 : prof->endTime - prof->receiveFinalizeTime, prof->endTime - prof->launchEntryTime);
99 :
100 29 : for (u32 j = 0; j < workRcdCnt; j++) {
101 0 : AicpuComProfCommLoop *commRcd = &prof->commLoop[j];
102 0 : HCCL_RUN_INFO("Turn %u: kfcAlgExeStartTime %lu, sendTaskStartTime %lu, sendSqeFinishTime %lu, "
103 : "TaskWaitRequest %lu, TaskOrchestration %lu, TaskLaunch %lu, TaskExecute %lu",
104 : j + 1, commRcd->hccExecStartTime, commRcd->sendTaskStartTime, commRcd->sendSqeFinishTime,
105 : commRcd->hccExecStartTime - prof->commInitEndTime,
106 : commRcd->sendTaskStartTime - commRcd->hccExecStartTime,
107 : commRcd->sendSqeFinishTime - commRcd->sendTaskStartTime,
108 : prof->receiveFinalizeTime - commRcd->sendSqeFinishTime);
109 : }
110 :
111 29 : prof->fillSqeCnt = 0;
112 29 : prof->fillSqeTimes = 0;
113 29 : prof->sendSqeBatch = 0;
114 29 : prof->sendSqeTimes = 0;
115 29 : prof->workCnt = 0;
116 29 : prof->traceSubmitTime = 0;
117 29 : prof->traceCtxTime = 0;
118 29 : prof->traceSqeTime = 0;
119 : }
120 1 : profIdx += AC_MAX_PROF_LOOP;
121 : }
122 :
123 522 : AicpuComProf &AicpuKfcProf::GetProInst(AicpuComContext &ctx)
124 : {
125 522 : return ctx.acprof[g_curLoopCnt];
126 : }
|