1 /**
2 * Copyright 2021 Huawei Technologies Co., Ltd
3 *
4 * Licensed under the Apache License, Version 2.0 (the "License");
5 * you may not use this file except in compliance with the License.
6 * You may obtain a copy of the License at
7 *
8 * http://www.apache.org/licenses/LICENSE-2.0
9 *
10 * Unless required by applicable law or agreed to in writing, software
11 * distributed under the License is distributed on an "AS IS" BASIS,
12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13 * See the License for the specific language governing permissions and
14 * limitations under the License.
15 */
16
17 #include "pipeline/pynative/pynative_profiling.h"
18 #include "utils/profile.h"
19 #include "utils/ms_context.h"
20 #include "utils/utils.h"
21 #include "profiler/device/profiling.h"
22
23 namespace mindspore {
24 constexpr int kDeviceInfoCoutWidth = 25;
25 constexpr int kHostTimePointCoutWidth = 35;
26 constexpr int kHostTimeCoutWidth = 30;
27
SetEnableProfilingFlag()28 void PynativeProfiler::SetEnableProfilingFlag() {
29 static bool flag = false;
30 if (flag) {
31 return;
32 }
33 auto profiler_manager = profiler::ProfilerManager::GetInstance();
34 MS_EXCEPTION_IF_NULL(profiler_manager);
35 enable_profiler_flag_ = profiler_manager->GetProfilingEnableFlag();
36 flag = true;
37 }
38
Reset()39 void PynativeProfiler::Reset() {
40 stage_time_point_vec_.clear();
41 stage_stat_time_vec_.clear();
42 op_name_launch_time_point_vec_.clear();
43 op_name_launch_time_vec_.clear();
44 }
45
SetDeviceOpNameAndLaunchTimePoint(const std::pair<std::string,std::pair<double,double>> & name_start_end)46 void PynativeProfiler::SetDeviceOpNameAndLaunchTimePoint(
47 const std::pair<std::string, std::pair<double, double>> &name_start_end) {
48 if (!enable_profiler_flag_ || op_name_launch_time_point_vec_.size() > kMaxVectorSize) {
49 return;
50 }
51 op_name_launch_time_point_vec_.push_back(name_start_end);
52 }
53
SetDeviceOpNameAndLaunchCostTime(const std::pair<std::string,double> & name_time)54 void PynativeProfiler::SetDeviceOpNameAndLaunchCostTime(const std::pair<std::string, double> &name_time) {
55 if (!enable_profiler_flag_ || op_name_launch_time_vec_.size() > kMaxVectorSize) {
56 return;
57 }
58 op_name_launch_time_vec_.push_back(name_time);
59 }
60
ExportDeviceInfoToFile()61 void PynativeProfiler::ExportDeviceInfoToFile() {
62 MS_LOG(DEBUG) << "Op name launch time point vec size: " << op_name_launch_time_point_vec_.size();
63 if (!enable_profiler_flag_ || op_name_launch_time_point_vec_.empty()) {
64 return;
65 }
66 static std::ofstream of_device("device_profiling_data.csv", std::ios::app);
67 of_device.setf(std::ios::fixed, std::ios::floatfield);
68 of_device << "DeviceIndex" << ',' << "op_name" << ',' << "LaunchStartTime(s)" << ',' << "LaunchEndTime(s)" << ','
69 << "LaunchCostTime(ms)" << std::endl;
70 if (op_name_launch_time_point_vec_.size() != op_name_launch_time_vec_.size()) {
71 MS_LOG(EXCEPTION) << "The size of the two vector is not equal, the two vector size is "
72 << op_name_launch_time_point_vec_.size() << " and " << op_name_launch_time_vec_.size();
73 }
74 for (size_t i = 1; i <= op_name_launch_time_point_vec_.size(); ++i) {
75 of_device << i << ',' << op_name_launch_time_point_vec_[i - 1].first << ','
76 << op_name_launch_time_point_vec_[i - 1].second.first << ','
77 << op_name_launch_time_point_vec_[i - 1].second.second << ','
78 << op_name_launch_time_vec_[i - 1].second * kBasicTimeTransferUnit << std::endl;
79 }
80 op_name_launch_time_point_vec_.clear();
81 op_name_launch_time_vec_.clear();
82 }
83
ExportDeviceInfoToScreen()84 void PynativeProfiler::ExportDeviceInfoToScreen() {
85 MS_LOG(DEBUG) << "Op name launch time point vec size: " << op_name_launch_time_point_vec_.size();
86 if (!enable_profiler_flag_ || op_name_launch_time_point_vec_.empty()) {
87 return;
88 }
89 if (op_name_launch_time_point_vec_.size() != op_name_launch_time_vec_.size()) {
90 MS_LOG(EXCEPTION) << "The size of the two vector is not equal, the two vector size is "
91 << op_name_launch_time_point_vec_.size() << " and " << op_name_launch_time_vec_.size();
92 }
93 std::cout << "====================================DeviceInfo===================================" << std::endl;
94 std::vector<std::string> head_str = {"DeviceIndex", "op_name", "LaunchStartTime(s)", "LaunchEndTime(s)",
95 "LaunchCostTime(ms)"};
96 std::cout.setf(std::ios::fixed, std::ios::floatfield);
97 std::cout.setf(std::ios::left);
98 for (const auto &str : head_str) {
99 std::cout.width(kDeviceInfoCoutWidth);
100 std::cout << str;
101 }
102 std::cout << std::endl;
103 for (size_t i = 1; i <= op_name_launch_time_point_vec_.size(); ++i) {
104 std::cout.width(kDeviceInfoCoutWidth);
105 std::cout << i;
106 std::cout.width(kDeviceInfoCoutWidth);
107 std::cout << op_name_launch_time_point_vec_[i - 1].first;
108 std::cout.width(kDeviceInfoCoutWidth);
109 std::cout << op_name_launch_time_point_vec_[i - 1].second.first;
110 std::cout.width(kDeviceInfoCoutWidth);
111 std::cout << op_name_launch_time_point_vec_[i - 1].second.second;
112 std::cout.width(kDeviceInfoCoutWidth);
113 std::cout << op_name_launch_time_vec_[i - 1].second * kBasicTimeTransferUnit;
114 std::cout << std::endl;
115 }
116 std::cout << "==============================================================================" << std::endl;
117 }
118
SetStageTimePoint(const std::string & stage_name,const std::string & flag)119 void PynativeProfiler::SetStageTimePoint(const std::string &stage_name, const std::string &flag) {
120 if (!enable_profiler_flag_ || stage_time_point_vec_.size() > kMaxVectorSize) {
121 return;
122 }
123 stage_time_point_vec_.emplace_back(stage_name, std::make_pair(flag, GetTime()));
124 }
125
SetStageTimePointWithReturn(const std::string & stage_name,const std::string & flag)126 double PynativeProfiler::SetStageTimePointWithReturn(const std::string &stage_name, const std::string &flag) {
127 if (!enable_profiler_flag_ || stage_time_point_vec_.size() > kMaxVectorSize) {
128 return 0;
129 }
130 double tmp_time = GetTime();
131 stage_time_point_vec_.emplace_back(stage_name, std::make_pair(flag, GetTime()));
132 return tmp_time;
133 }
134
SetStageStatTime(const std::string & stage_name,double cost_time)135 void PynativeProfiler::SetStageStatTime(const std::string &stage_name, double cost_time) {
136 if (!enable_profiler_flag_ || stage_stat_time_vec_.size() > kMaxVectorSize) {
137 return;
138 }
139 stage_stat_time_vec_.emplace_back(stage_name, cost_time);
140 }
141
ExportStageTimePointToFile()142 void PynativeProfiler::ExportStageTimePointToFile() {
143 if (!enable_profiler_flag_ || stage_time_point_vec_.empty()) {
144 return;
145 }
146 static std::ofstream of_host("host_stage_time_point_profiling_data.csv", std::ios::app);
147 of_host.setf(std::ios::fixed, std::ios::floatfield);
148 for (size_t i = 0; i < stage_time_point_vec_.size(); ++i) {
149 if (i == 0) {
150 of_host << stage_time_point_vec_[i].first + stage_time_point_vec_[i].second.first + "Time(s)";
151 continue;
152 }
153 of_host << ',' << stage_time_point_vec_[i].first + stage_time_point_vec_[i].second.first + "Time(s)";
154 }
155 of_host << std::endl;
156 for (size_t i = 0; i < stage_time_point_vec_.size(); ++i) {
157 if (i == 0) {
158 of_host << stage_time_point_vec_[i].second.second;
159 continue;
160 }
161 of_host << ',' << stage_time_point_vec_[i].second.second;
162 }
163 of_host << std::endl;
164 stage_time_point_vec_.clear();
165 }
166
ExportStageTimePointToScreen()167 void PynativeProfiler::ExportStageTimePointToScreen() {
168 if (!enable_profiler_flag_ || stage_time_point_vec_.empty()) {
169 return;
170 }
171 std::cout << "===============================StageTimePoint=================================" << std::endl;
172 std::cout.setf(std::ios::fixed, std::ios::floatfield);
173 std::cout.setf(std::ios::left);
174 for (const auto &i : stage_time_point_vec_) {
175 std::cout.width(kHostTimePointCoutWidth);
176 std::cout << i.first + i.second.first + "Time(s)";
177 }
178 std::cout << std::endl;
179 for (const auto &i : stage_time_point_vec_) {
180 std::cout.width(kHostTimePointCoutWidth);
181 std::cout << i.second.second * kBasicTimeTransferUnit;
182 }
183 std::cout << std::endl;
184 std::cout << "==============================================================================" << std::endl;
185 }
186
ExportStageStatTimeToFile()187 void PynativeProfiler::ExportStageStatTimeToFile() {
188 if (!enable_profiler_flag_ || stage_stat_time_vec_.empty()) {
189 return;
190 }
191 static std::ofstream of_host("host_stage_stat_time_profiling_data.csv", std::ios::app);
192 of_host.setf(std::ios::fixed, std::ios::floatfield);
193 for (size_t i = 0; i < stage_stat_time_vec_.size(); ++i) {
194 if (i == 0) {
195 of_host << stage_stat_time_vec_[i].first + "Time(ms)";
196 continue;
197 }
198 of_host << ',' << stage_stat_time_vec_[i].first + "Time(ms)";
199 }
200 of_host << std::endl;
201 for (size_t i = 0; i < stage_stat_time_vec_.size(); ++i) {
202 if (i == 0) {
203 of_host << stage_stat_time_vec_[i].second * kBasicTimeTransferUnit;
204 continue;
205 }
206 of_host << ',' << stage_stat_time_vec_[i].second * kBasicTimeTransferUnit;
207 }
208 of_host << std::endl;
209 stage_stat_time_vec_.clear();
210 }
211
ExportStageStatTimeToScreen()212 void PynativeProfiler::ExportStageStatTimeToScreen() {
213 if (!enable_profiler_flag_ || stage_stat_time_vec_.empty()) {
214 return;
215 }
216 std::cout << "================================StageStatTime=================================" << std::endl;
217 std::cout.setf(std::ios::fixed, std::ios::floatfield);
218 std::cout.setf(std::ios::left);
219 for (const auto &i : stage_stat_time_vec_) {
220 std::cout.width(kHostTimeCoutWidth);
221 std::cout << i.first + "Time(ms)";
222 }
223 std::cout << std::endl;
224 for (const auto &i : stage_stat_time_vec_) {
225 std::cout.width(kHostTimeCoutWidth);
226 std::cout << i.second * kBasicTimeTransferUnit;
227 }
228 std::cout << std::endl;
229 std::cout << "==============================================================================" << std::endl;
230 }
231 } // namespace mindspore
232