/** * Copyright 2020 Huawei Technologies Co., Ltd * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. * You may obtain a copy of the License at * * http://www.apache.org/licenses/LICENSE-2.0 * * Unless required by applicable law or agreed to in writing, software * distributed under the License is distributed on an "AS IS" BASIS, * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. * See the License for the specific language governing permissions and * limitations under the License. */ #include "debug/trace.h" #include #include #include #include #include #include #include #include #include #include #include "ir/meta_func_graph.h" #include "utils/graph_utils.h" #include "operator/composite/composite.h" #include "ir/meta_tensor.h" #include "debug/anf_ir_utils.h" #include "pipeline/static_analysis/evaluator.h" namespace mindspore { // namespace to support debug trace infomation namespace trace { std::string GetAbstractStr(const abstract::AbstractBasePtr &abs) { if (abs == nullptr) { return "Null Abstract"; } auto shape = abs->BuildShape()->cast(); TypePtr type = abs->BuildType(); std::ostringstream oss; if ((shape != nullptr) && (type != nullptr)) { oss << type->DumpText() << shape->DumpText(); } else if (type != nullptr) { oss << type->DumpText(); } else { oss << "Undefined"; } return oss.str(); } std::vector GetSourceCodeDebugInfoVec(DebugInfoPtr debug_info) { std::vector debug_with_loc_vec; while (debug_info != nullptr) { if (debug_info->location() != nullptr) { debug_with_loc_vec.push_back(debug_info); } if (debug_info->trace_info() != nullptr) { debug_info = debug_info->trace_info()->debug_info(); } else { break; } } return debug_with_loc_vec; } DebugInfoPtr GetSourceCodeDebugInfo(const DebugInfoPtr &info) { auto debug_with_loc_vec = GetSourceCodeDebugInfoVec(info); if (debug_with_loc_vec.size() > 0) { return debug_with_loc_vec[0]; } else { return info; } } std::string GetDebugInfo(const DebugInfoPtr &info, SourceLineTip tip) { if (info == nullptr) { return ""; } auto src_info = GetSourceCodeDebugInfo(info); if (src_info->location() != nullptr) { return src_info->location()->ToString(tip); } return ""; } // a trace info identifies a node transform, so we can trace the node transform through // a link of trace info and debug info std::string GetInfoWithAction(const std::vector &info_vec, SourceLineTip tip) { if (info_vec.size() < 1) { return ""; } if (info_vec.size() == 1) { return info_vec[0]->location()->ToString(tip); } std::string traced_info = info_vec[0]->location()->ToString(tip); for (size_t i = 1; i < info_vec.size(); i++) { auto action_name = info_vec[i - 1]->trace_info()->GetActionBetweenNode(info_vec[i]); if (action_name == "") { break; } traced_info = traced_info + action_name + info_vec[i]->location()->ToString(tip); } return traced_info; } std::string GetTracedDebugInfo(const DebugInfoPtr &info, SourceLineTip tip) { if (info == nullptr) { return ""; } auto info_vec = GetSourceCodeDebugInfoVec(info); if (info_vec.size() == 0) { return ""; } else if (info_vec.size() == 1) { return info_vec[0]->location()->ToString(tip); } else if (info_vec.size() > 1) { return GetInfoWithAction(info_vec, tip); } return ""; } std::string GetDebugInfo(const DebugInfoPtr &info, const std::string &prefix, SourceLineTip tip) { std::ostringstream oss; if (info == nullptr) { return ""; } auto debug_info = GetTracedDebugInfo(info, tip); if (tip == kSourceLineTipDiscard) { std::replace(debug_info.begin(), debug_info.end(), '\r', '/'); std::replace(debug_info.begin(), debug_info.end(), '\n', '/'); } oss << prefix << debug_info; return oss.str(); } std::string GetGraphParamString(const FuncGraphPtr &graph, abstract::AbstractBasePtrList args_spec_list) { std::ostringstream oss; oss << "graph:" << graph->ToString() << " with args["; auto params = graph->parameters(); for (size_t i = 0; i < args_spec_list.size(); i++) { oss << params[i]->ToString() << ":<" << GetAbstractStr(args_spec_list[i]) << ">,"; } oss << "]"; oss << GetDebugInfo(graph->debug_info(), kSourceLineTipDiscard); return oss.str(); } void DumpInferStack(std::ostringstream &oss) { auto &infer_stack = GetCurrenGraphInferStack(); if (infer_stack.empty()) { return; } std::vector> infer_vec; while (!infer_stack.empty()) { auto top = infer_stack.top(); infer_vec.push_back(top); infer_stack.pop(); } std::reverse(infer_vec.begin(), infer_vec.end()); int index = 0; for (auto &item : infer_vec) { auto graph_infer = std::dynamic_pointer_cast(item.first); if (graph_infer == nullptr) { MS_LOG(WARNING) << "DumpInferStack failed, got null graph evaluator"; infer_vec.clear(); break; } auto graph_context = graph_infer->graph_context(); if (graph_context == nullptr) { MS_LOG(INFO) << "Null context continue"; continue; } auto graph = graph_context->func_graph(); auto args_spec_list = graph_context->args_spec_list(); oss << " #" << index++ << " " << GetGraphParamString(graph, args_spec_list); } } void TraceGraphInfer() { auto &infer_stack = GetCurrenGraphInferStack(); std::ostringstream oss; if (infer_stack.empty()) { return; } MS_LOG(INFO) << "\n*******************************graph evaluate stack**********************************"; oss << std::endl; DumpInferStack(oss); MS_LOG(INFO) << oss.str(); MS_LOG(INFO) << "\n*************************************************************************************"; } class AnalyzedFuncGraphExporter : public AnfExporter { public: AnalyzedFuncGraphExporter() : AnfExporter("", true, false) {} ~AnalyzedFuncGraphExporter() override = default; void ExportFuncGraph(const std::string &filename, const std::vector &node_cfgs); private: std::string GetNodeType(const AnfNodePtr &nd) override; }; std::unordered_map CalcTaggedFuncGraphs() { std::unordered_map tagged_func_graphs; auto &list = GetCNodeDebugStack(); for (size_t i = 0; i < list.size(); ++i) { auto node_cfg = list[i]; auto fg = node_cfg->context()->func_graph(); auto node = node_cfg->node(); tagged_func_graphs[fg][node] = i; } return tagged_func_graphs; } void OutputAnalyzedGraphWithType() { AnalyzedFuncGraphExporter exporter; exporter.ExportFuncGraph("analyze_fail.dat", GetCNodeDebugStack()); } std::string AnalyzedFuncGraphExporter::GetNodeType(const AnfNodePtr &node) { if (node_cfg_ == nullptr) { return AnfExporter::GetNodeType(node); } auto ctx = node_cfg_->context(); auto engine = node_cfg_->engine(); auto cfg = engine->MakeConfig(node, ctx); auto abs = engine->cache().GetValue(cfg); if (abs == nullptr) { return "Undefined"; } auto dtype = abs->BuildType(); auto shape = abs->BuildShape(); std::ostringstream oss; if (dtype != nullptr && abs->isa() && shape != nullptr) { oss << dtype->DumpText() << shape->DumpText(); } else if (dtype != nullptr) { oss << dtype->DumpText(); } else { oss << "Undefined"; } return oss.str(); } void AnalyzedFuncGraphExporter::ExportFuncGraph(const std::string &filename, const std::vector &node_cfgs) { if (node_cfgs.empty()) { MS_LOG(DEBUG) << "Node configs is empty"; return; } std::ofstream ofs(filename); if (!ofs.is_open()) { MS_LOG(ERROR) << "Open file '" << filename << "' failed!"; return; } param_index = 1; auto tagged_func_graphs = CalcTaggedFuncGraphs(); // first output graph on the analysis stack for (const auto &node_cfg : node_cfgs) { auto fg = node_cfg->context()->func_graph(); // the graph is already output, skip it if (exported.find(fg) != exported.end()) { continue; } // set node_cfg info for getting type node_cfg_ = node_cfg; tagged_cnodes_ = tagged_func_graphs[fg]; ExportOneFuncGraph(ofs, fg); ofs << "\n\n"; } node_cfg_ = nullptr; tagged_cnodes_.clear(); // print seperator between function graphs on analyzed graph call stack and others ofs << "#===============================================================================\n\n\n"; // second output other graphs while (!func_graph_set.empty()) { FuncGraphPtr fg = *func_graph_set.begin(); ExportOneFuncGraph(ofs, fg); ofs << "\n\n"; (void)func_graph_set.erase(fg); } ofs << "# num of total function graphs: " << exported.size(); ofs.close(); } void GetInferStackInfo(std::ostringstream &oss) { MS_LOG(INFO) << "Get graph analysis information begin"; auto stack = GetCNodeDebugStack(); if (stack.empty()) { MS_LOG(INFO) << "Length of analysis information stack is empty."; return; } OutputAnalyzedGraphWithType(); oss << "\nThe function call stack:\n"; int index = 0; std::string last_py_func = ""; for (size_t i = 0; i < stack.size(); ++i) { auto node_cfg = stack[i]; auto cnode = dyn_cast(node_cfg->node()); if (cnode == nullptr) { MS_LOG(DEBUG) << "CNode of elements[" << i << "] is nullptr."; continue; } auto debug_info = cnode->debug_info(); auto this_py_func = debug_info->get_python_func_belonged(); if (i > 0 && (this_py_func == last_py_func)) { MS_LOG(DEBUG) << "Python function of elements[" << i << "] is same as previous."; continue; } last_py_func = this_py_func; oss << "# " << index++ << " " << trace::GetDebugInfo(debug_info, std::string("")); } stack.clear(); MS_LOG(INFO) << "Get graph analysis information *end*"; } // trace the graph evaluator stack static std::stack> graph_infer_stack; // trace the cnode infer debug info static std::vector cnode_debug_stack{}; void TraceGraphInferEnter(const abstract::EvaluatorPtr &eval, const abstract::AnfNodeConfigPtr &node) { if (eval == nullptr) { MS_LOG(EXCEPTION) << "GraphInferEnter got null eval"; } if (eval->isa() || eval->isa()) { graph_infer_stack.emplace(std::pair(eval, node)); } } void TraceGraphInferLeave(const abstract::EvaluatorPtr &eval) { if (eval == nullptr) { MS_LOG(EXCEPTION) << "GraphInferEnter got null eval"; } if (eval->isa() || eval->isa()) { graph_infer_stack.pop(); } } void TraceInferCNodeEnter(const abstract::AnfNodeConfigPtr &node_cfg) { cnode_debug_stack.push_back(node_cfg); } void TraceInferCNodeLeave() { cnode_debug_stack.pop_back(); } std::vector &GetCNodeDebugStack() { return cnode_debug_stack; } std::stack> &GetCurrenGraphInferStack() { return graph_infer_stack; } void ClearTraceStack() { while (!graph_infer_stack.empty()) { graph_infer_stack.pop(); } cnode_debug_stack.clear(); } } // namespace trace } // namespace mindspore