1 /**
2 * Copyright 2019-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 "utils/info.h"
18 #include <fstream>
19 #include <sstream>
20 #include "ir/anf.h"
21 #include "ir/graph_utils.h"
22 #include "ir/func_graph.h"
23 #include "utils/convert_utils_base.h"
24 #include "utils/file_utils.h"
25 #include "utils/trace_base.h"
26 #include "utils/compile_config.h"
27
28 namespace mindspore {
29 namespace {
30 /// \brief Trace context stack for current thread.
31 thread_local std::vector<TraceContext> trace_context_stack_;
32
33 /// \brief Record a debug info for print.
34 thread_local DebugInfoPtr parser_debug_info_ = nullptr;
35
36 /// \brief A flag to decide whether record a debug info or not.
37 thread_local bool parser_debug_info_flag_ = false;
38 } // namespace
39
ClearThreadLocal()40 void ClearThreadLocal() {
41 trace_context_stack_.clear();
42 parser_debug_info_.reset();
43 }
44
HighlightLine(const std::string & line,int col_begin,int col_end,bool single_line,SourceLineTip tip)45 std::string HighlightLine(const std::string &line, int col_begin, int col_end, bool single_line, SourceLineTip tip) {
46 if (col_begin < col_end && col_begin != -1 && col_end <= SizeToLong(line.length()) && tip != kSourceLineTipDiscard) {
47 std::stringstream oss;
48 if (tip == kSourceLineTipInLine) {
49 if (single_line) {
50 std::string start = line.substr(0, LongToSize(col_begin));
51 std::string trimmed = line.substr(LongToSize(col_begin), LongToSize(col_end - col_begin));
52 std::string end = line.substr(LongToSize(col_end), LongToSize(SizeToLong(line.length()) - col_end));
53 oss << start << "<" << trimmed << ">" << end << "\n";
54 } else {
55 oss << line << "\n";
56 }
57 } else if (tip == kSourceLineTipNextLine) {
58 std::string start = line.substr(0, LongToSize(col_begin));
59 std::string start_spaces(start.length(), ' ');
60 oss << line << "\n" << start_spaces << "^";
61 if (single_line) {
62 for (size_t i = 1; i < LongToSize(col_end - col_begin); ++i) {
63 oss << "~";
64 }
65 }
66 } else if (tip == kSourceSectionTipNextLineHere) {
67 std::string start = line.substr(0, LongToSize(col_begin));
68 std::string start_spaces(start.length(), ' ');
69 oss << line << "\n" << start_spaces << "~<-------------HERE";
70 }
71 return oss.str();
72 }
73 return line;
74 }
75
DebugString() const76 std::string Location::DebugString() const {
77 std::stringstream ss;
78 ss << "Location{\n";
79 ss << "\tfile_name_: " << file_name_ << ",\n";
80 ss << "\tline_: " << line_ << ",\n";
81 ss << "\tline_end_: " << line_end_ << ",\n";
82 ss << "\tcolumn_: " << column_ << ",\n";
83 ss << "\tcolumn_end_: " << column_end_ << ",\n";
84 ss << "\tcomments_: " << comments_ << "\n";
85 ss << "}\n";
86 return ss.str();
87 }
88
89 // Generate debug information for the location node .
90 // print the file name, line no and column no, and part of the content
ToString(SourceLineTip tip,int start_line)91 std::string Location::ToString(SourceLineTip tip, int start_line) {
92 std::stringstream debug_info_ss;
93 std::stringstream section_debug_info_ss;
94 if (tip != kSourceSectionTipNextLineHere) {
95 // For example,
96 // the location is from {line 9, column 4}, to {line 15, column 20}:
97 // In file /x/xxx/x.py:9~15, 4~20
98 // If in single line, from {line 9, column 4}, to {line 9, column 20}:
99 // In file /x/xxx/x.py:9, 4~20
100 debug_info_ss << "In file " << file_name_ << ":" << line_;
101 if (line_ <= 0) {
102 return debug_info_ss.str();
103 }
104 if (line_end_ > line_) {
105 debug_info_ss << "~" << line_end_;
106 }
107 debug_info_ss << ", " << column_ << "~" << column_end_ << std::endl;
108 // Use line_str_ as cache.
109 if (!line_str_.empty()) {
110 debug_info_ss << HighlightLine(line_str_, column_, column_end_, line_end_ == line_, tip) << std::endl;
111 return debug_info_ss.str();
112 }
113 } else { // tip == kSourceSectionTipNextLineHere
114 section_debug_info_ss << "In file " << file_name_ << ":" << line_ << std::endl;
115 }
116
117 // Start read the specific line. Optimize here by seekg().
118 auto path = FileUtils::GetRealPath(file_name_.c_str());
119 if (!path.has_value()) {
120 MS_LOG(WARNING) << "The file '" << file_name_ << "' may not exists.";
121 return debug_info_ss.str();
122 }
123 std::ifstream file(path.value());
124 if (!file.is_open()) {
125 MS_LOG(WARNING) << "Failed to open file '" << file_name_ << "'.";
126 return debug_info_ss.str();
127 }
128 // Read the lines one by one.
129 int line_num = 0;
130 std::string line;
131 (void)getline(file, line);
132 while (line_num != line_ - 1) {
133 if (tip == kSourceSectionTipNextLineHere && line_num >= start_line - 1) {
134 section_debug_info_ss << line << "\n";
135 }
136 (void)getline(file, line);
137 line_num++;
138 }
139 file.close();
140 // Store the line string as cache.
141 line_str_ = line;
142
143 if (tip == kSourceSectionTipNextLineHere) {
144 section_debug_info_ss << HighlightLine(line, column_, column_end_, line_end_ == line_, tip) << std::endl;
145 return section_debug_info_ss.str();
146 }
147 debug_info_ss << HighlightLine(line, column_, column_end_, line_end_ == line_, tip) << std::endl;
148 return debug_info_ss.str();
149 }
150
operator <(const Location & other) const151 bool Location::operator<(const Location &other) const {
152 auto ret = file_name_.compare(other.file_name());
153 if (ret != 0) {
154 return ret < 0;
155 }
156 return line_ < other.line();
157 }
158
DebugInfo(const std::string & name)159 DebugInfo::DebugInfo(const std::string &name) : unique_id_(gen_unique_id()), name_(name) {
160 auto top = TraceManager::CurrentContextInfo();
161 if (top != nullptr) {
162 trace_info_ = top->trace_info();
163 location_ = top->location();
164 }
165 }
166
DebugInfo(const LocationPtr & loc)167 DebugInfo::DebugInfo(const LocationPtr &loc) : unique_id_(gen_unique_id()), location_(loc) {
168 auto top = TraceManager::CurrentContextInfo();
169 if (top != nullptr) {
170 trace_info_ = top->trace_info();
171 }
172 }
173
get_id() const174 size_t DebugInfo::get_id() const {
175 // cppcheck-suppress variableScope
176 static size_t current_id = 0;
177 if (id_ == 0) {
178 id_ = ++current_id;
179 }
180 return id_;
181 }
182
unique_id_through_copy() const183 size_t DebugInfo::unique_id_through_copy() const {
184 auto info = trace_info();
185 auto final_unique_id =
186 through_copy_unique_id_ == std::numeric_limits<size_t>::max() ? unique_id_ : through_copy_unique_id_;
187 if (info != nullptr) {
188 if (info->isa<TraceCopy>() && info->debug_info() != nullptr) {
189 final_unique_id = info->debug_info()->unique_id_through_copy();
190 }
191 }
192 const_cast<DebugInfo *>(this)->through_copy_unique_id_ = final_unique_id;
193 return final_unique_id;
194 }
195
GetDebugInfos(const DebugInfoPtr & debug_info)196 HashSet<DebugInfoPtr> GetDebugInfos(const DebugInfoPtr &debug_info) {
197 HashSet<DebugInfoPtr> debug_infos;
198 auto cur_debug_info = debug_info;
199 while (cur_debug_info != nullptr) {
200 (void)debug_infos.insert(cur_debug_info);
201 if (cur_debug_info->trace_info() == nullptr) {
202 break;
203 }
204 cur_debug_info = cur_debug_info->trace_info()->debug_info();
205 }
206 return debug_infos;
207 }
208
debug_name()209 std::string NodeDebugInfo::debug_name() {
210 if (!debug_name_.empty()) {
211 return debug_name_;
212 }
213 std::ostringstream oss;
214 oss << type_name_ << "_" << get_id();
215 debug_name_ = oss.str();
216 return debug_name_;
217 }
218
debug_name()219 std::string GraphDebugInfo::debug_name() {
220 if (debug_name_.empty()) {
221 debug_name_ = "_anonymous_"; // Represent <anonymous>
222 }
223 return debug_name_;
224 }
225
location() const226 LocationPtr GraphDebugInfo::location() const {
227 // Function may have decorator which is included in its location.
228 auto loc = DebugInfo::location();
229 if (deco_loc_ != nullptr && loc != nullptr) {
230 auto loc_line = loc->line() + ((deco_loc_->line_end() - deco_loc_->line()) + 1);
231 auto comments = loc->comments();
232 return std::make_shared<Location>(loc->file_name(), loc_line, loc->line_end(), loc->column(), loc->column_end(),
233 loc->expr_src(), std::move(comments));
234 }
235 return loc;
236 }
237
set_deco_location(const LocationPtr & deco_list_loc)238 void GraphDebugInfo::set_deco_location(const LocationPtr &deco_list_loc) { deco_loc_ = deco_list_loc; }
239
CurrentContextInfo()240 TraceContextPtr TraceManager::CurrentContextInfo() {
241 if (!trace_context_stack_.empty()) {
242 return &trace_context_stack_.back();
243 }
244 return nullptr;
245 }
246
DebugTrace(const LocationPtr & location)247 bool TraceManager::DebugTrace(const LocationPtr &location) {
248 MS_EXCEPTION_IF_NULL(location);
249 if (location->invalid()) {
250 MS_LOG(DEBUG) << "Trace failed";
251 return false;
252 }
253 (void)trace_context_stack_.emplace_back(location);
254 if (parser_debug_info_flag_) {
255 parser_debug_info_ = std::make_shared<DebugInfo>(location);
256 }
257 MS_LOG(DEBUG) << "location: " << location->ToString();
258 return true;
259 }
260
DebugTrace(const TraceInfoPtr & trace_info)261 bool TraceManager::DebugTrace(const TraceInfoPtr &trace_info) {
262 MS_EXCEPTION_IF_NULL(trace_info);
263 auto &debug_info = trace_info->debug_info();
264 MS_EXCEPTION_IF_NULL(debug_info);
265 (void)trace_context_stack_.emplace_back(trace_info);
266 if (parser_debug_info_flag_) {
267 parser_debug_info_ = debug_info;
268 }
269 return true;
270 }
271
EndTrace()272 void TraceManager::EndTrace() noexcept { trace_context_stack_.pop_back(); }
273
parser_debug_info()274 DebugInfoPtr TraceManager::parser_debug_info() { return parser_debug_info_; }
275
ClearParserDebugInfo()276 void TraceManager::ClearParserDebugInfo() { parser_debug_info_ = nullptr; }
277
CloseParserDebugInfoFlag()278 void TraceManager::CloseParserDebugInfoFlag() {
279 parser_debug_info_flag_ = false;
280 ClearParserDebugInfo();
281 }
282
OpenParserDebugInfoFlag()283 void TraceManager::OpenParserDebugInfoFlag() { parser_debug_info_flag_ = true; }
284
parser_debug_info_flag()285 bool TraceManager::parser_debug_info_flag() { return parser_debug_info_flag_; }
286
GetFirstLocation(const DebugInfoPtr & debug_info)287 LocationPtr GetFirstLocation(const DebugInfoPtr &debug_info) {
288 auto tmp = debug_info;
289 while (tmp != nullptr) {
290 if (tmp->location() != nullptr) {
291 return tmp->location();
292 }
293 if (tmp->trace_info() != nullptr) {
294 tmp = tmp->trace_info()->debug_info();
295 } else {
296 break;
297 }
298 }
299 return nullptr;
300 }
301
operator ()(const DebugInfoPtr & left,const DebugInfoPtr & right) const302 bool DebugInfoCompare::operator()(const DebugInfoPtr &left, const DebugInfoPtr &right) const {
303 MS_EXCEPTION_IF_NULL(left);
304 MS_EXCEPTION_IF_NULL(right);
305 if (left == right) {
306 return false;
307 }
308 auto left_loc = GetFirstLocation(left);
309 auto right_loc = GetFirstLocation(right);
310 if (left_loc == nullptr || right_loc == nullptr) {
311 return left < right;
312 }
313 if (left_loc == right_loc) {
314 return false;
315 }
316 return *left_loc < *right_loc;
317 }
318
UpdateDebugInfo(const FuncGraphPtr & func_graph,const ScopePtr & scope,const DebugInfoPtr & debug_info)319 void UpdateDebugInfo(const FuncGraphPtr &func_graph, const ScopePtr &scope, const DebugInfoPtr &debug_info) {
320 if (func_graph == nullptr || scope == nullptr || debug_info == nullptr) {
321 return;
322 }
323 auto nodes = TopoSort(func_graph->get_return(), SuccDeeperSimple);
324 TraceGuard guard(std::make_shared<TraceGenMetaFuncGraph>(debug_info));
325 for (const auto &node : nodes) {
326 if (!node->isa<CNode>()) {
327 continue;
328 }
329 node->set_scope(std::make_shared<Scope>(scope->name()));
330 node->set_debug_info(std::make_shared<NodeDebugInfo>());
331 }
332 }
333
334 namespace {
DumpNodesDebugInfos(const AnfNodePtr & caller,const AnfNodePtr & callee)335 void DumpNodesDebugInfos(const AnfNodePtr &caller, const AnfNodePtr &callee) {
336 const DebugInfoPtr &caller_debug_info = caller->debug_info();
337 const DebugInfoPtr &callee_debug_info = callee->debug_info();
338 const auto caller_debug_infos = GetDebugInfoList(caller_debug_info);
339 const auto callee_debug_infos = GetDebugInfoList(callee_debug_info);
340 MS_LOG(ERROR) << "caller: " << caller << "/" << caller->DebugString() << ", caller_debug_info: " << callee << "/"
341 << caller_debug_info << ", debug info size: " << caller_debug_infos.size();
342 MS_LOG(ERROR) << "callee: " << callee->DebugString() << ", callee_debug_info: " << callee_debug_info
343 << ", debug info size: " << callee_debug_infos.size();
344 for (size_t i = 0; i < caller_debug_infos.size(); ++i) {
345 MS_LOG(ERROR) << "# caller_debug_infos[" << i << "]: " << caller_debug_infos[i] << "/"
346 << caller_debug_infos[i]->name() << "/" << caller_debug_infos[i]->debug_name() << "/"
347 << trace::GetDebugInfoStr(caller_debug_infos[i], "", kSourceLineTipNextLine, true) << ", trace: "
348 << (caller_debug_infos[i]->trace_info() != nullptr ? caller_debug_infos[i]->trace_info()->name()
349 : "none");
350 }
351 for (size_t i = 0; i < callee_debug_infos.size(); ++i) {
352 MS_LOG(ERROR) << "# callee_debug_infos[" << i << "]: " << callee_debug_infos[i] << "/"
353 << callee_debug_infos[i]->name() << "/" << callee_debug_infos[i]->debug_name() << "/"
354 << trace::GetDebugInfoStr(callee_debug_infos[i], "", kSourceLineTipNextLine, true) << ", trace: "
355 << (callee_debug_infos[i]->trace_info() != nullptr ? callee_debug_infos[i]->trace_info()->name()
356 : "none");
357 }
358 }
359
SyncShadowDebugInfo(const DebugInfoPtr & caller_debug_info,const DebugInfoPtr & callee_debug_info)360 void SyncShadowDebugInfo(const DebugInfoPtr &caller_debug_info, const DebugInfoPtr &callee_debug_info) {
361 // Synchronize callers' shadow debug infos.
362 const auto &caller_shadow_debug_infos = caller_debug_info->shadow_debug_infos_map();
363 callee_debug_info->shadow_debug_infos_map().insert(caller_shadow_debug_infos.cbegin(),
364 caller_shadow_debug_infos.cend());
365 }
366 } // namespace
367
UpdateInlineCNodeDebugInfo(const AnfNodePtr & caller,const AnfNodePtr & callee)368 void UpdateInlineCNodeDebugInfo(const AnfNodePtr &caller, const AnfNodePtr &callee) {
369 const DebugInfoPtr &caller_debug_info = caller->debug_info();
370 const DebugInfoPtr &callee_debug_info = callee->debug_info();
371 const auto caller_debug_infos = GetDebugInfoList(caller_debug_info);
372 const auto callee_debug_infos = GetDebugInfoList(callee_debug_info);
373 if (callee_debug_infos.size() == 1) { // New inserted node, not by parser.
374 SyncShadowDebugInfo(caller_debug_info, callee_debug_info);
375 return;
376 }
377 int64_t pos = -1;
378 for (size_t i = 0; i < caller_debug_infos.size() && i < callee_debug_infos.size(); ++i) {
379 const auto &cur_caller_debug_info = caller_debug_infos[caller_debug_infos.size() - i - 1];
380 const auto &cur_callee_debug_info = callee_debug_infos[callee_debug_infos.size() - i - 1];
381 if (cur_caller_debug_info == cur_callee_debug_info) {
382 continue;
383 }
384 const auto &caller_locaton = cur_caller_debug_info->location();
385 const auto &callee_locaton = cur_callee_debug_info->location();
386 if (caller_locaton == nullptr || callee_locaton == nullptr) {
387 SyncShadowDebugInfo(caller_debug_info, callee_debug_info);
388 return;
389 }
390 if (caller_locaton != callee_locaton) {
391 pos = SizeToLong(i);
392 break;
393 }
394 }
395 if (pos == -1) {
396 SyncShadowDebugInfo(caller_debug_info, callee_debug_info);
397 return;
398 }
399 MS_LOG(DEBUG) << "pos: " << pos << ", caller_debug_info: " << caller_debug_info << "/"
400 << trace::GetDebugInfoStr(caller_debug_info, "", kSourceLineTipNextLine, true)
401 << ", callee_debug_info: " << callee_debug_info << "/"
402 << trace::GetDebugInfoStr(callee_debug_info, "", kSourceLineTipNextLine, true);
403 // Change the parse func debug info with call func debug info.
404 const int64_t callee_reverse_pos = SizeToLong(callee_debug_infos.size()) - pos - 1;
405 if (callee_reverse_pos < 0) {
406 DumpNodesDebugInfos(caller, callee);
407 MS_LOG(INTERNAL_EXCEPTION) << "Wrong index for callee.";
408 }
409 auto parse_def_debug_info = callee_debug_infos[callee_reverse_pos];
410 MS_EXCEPTION_IF_NULL(parse_def_debug_info);
411 const int64_t caller_reverse_pos = SizeToLong(caller_debug_infos.size()) - pos - 1;
412 if (caller_reverse_pos < 0) {
413 DumpNodesDebugInfos(caller, callee);
414 MS_LOG(INTERNAL_EXCEPTION) << "Wrong index for caller.";
415 }
416 auto first_diff_caller_debug_info = caller_debug_infos[caller_reverse_pos];
417 MS_LOG(DEBUG) << "reverse_pos: " << callee_reverse_pos << "/" << caller_reverse_pos
418 << ", callee_debug_info: " << callee_debug_info << ", parse_def_debug_info: " << parse_def_debug_info
419 << "/" << trace::GetDebugInfoStr(parse_def_debug_info, "", kSourceLineTipNextLine, true)
420 << ", first_diff_caller_debug_info: " << first_diff_caller_debug_info << "/"
421 << trace::GetDebugInfoStr(first_diff_caller_debug_info, "", kSourceLineTipNextLine, true);
422 // Insert inlined shadow debug info pair.
423 (void)callee_debug_info->shadow_debug_infos_map().emplace(parse_def_debug_info, first_diff_caller_debug_info);
424 // Synchronize callers' shadow debug infos.
425 SyncShadowDebugInfo(caller_debug_info, callee_debug_info);
426 }
427
GetDebugInfoList(const DebugInfoPtr & debug_info)428 std::vector<DebugInfoPtr> GetDebugInfoList(const DebugInfoPtr &debug_info) {
429 std::vector<DebugInfoPtr> debug_infos;
430 auto cur_debug_info = debug_info;
431 while (cur_debug_info != nullptr) {
432 (void)debug_infos.emplace_back(cur_debug_info);
433 if (cur_debug_info->trace_info() == nullptr) {
434 break;
435 }
436 cur_debug_info = cur_debug_info->trace_info()->debug_info();
437 }
438 return debug_infos;
439 }
440 } // namespace mindspore
441