/** * Copyright 2019-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/tensor.h" #include "debug/anf_ir_utils.h" #include "pipeline/static_analysis/evaluator.h" namespace mindspore { // namespace to support debug trace infomation namespace trace { using abstract::AbstractBasePtr; using abstract::AnalysisContextPtr; using abstract::AnalysisEnginePtr; using abstract::AnfNodeConfigPtr; 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::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 TraceGraphEval() { 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); void ExportOneFuncGraph(std::ofstream &ofs, const FuncGraphPtr &func_graph); void OutputCNodes(std::ofstream &ofs, const std::vector &nodes, const FuncGraphPtr &func_graph); void OutputCNode(std::ofstream &ofs, const CNodePtr &cnode, const FuncGraphPtr &func_graph, int *idx, std::map *const apply_map); private: std::string GetNodeType(const AnfNodePtr &nd) override; AbstractBasePtr GetNodeAbstract(const AnfNodePtr &nd); AnfNodeConfigPtr GetFordwardConfigPtr(const AnfNodeConfigPtr &cfg); AnalysisContextPtr ProcessFuncGraphCall(const CNodePtr &node); // key: context, val: whether the context has already been printed std::unordered_map context_map_; std::vector context_vec_; AnalysisContextPtr cur_ctx_ = nullptr; AnalysisEnginePtr engine_ = nullptr; }; 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 (cur_ctx_ == nullptr) { return AnfExporter::GetNodeType(node); } MS_EXCEPTION_IF_NULL(engine_); auto cfg = engine_->MakeConfig(node, cur_ctx_); auto ret = engine_->cache().GetValue(cfg); if (ret == nullptr) { return "Undefined"; } auto abs = ret->abstract(); 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(); } AbstractBasePtr AnalyzedFuncGraphExporter::GetNodeAbstract(const AnfNodePtr &node) { if (cur_ctx_ == nullptr) { return nullptr; } MS_EXCEPTION_IF_NULL(engine_); auto cfg = engine_->MakeConfig(node, cur_ctx_); auto ret = engine_->cache().GetValue(cfg); return ret == nullptr ? nullptr : ret->abstract(); } AnfNodeConfigPtr AnalyzedFuncGraphExporter::GetFordwardConfigPtr(const AnfNodeConfigPtr &cfg) { AnfNodeConfigPtr cur_cfg = cfg; auto iter = engine_->anfnode_config_map().find(cur_cfg); while (iter != engine_->anfnode_config_map().end()) { auto node = cur_cfg->node(); cur_cfg = iter->second; MS_LOG(DEBUG) << "Get forword node: " << node.get() << "[" << node->ToString() << "] --> " << cur_cfg->node().get() << "[" << cur_cfg->node()->ToString() << "]"; iter = engine_->anfnode_config_map().find(cur_cfg); } return cur_cfg; } AnalysisContextPtr AnalyzedFuncGraphExporter::ProcessFuncGraphCall(const CNodePtr &node) { if (node == nullptr) { return nullptr; } auto cfg = engine_->MakeConfig(node, cur_ctx_); cfg = GetFordwardConfigPtr(cfg); auto cnode = dyn_cast(cfg->node()); if (cnode == nullptr) { MS_LOG(DEBUG) << "CNode is nullptr"; return nullptr; } const auto &inputs = cnode->inputs(); auto op_abs = GetNodeAbstract(inputs[0]); if (op_abs == nullptr) { MS_LOG(DEBUG) << "Abstract of inputs[0] of cnode " << cnode->ToString() << " is nullptr"; return nullptr; } if (!op_abs->isa() && !op_abs->isa()) { MS_LOG(DEBUG) << "Inputs[0] of cnode " << cnode->ToString() << " is of type " << op_abs->type_name() << ", not function, ignore it"; return nullptr; } auto evaluator = engine_->GetEvaluatorFor(dyn_cast(op_abs)); if (!evaluator->isa()) { MS_LOG(DEBUG) << "Evaluator for inputs[0] of cnode " << cnode->ToString() << " is of type " << evaluator->type_name() << ", not BaseFuncGraphEvaluator, ignore it."; return nullptr; } auto base_fg_evaluator = dyn_cast(evaluator); auto ctx = base_fg_evaluator->graph_context(); if (ctx != nullptr && context_map_.insert({ctx, false}).second) { MS_LOG(DEBUG) << "Add new context, ctx.addr = " << ctx.get() << "ctx = " << ctx->ToString(); context_vec_.push_back(ctx); } return ctx; } void AnalyzedFuncGraphExporter::OutputCNode(std::ofstream &ofs, const CNodePtr &cnode, const FuncGraphPtr &func_graph, int *idx, std::map *const apply_map) { auto &inputs = cnode->inputs(); std::string op_text = GetAnfNodeText(func_graph, inputs[0], *apply_map); // non-return node if (cnode != func_graph->get_return()) { int apply_idx = (*idx)++; (*apply_map)[cnode] = apply_idx; std::string type_info = GetNodeType(cnode); if (type_info == "Undefined") { ofs << " %" << apply_idx << " = " << op_text << "("; } else { ofs << " %" << apply_idx << " : " << type_info << " = " << op_text << "("; } } else { ofs << " " << op_text << "("; } for (size_t i = 1; i < inputs.size(); ++i) { if (i != 1) { ofs << ", "; } AnfNodePtr arg = inputs[i]; ofs << GetAnfNodeText(func_graph, arg, *apply_map); } ofs << ")"; // process function graph call auto ctx = ProcessFuncGraphCall(cnode); // output comment OutputStatementComment(ofs, cnode); if (ctx != nullptr) { ofs << " @ctx.addr=" << ctx.get(); } ofs << "\n"; if (label_manage::GetGlobalTraceLabelType() == label_manage::TraceLabelType::kWithUniqueId) { ofs << trace::GetDebugInfo(cnode->debug_info(), " # ", kSourceLineTipDiscard) << "#" << label_manage::Label(cnode->debug_info()) << "\n"; } else { ofs << trace::GetDebugInfo(cnode->debug_info(), " # ", kSourceLineTipDiscard) << "\n"; } } void AnalyzedFuncGraphExporter::OutputCNodes(std::ofstream &ofs, const std::vector &nodes, const FuncGraphPtr &func_graph) { if (func_graph == nullptr) { return; } int idx = 1; std::map apply_map; for (const AnfNodePtr &node : nodes) { MS_EXCEPTION_IF_NULL(node); if (!node->isa()) { continue; } auto iter = tagged_cnodes_.find(node); if (iter != tagged_cnodes_.end()) { ofs << "\n#------------------------> " << iter->second << "\n"; } auto cnode = node->cast(); OutputCNode(ofs, cnode, func_graph, &idx, &apply_map); } } void AnalyzedFuncGraphExporter::ExportOneFuncGraph(std::ofstream &ofs, const FuncGraphPtr &func_graph) { if (func_graph == nullptr) { return; } std::vector nodes = TopoSort(func_graph->get_return(), SuccIncoming, AlwaysInclude); std::vector parameters = func_graph->parameters(); OrderedMap param_map; ofs << "# [No." << (exported.size() + 1) << "] " << func_graph->DumpText() << "." << func_graph->debug_info()->get_id(); if (cur_ctx_ != nullptr) { ofs << " @ctx.addr=" << cur_ctx_.get(); } ofs << "\n"; if (label_manage::GetGlobalTraceLabelType() == label_manage::TraceLabelType::kWithUniqueId) { ofs << trace::GetDebugInfo(func_graph->debug_info(), "# ", kSourceLineTipDiscard) << "#" << label_manage::Label(func_graph->debug_info()) << "\n"; } else { ofs << trace::GetDebugInfo(func_graph->debug_info(), "# ", kSourceLineTipDiscard) << "\n"; } ofs << "funcgraph fg_" << func_graph->debug_info()->get_id(); // output name of parent of graph if exists if (func_graph->parent() != nullptr) { ofs << "[fg_" << func_graph->parent()->debug_info()->get_id() << "]"; } ofs << "(\n"; OutputParameters(ofs, parameters, ¶m_map); exported[func_graph] = param_map; ofs << (!parameters.empty() ? " " : "") << ") {\n"; OutputCNodes(ofs, nodes, func_graph); ofs << "}\n"; } void AnalyzedFuncGraphExporter::ExportFuncGraph(const std::string &filename, const std::vector &node_cfgs) { if (node_cfgs.empty()) { MS_LOG(DEBUG) << "Node configs is empty"; return; } context_map_.clear(); context_vec_.clear(); 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 ctx = node_cfg->context(); if (engine_ == nullptr) { engine_ = node_cfg->engine(); } if (context_map_.insert({ctx, false}).second) { context_vec_.push_back(ctx); } // the graph has already been printed if (context_map_[ctx]) { continue; } context_map_[ctx] = true; auto fg = ctx->func_graph(); // set current context cur_ctx_ = ctx; tagged_cnodes_ = tagged_func_graphs[fg]; ExportOneFuncGraph(ofs, fg); ofs << "\n\n"; } tagged_cnodes_.clear(); // print seperator between function graphs on analyzed graph call stack and others ofs << "#===============================================================================\n\n\n"; // second output other graphs size_t ctx_idx = 0; while (ctx_idx < context_vec_.size()) { auto ctx = context_vec_[ctx_idx++]; if (context_map_[ctx]) { continue; } context_map_[ctx] = true; cur_ctx_ = ctx; ExportOneFuncGraph(ofs, ctx->func_graph()); ofs << "\n\n"; } ofs << "# num of total function graphs: " << context_map_.size() << "\n"; ofs.close(); } void GetEvalStackInfo(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 TraceGraphEvalEnter(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 TraceGraphEvalLeave(const abstract::EvaluatorPtr &eval) { if (eval == nullptr) { MS_LOG(EXCEPTION) << "GraphInferEnter got null eval"; } if (eval->isa() || eval->isa()) { graph_infer_stack.pop(); } } void TraceEvalCNodeEnter(const abstract::AnfNodeConfigPtr &node_cfg) { cnode_debug_stack.push_back(node_cfg); } void TraceEvalCNodeLeave() { 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