CPU: Per-function timelines (#564)

src/ngraph/runtime/cpu/cpu_call_frame.cpp

@@ -65,7 +65,9 @@ void runtime::cpu::CPU_CallFrame::tensor_call(
 
     if (runtime::cpu::IsTracingEnabled())
     {
-        GenerateTimeline(m_external_function->get_op_attrs(), ctx->op_durations);
+        GenerateTimeline(m_external_function->get_op_attrs(),
+                         ctx->op_durations,
+                         m_external_function->get_function_name() + ".timeline.json");
     }
 }
 

src/ngraph/runtime/cpu/cpu_external_function.cpp

@@ -245,6 +245,7 @@ runtime::cpu::CPU_ExternalFunction::CPU_ExternalFunction(
     , m_compiled_function(nullptr)
     , m_emit_timing(std::getenv("NGRAPH_CPU_EMIT_TIMING") != nullptr)
     , m_use_tbb(std::getenv("NGRAPH_CPU_USE_TBB") != nullptr)
+    , m_function_name(function->get_name())
 {
 }
 
@@ -255,8 +256,6 @@ void runtime::cpu::CPU_ExternalFunction::compile()
         return;
     }
 
-    string function_name = m_function->get_name();
-
     m_mkldnn_emitter.reset(new MKLDNNEmitter(shared_from_this()));
 
     ngraph::pass::Manager pass_manager;
@@ -537,7 +536,7 @@ using namespace ngraph::runtime;
         }
 
         // Execution tracing support
-        if (runtime::cpu::IsTracingEnabled() && current_function->get_name() == function_name)
+        if (runtime::cpu::IsTracingEnabled() && current_function->get_name() == m_function_name)
         {
             writer << "cpu::Timestamp start_ts;\n"
                    << "int profiler_count = 0;\n\n";
@@ -688,7 +687,7 @@ using namespace ngraph::runtime;
             // Emit operation prologue
             if (!node->is_parameter() && !node->is_constant())
             {
-                if (current_function->get_name() == function_name)
+                if (current_function->get_name() == m_function_name)
                 {
                     m_op_attrs.emplace_back(
                         node->description(), node_output_names, node_input_names);
@@ -706,7 +705,7 @@ using namespace ngraph::runtime;
                     emit_debug_function_entry(writer, node.get(), in, out);
                 }
                 if (runtime::cpu::IsTracingEnabled() &&
-                    current_function->get_name() == function_name)
+                    current_function->get_name() == m_function_name)
                 {
                     writer << "start_ts = cpu::Clock::now();\n";
                 }
@@ -750,7 +749,7 @@ using namespace ngraph::runtime;
                     emit_debug_function_exit(writer, node.get(), in, out);
                 }
                 if (runtime::cpu::IsTracingEnabled() &&
-                    current_function->get_name() == function_name)
+                    current_function->get_name() == m_function_name)
                 {
                     writer << "ctx->op_durations[profiler_count++] = "
                            << "(std::chrono::duration_cast<cpu::Timescale>(cpu::Clock::now() - "
@@ -848,7 +847,7 @@ using namespace ngraph::runtime;
     // TODO: Cleanup and make this a utility function
 
     file_util::make_directory(s_output_dir);
-    string filename = file_util::path_join(s_output_dir, function_name + "_codegen.cpp");
+    string filename = file_util::path_join(s_output_dir, m_function_name + "_codegen.cpp");
     ofstream out(filename);
     string code = writer.get_code();
     out << code;
@@ -867,7 +866,7 @@ using namespace ngraph::runtime;
     }
     m_execution_engine->add_module(codegen_module);
     m_execution_engine->finalize();
-    m_compiled_function = m_execution_engine->find_function<EntryPoint_t>(function_name);
+    m_compiled_function = m_execution_engine->find_function<EntryPoint_t>(m_function_name);
 
     if (m_compiled_function == nullptr)
     {

src/ngraph/runtime/cpu/cpu_external_function.hpp

@@ -86,6 +86,7 @@ namespace ngraph
                     return m_mkldnn_emitter;
                 }
 
+                const std::string& get_function_name() const { return m_function_name; }
             protected:
                 void compile();
 
@@ -123,6 +124,8 @@ namespace ngraph
                 std::vector<OpAttributes> m_op_attrs;
 
                 std::unique_ptr<MKLDNNEmitter> m_mkldnn_emitter;
+
+                std::string m_function_name;
             };
         }
     }

src/ngraph/runtime/cpu/cpu_tracing.cpp

@@ -42,11 +42,12 @@ void ngraph::runtime::cpu::to_json(nlohmann::json& json, const TraceEvent& event
 }
 
 void ngraph::runtime::cpu::GenerateTimeline(const std::vector<OpAttributes>& op_attrs,
-                                            int64_t* op_durations)
+                                            int64_t* op_durations,
+                                            const std::string& file_name)
 {
     nlohmann::json timeline;
     std::list<TraceEvent> trace;
-    std::ofstream out("timeline.json");
+    std::ofstream out(file_name);
 
     int64_t ts = 0;
     for (size_t i = 0; i < op_attrs.size(); i++)

src/ngraph/runtime/cpu/cpu_tracing.hpp

@@ -69,7 +69,9 @@ namespace ngraph
 
             void to_json(nlohmann::json& json, const TraceEvent& event);
 
-            void GenerateTimeline(const std::vector<OpAttributes>& op_attrs, int64_t* op_durations);
+            void GenerateTimeline(const std::vector<OpAttributes>& op_attrs,
+                                  int64_t* op_durations,
+                                  const std::string& file_name);
             bool IsTracingEnabled();
         }
     }