From 36db75b4f445365c8c28b4b4db269d2be8571b1e Mon Sep 17 00:00:00 2001 From: Zhanlue Yang Date: Tue, 15 Mar 2022 13:24:16 +0800 Subject: [PATCH] Added more profile signposts to dygraph (#40201) * Added more signposts to dygraph profiling * Fixed minor issues * Refactored signpost names * Fixed typo * Removed debug codes * Fixed typo * Adjusted signpost names * Fixed issues from branch merge --- .../auto_code_generator/eager_generator.cc | 33 ++++++++++++++++--- .../final_state_generator/eager_gen.py | 16 ++++++++- .../final_state_generator/python_c_gen.py | 9 +++-- paddle/fluid/eager/backward.cc | 9 +++++ paddle/fluid/imperative/basic_engine.cc | 5 ++- paddle/fluid/imperative/tracer.cc | 31 +++++++++-------- python/paddle/utils/code_gen/api_base.py | 12 +++++-- python/paddle/utils/code_gen/api_gen.py | 3 ++ .../paddle/utils/code_gen/backward_api_gen.py | 2 ++ 9 files changed, 97 insertions(+), 23 deletions(-) diff --git a/paddle/fluid/eager/auto_code_generator/eager_generator.cc b/paddle/fluid/eager/auto_code_generator/eager_generator.cc index dc79a8a45a2..6a2e5e7ac6c 100644 --- a/paddle/fluid/eager/auto_code_generator/eager_generator.cc +++ b/paddle/fluid/eager/auto_code_generator/eager_generator.cc @@ -1553,9 +1553,23 @@ static std::pair GenerateForwardFunctionContents( core_ops_returns_info[op_type] = return_contents; // [Generation] ComputeRequireGrad -> GradNodeCreation + if (!bwd_info.GenerateForwardOnly()) { std::string grad_node_creation_body_str = GenerateGradNodeCreationContent(fwd_info, bwd_info); + + // Add event record + std::string event_name = op_type + " node_creation"; + const char* NODE_CREATION_TEMPLATE = + "{\n" + " paddle::platform::RecordEvent node_creation_record_event(\"%s\", " + "paddle::platform::TracerEventType::Operator, 1);\n" + " %s\n" + "}"; + + grad_node_creation_body_str = paddle::string::Sprintf( + NODE_CREATION_TEMPLATE, event_name, grad_node_creation_body_str); + generated_function_body += grad_node_creation_body_str; generated_function_body += "\n"; @@ -1614,10 +1628,20 @@ static std::pair GenerateForwardFunctionContents( if ((*iter) == ',') dygraph_function_args_str.erase(iter); } - const char* FWD_FUNCTION_TEMPLATE = "%s %s(%s) {\n\n%s\n}\n\n"; + const char* DYGRAPH_FUNCTION_EVENT_RECORD_FUNCTION_TEMPLATE = + "paddle::platform::RecordEvent dygraph_entrance_record_event(\"%s\", " + "paddle::platform::TracerEventType::Operator, 1);"; + std::string event_name = op_type + " dygraph"; + std::string fwd_record_event_str = paddle::string::Sprintf( + DYGRAPH_FUNCTION_EVENT_RECORD_FUNCTION_TEMPLATE, event_name); + const char* FWD_FUNCTION_TEMPLATE = + "%s %s(%s) {\n\n" + " %s\n" + " %s\n" + "}\n\n"; std::string fwd_function_str = paddle::string::Sprintf( FWD_FUNCTION_TEMPLATE, function_proto_return_type_str, function_name, - dygraph_function_args_str, generated_function_body); + dygraph_function_args_str, fwd_record_event_str, generated_function_body); // [Generation] Generate forward functions header const char* FWD_HEADER_TEMPLATE = "%s %s(%s);\n"; @@ -2240,8 +2264,9 @@ static void GenerateForwardDygraphFile(const std::string& forward_cc_path, "\"paddle/fluid/eager/api/generated/fluid_generated/" "dygraph_forward_api.h\"\n" "#include " - "\"paddle/fluid/eager/api/generated/fluid_generated/nodes/nodes.h\"\n\n" - "#include \"paddle/fluid/eager/api/utils/global_utils.h\"\n"; + "\"paddle/fluid/eager/api/generated/fluid_generated/nodes/nodes.h\"\n" + "#include \"paddle/fluid/eager/api/utils/global_utils.h\"\n" + "#include \"paddle/fluid/platform/profiler/event_tracing.h\"\n\n"; std::string forward_cc_include_str = paddle::string::Sprintf(FORWARD_INCLUDE_TEMPLATE); std::ofstream forward_cc_stream(forward_cc_path, std::ios::out); diff --git a/paddle/fluid/eager/auto_code_generator/final_state_generator/eager_gen.py b/paddle/fluid/eager/auto_code_generator/final_state_generator/eager_gen.py index 537c2bb7f02..656418a05ad 100644 --- a/paddle/fluid/eager/auto_code_generator/final_state_generator/eager_gen.py +++ b/paddle/fluid/eager/auto_code_generator/final_state_generator/eager_gen.py @@ -923,8 +923,20 @@ def GenerateForwardDefinition(fwd_api_name, bwd_api_name, backward_fwd_input_map, backward_grad_input_map, backward_grad_output_map, backward_attrs_list, optional_inputs) + node_event_name = fwd_api_name + " node_creation" + NODE_CREATION_TEMPLATE = """{{\n + paddle::platform::RecordEvent node_creation_record_event(\"{}\", paddle::platform::TracerEventType::Operator, 1);\n + {}\n + }}""" + node_creation_str = NODE_CREATION_TEMPLATE.format(node_event_name, + node_creation_str) + + dygraph_event_str = f"paddle::platform::RecordEvent dygraph_entrance_record_event(\"{fwd_api_name} dygraph\", paddle::platform::TracerEventType::Operator, 1);" + FORWARD_FUNCTION_TEMPLATE = """ {} {}({}) {{ + {} + // Forward API Call {} @@ -938,7 +950,7 @@ def GenerateForwardDefinition(fwd_api_name, bwd_api_name, forward_function_name = GetForwardFunctionName(fwd_api_name) forward_function_str = FORWARD_FUNCTION_TEMPLATE.format( returns_type_str, forward_function_name, inputs_args_definition_str, - forward_call_str, node_creation_str, returns_str) + dygraph_event_str, forward_call_str, node_creation_str, returns_str) forward_function_declaration_str = f"{returns_type_str} {forward_function_name}({inputs_args_declaration_str});" return forward_function_str, forward_function_declaration_str @@ -1065,6 +1077,8 @@ def GenerateForwardCCFile(filepath, forward_definition_str): #include "paddle/phi/api/include/sparse_api.h" #include "paddle/fluid/eager/api/utils/global_utils.h" +#include "paddle/fluid/platform/profiler/event_tracing.h" + """ file_contents += GenerateCoreOpInfoDefinition() diff --git a/paddle/fluid/eager/auto_code_generator/final_state_generator/python_c_gen.py b/paddle/fluid/eager/auto_code_generator/final_state_generator/python_c_gen.py index eee32a2c505..9b77f0449e0 100644 --- a/paddle/fluid/eager/auto_code_generator/final_state_generator/python_c_gen.py +++ b/paddle/fluid/eager/auto_code_generator/final_state_generator/python_c_gen.py @@ -94,9 +94,13 @@ def GeneratePythonCFunction(fwd_api_name, forward_inputs_position_map, dygraph_function_call_list[pos] = f"{name}" dygraph_function_call_str = ",".join(dygraph_function_call_list) + pythonc_event_str = f"paddle::platform::RecordEvent pythonc_record_event(\"{fwd_api_name} pybind_imperative_func\", paddle::platform::TracerEventType::Operator, 1);" + PYTHON_C_FUNCTION_TEMPLATE = """ static PyObject * eager_final_state_api_{}(PyObject *self, PyObject *args, PyObject *kwargs) {{ + {} + PyThreadState *tstate = nullptr; try {{ @@ -136,8 +140,8 @@ static PyObject * eager_final_state_api_{}(PyObject *self, PyObject *args, PyObj fwd_function_name = namespace_str + GetForwardFunctionName(fwd_api_name) python_c_function_str = PYTHON_C_FUNCTION_TEMPLATE.format( - fwd_api_name, fwd_api_name, get_eager_tensor_str, parse_attributes_str, - fwd_function_name, dygraph_function_call_str) + fwd_api_name, pythonc_event_str, fwd_api_name, get_eager_tensor_str, + parse_attributes_str, fwd_function_name, dygraph_function_call_str) python_c_function_reg_str = f"{{\"final_state_{fwd_api_name}\", (PyCFunction)(void(*)(void)) {namespace_str}eager_final_state_api_{fwd_api_name}, METH_VARARGS | METH_KEYWORDS, \"C++ interface function for {fwd_api_name} in dygraph.\"}}\n" @@ -231,6 +235,7 @@ def GeneratePythonCWrappers(python_c_function_str, python_c_function_reg_str): #include "paddle/fluid/pybind/op_function_common.h" #include "paddle/fluid/eager/api/generated/eager_generated/forwards/dygraph_functions.h" #include "paddle/fluid/pybind/exception.h" +#include "paddle/fluid/platform/profiler/event_tracing.h" #include namespace paddle {{ diff --git a/paddle/fluid/eager/backward.cc b/paddle/fluid/eager/backward.cc index 603f93d9ddc..1987d024d8f 100644 --- a/paddle/fluid/eager/backward.cc +++ b/paddle/fluid/eager/backward.cc @@ -19,6 +19,8 @@ #include "paddle/fluid/eager/grad_node_info.h" #include "paddle/fluid/eager/grad_tensor_holder.h" #include "paddle/fluid/eager/utils.h" +#include "paddle/fluid/platform/profiler.h" +#include "paddle/fluid/platform/profiler/event_tracing.h" #include "paddle/fluid/platform/enforce.h" #include "paddle/fluid/platform/errors.h" @@ -77,6 +79,9 @@ std::unordered_map getInDegreeMap( void RunBackward(const std::vector& tensors, const std::vector& grad_tensors, bool retain_graph) { + paddle::platform::RecordEvent backward_record_event( + "backward", paddle::platform::TracerEventType::Operator, 1); + VLOG(6) << "Start Backward"; // *Gradient Hook should happen at node-level // *Inplace version check should perform at node-level @@ -160,6 +165,10 @@ void RunBackward(const std::vector& tensors, while (!queue.empty()) { GradNodeBase* node = queue.front(); + paddle::platform::RecordEvent node_record_event( + std::string(typeid(*node).name()) + " grad_node", + paddle::platform::TracerEventType::Operator, 1); + if (queue.size() > 1 && node_in_degree_map[node] != 0) { queue.pop(); continue; diff --git a/paddle/fluid/imperative/basic_engine.cc b/paddle/fluid/imperative/basic_engine.cc index 7416d206fc4..d7478b18dba 100644 --- a/paddle/fluid/imperative/basic_engine.cc +++ b/paddle/fluid/imperative/basic_engine.cc @@ -389,6 +389,9 @@ static void PerformBackwardInplace(const std::string& op_type, } void BasicEngine::Execute() { + platform::RecordEvent backward_record_event( + "backward", platform::TracerEventType::Operator, 1); + if (init_nodes_.empty()) { return; } @@ -412,7 +415,7 @@ void BasicEngine::Execute() { for (auto& cur_op : *shared_cur_node) { platform::RecordEvent op_type_record_event( - cur_op.Type(), platform::TracerEventType::Operator, 1); + cur_op.Type() + " grad_node", platform::TracerEventType::Operator, 1); ++op_num; diff --git a/paddle/fluid/imperative/tracer.cc b/paddle/fluid/imperative/tracer.cc index 01c9d2847e0..c55599cc9aa 100644 --- a/paddle/fluid/imperative/tracer.cc +++ b/paddle/fluid/imperative/tracer.cc @@ -177,7 +177,7 @@ void Tracer::TraceOp(const std::string& type, const NameVarMap& ins, paddle::framework::AttributeMap* passed_default_attrs_, bool use_default_attr_map) { platform::RecordEvent op_type_record_event( - type, platform::TracerEventType::Operator, 1); + type + " trace_op", platform::TracerEventType::Operator, 1); platform::ScopedFlushDenormal flush; VLOG(1) << "Trace Op: " << type; if (FLAGS_use_mkldnn) { @@ -297,19 +297,24 @@ void Tracer::TraceOp(const std::string& type, const NameVarMap& ins, program_desc_tracer_->InsertOp(type, new_ins, outs, attrs); } - if (ComputeRequiredGrad(new_ins, outs, trace_backward)) { - PADDLE_ENFORCE_EQ( - passed_default_attrs_, nullptr, - paddle::platform::errors::PermissionDenied( - "We expect passed_default_attrs_ is nullptr while " - "use_default_attr_map is true, however we got not null " - "passed_default_attrs_. Please check your usage of trace_op. ")); - CreateGradOpNode(*op, new_ins, outs, attrs, default_attrs, place, - inplace_map); - } else { - VLOG(3) << "No Grad to track for Op: " << type; + { + platform::RecordEvent node_creation_record_event( + type + " node_creation", platform::TracerEventType::Operator, 1); + + if (ComputeRequiredGrad(new_ins, outs, trace_backward)) { + PADDLE_ENFORCE_EQ( + passed_default_attrs_, nullptr, + paddle::platform::errors::PermissionDenied( + "We expect passed_default_attrs_ is nullptr while " + "use_default_attr_map is true, however we got not null " + "passed_default_attrs_. Please check your usage of trace_op. ")); + CreateGradOpNode(*op, new_ins, outs, attrs, default_attrs, place, + inplace_map); + } else { + VLOG(3) << "No Grad to track for Op: " << type; + } + VLOG(6) << "Finish Trace Op: " << type; } - VLOG(6) << "Finish Trace Op: " << type; } template void Tracer::TraceOp( diff --git a/python/paddle/utils/code_gen/api_base.py b/python/paddle/utils/code_gen/api_base.py index fe68548a22a..d91b76bb703 100644 --- a/python/paddle/utils/code_gen/api_base.py +++ b/python/paddle/utils/code_gen/api_base.py @@ -696,6 +696,7 @@ PADDLE_API {self.gene_return_type_code()} {self.get_api_func_name() + '_'}({self code_indent) outputs_args, kernel_output_names, output_create = self.gene_output( self.outputs['types'], 'SetKernelOutput', code_indent, inplace_flag) + api_func_name = self.get_api_func_name() + ('_' if inplace_flag else '') return f""" {code_indent} auto kernel = phi::KernelFactory::Instance().SelectKernelOrThrowError( {code_indent} "{self.kernel['func'][0]}", {{kernel_backend, kernel_layout, kernel_data_type}}); @@ -709,7 +710,10 @@ PADDLE_API {self.gene_return_type_code()} {self.get_api_func_name() + '_'}({self {code_indent} using kernel_signature = {kernel_signature}; {code_indent} auto* kernel_fn = kernel.GetVariadicKernelFn(); -{code_indent} (*kernel_fn)({kernel_args}, {outputs_args}); +{code_indent} {{ +{code_indent} paddle::platform::RecordEvent kernel_record_event(\"{api_func_name} compute\", paddle::platform::TracerEventType::Operator, 1); +{code_indent} (*kernel_fn)({kernel_args}, {outputs_args}); +{code_indent} }} {code_indent} return {self.gene_return_code()};""" @@ -719,6 +723,7 @@ PADDLE_API {self.gene_return_type_code()} {self.get_api_func_name() + '_'}({self outputs_args, kernel_output_names, output_create = self.gene_output( self.outputs['types'], 'SetSelectedRowsKernelOutput', code_indent, inplace_flag) + api_func_name = self.get_api_func_name() + ('_' if inplace_flag else '') return f""" {code_indent} auto kernel = phi::KernelFactory::Instance().SelectKernelOrThrowError( {code_indent} "{self.kernel['func'][1]}", {{kernel_backend, kernel_layout, kernel_data_type}}); @@ -732,7 +737,10 @@ PADDLE_API {self.gene_return_type_code()} {self.get_api_func_name() + '_'}({self {code_indent} using kernel_signature = {kernel_signature}; {code_indent} auto* kernel_fn = kernel.GetVariadicKernelFn(); -{code_indent} (*kernel_fn)({kernel_args}, {outputs_args}); +{code_indent} {{ +{code_indent} paddle::platform::RecordEvent kernel_record_event(\"{api_func_name} compute\", paddle::platform::TracerEventType::Operator, 1); +{code_indent} (*kernel_fn)({kernel_args}, {outputs_args}); +{code_indent} }} {code_indent} return {self.gene_return_code()};""" diff --git a/python/paddle/utils/code_gen/api_gen.py b/python/paddle/utils/code_gen/api_gen.py index a404fc01784..98a3606952b 100644 --- a/python/paddle/utils/code_gen/api_gen.py +++ b/python/paddle/utils/code_gen/api_gen.py @@ -147,6 +147,9 @@ def source_include(header_file_path): #include "paddle/phi/infermeta/multiary.h" #include "paddle/phi/infermeta/nullary.h" #include "paddle/phi/infermeta/unary.h" +#include "paddle/phi/kernels/declarations.h" + +#include "paddle/fluid/platform/profiler/event_tracing.h" """ diff --git a/python/paddle/utils/code_gen/backward_api_gen.py b/python/paddle/utils/code_gen/backward_api_gen.py index 7417d6bb030..5506f71f4b6 100644 --- a/python/paddle/utils/code_gen/backward_api_gen.py +++ b/python/paddle/utils/code_gen/backward_api_gen.py @@ -154,6 +154,8 @@ def source_include(header_file_path): #include "paddle/phi/core/kernel_registry.h" #include "paddle/phi/api/include/api.h" #include "paddle/phi/infermeta/backward.h" + +#include "paddle/fluid/platform/profiler/event_tracing.h" """ -- GitLab