• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
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