add tracing to interpreter

src/ngraph/CMakeLists.txt

@@ -463,6 +463,8 @@ set (SRC
     runtime/backend.hpp
     runtime/backend_manager.cpp
     runtime/backend_manager.hpp
+    runtime/chrome_trace.cpp
+    runtime/chrome_trace.hpp
     runtime/executable.cpp
     runtime/executable.hpp
     runtime/host_tensor.cpp

src/ngraph/runtime/interpreter/chrome_trace.cpp → src/ngraph/runtime/chrome_trace.cpp

@@ -32,12 +32,10 @@ static bool read_tracing_env_var()
     return is_enabled;
 }
 
-mutex runtime::interpreter::event::Manager::s_file_mutex;
-bool runtime::interpreter::event::Manager::s_tracing_enabled = read_tracing_env_var();
+mutex runtime::event::Manager::s_file_mutex;
+bool runtime::event::Manager::s_tracing_enabled = read_tracing_env_var();
 
-runtime::interpreter::event::Duration::Duration(const string& name,
-                                                const string& category,
-                                                const string& args)
+runtime::event::Duration::Duration(const string& name, const string& category, const string& args)
 {
     if (Manager::is_tracing_enabled())
     {
@@ -49,7 +47,7 @@ runtime::interpreter::event::Duration::Duration(const string& name,
     }
 }
 
-void runtime::interpreter::event::Duration::stop()
+void runtime::event::Duration::stop()
 {
     if (Manager::is_tracing_enabled())
     {
@@ -57,7 +55,7 @@ void runtime::interpreter::event::Duration::stop()
     }
 }
 
-void runtime::interpreter::event::Duration::write()
+void runtime::event::Duration::write()
 {
     if (Manager::is_tracing_enabled())
     {
@@ -65,10 +63,10 @@ void runtime::interpreter::event::Duration::write()
 
         lock_guard<mutex> lock(Manager::get_mutex());
 
-        ofstream& out = runtime::interpreter::event::Manager::get_output_stream();
+        ofstream& out = runtime::event::Manager::get_output_stream();
         if (out.is_open() == false)
         {
-            runtime::interpreter::event::Manager::open();
+            runtime::event::Manager::open();
         }
         else
         {
@@ -89,7 +87,7 @@ void runtime::interpreter::event::Duration::write()
     }
 }
 
-runtime::interpreter::event::Object::Object(const string& name, const string& args)
+runtime::event::Object::Object(const string& name, const string& args)
     : m_name{name}
     , m_id{static_cast<size_t>(chrono::high_resolution_clock::now().time_since_epoch().count())}
 {
@@ -97,10 +95,10 @@ runtime::interpreter::event::Object::Object(const string& name, const string& ar
     {
         lock_guard<mutex> lock(Manager::get_mutex());
 
-        ofstream& out = runtime::interpreter::event::Manager::get_output_stream();
+        ofstream& out = runtime::event::Manager::get_output_stream();
         if (out.is_open() == false)
         {
-            runtime::interpreter::event::Manager::open();
+            runtime::event::Manager::open();
         }
         else
         {
@@ -120,16 +118,16 @@ runtime::interpreter::event::Object::Object(const string& name, const string& ar
     }
 }
 
-void runtime::interpreter::event::Object::snapshot(const string& args)
+void runtime::event::Object::snapshot(const string& args)
 {
     if (Manager::is_tracing_enabled())
     {
         lock_guard<mutex> lock(Manager::get_mutex());
 
-        ofstream& out = runtime::interpreter::event::Manager::get_output_stream();
+        ofstream& out = runtime::event::Manager::get_output_stream();
         if (out.is_open() == false)
         {
-            runtime::interpreter::event::Manager::open();
+            runtime::event::Manager::open();
         }
         else
         {
@@ -139,7 +137,7 @@ void runtime::interpreter::event::Object::snapshot(const string& args)
     }
 }
 
-void runtime::interpreter::event::Object::write_snapshot(ostream& out, const string& args)
+void runtime::event::Object::write_snapshot(ostream& out, const string& args)
 {
     out << R"({"name":")" << m_name << R"(","ph":"O","id":")" << m_id <<
         R"(","ts":)" << Manager::get_current_microseconds() <<
@@ -152,16 +150,16 @@ void runtime::interpreter::event::Object::write_snapshot(ostream& out, const str
     out << "}";
 }
 
-void runtime::interpreter::event::Object::destroy()
+void runtime::event::Object::destroy()
 {
     if (Manager::is_tracing_enabled())
     {
         lock_guard<mutex> lock(Manager::get_mutex());
 
-        ofstream& out = runtime::interpreter::event::Manager::get_output_stream();
+        ofstream& out = runtime::event::Manager::get_output_stream();
         if (out.is_open() == false)
         {
-            runtime::interpreter::event::Manager::open();
+            runtime::event::Manager::open();
         }
         else
         {
@@ -174,17 +172,18 @@ void runtime::interpreter::event::Object::destroy()
     }
 }
 
-void runtime::interpreter::event::Manager::open(const string& path)
+void runtime::event::Manager::open(const string& path)
 {
     ofstream& out = get_output_stream();
     if (out.is_open() == false)
     {
+        NGRAPH_INFO << path;
         out.open(path, ios_base::trunc);
         out << "[\n";
     }
 }
 
-void runtime::interpreter::event::Manager::close()
+void runtime::event::Manager::close()
 {
     ofstream& out = get_output_stream();
     if (out.is_open())
@@ -194,34 +193,34 @@ void runtime::interpreter::event::Manager::close()
     }
 }
 
-ofstream& runtime::interpreter::event::Manager::get_output_stream()
+ofstream& runtime::event::Manager::get_output_stream()
 {
     static ofstream s_event_log;
     return s_event_log;
 }
 
-const string& runtime::interpreter::event::Manager::get_process_id()
+const string& runtime::event::Manager::get_process_id()
 {
     static const string s_pid = to_string(getpid());
     return s_pid;
 }
 
-void runtime::interpreter::event::Manager::enable_event_tracing()
+void runtime::event::Manager::enable_event_tracing()
 {
     s_tracing_enabled = true;
 }
 
-void runtime::interpreter::event::Manager::disable_event_tracing()
+void runtime::event::Manager::disable_event_tracing()
 {
     s_tracing_enabled = false;
 }
 
-bool runtime::interpreter::event::Manager::is_event_tracing_enabled()
+bool runtime::event::Manager::is_event_tracing_enabled()
 {
     return s_tracing_enabled;
 }
 
-string runtime::interpreter::event::Manager::get_thread_id()
+string runtime::event::Manager::get_thread_id()
 {
     thread::id tid = this_thread::get_id();
     static map<thread::id, string> tid_map;

src/ngraph/runtime/interpreter/chrome_trace.hpp → src/ngraph/runtime/chrome_trace.hpp

@@ -34,8 +34,6 @@
 namespace ngraph
 {
     namespace runtime
-    {
-        namespace interpreter
     {
         namespace event
         {
@@ -44,7 +42,6 @@ namespace ngraph
             class Manager;
         }
     }
-    }
 }
 
 //
@@ -78,13 +75,13 @@ namespace ngraph
 // More information about this is at:
 // http://dev.chromium.org/developers/how-tos/trace-event-profiling-tool
 
-class ngraph::runtime::interpreter::event::Manager
+class ngraph::runtime::event::Manager
 {
     friend class Duration;
     friend class Object;
 
 public:
-    static void open(const std::string& path = "interpreter_event_trace.json");
+    static void open(const std::string& path = "runtime_event_trace.json");
     static void close();
     static bool is_tracing_enabled() { return s_tracing_enabled; }
     static void enable_event_tracing();
@@ -105,7 +102,7 @@ private:
     static bool s_tracing_enabled;
 };
 
-class ngraph::runtime::interpreter::event::Duration
+class ngraph::runtime::event::Duration
 {
 public:
     explicit Duration(const std::string& name,
@@ -133,7 +130,7 @@ private:
     std::string m_args;
 };
 
-class ngraph::runtime::interpreter::event::Object
+class ngraph::runtime::event::Object
 {
 public:
     Object(const std::string& name, const std::string& args);

src/ngraph/runtime/host_tensor.cpp

@@ -18,6 +18,7 @@
 #include <memory>
 
 #include "ngraph/descriptor/layout/dense_tensor_layout.hpp"
+#include "ngraph/runtime/chrome_trace.hpp"
 #include "ngraph/runtime/host_tensor.hpp"
 #include "ngraph/util.hpp"
 
@@ -96,6 +97,8 @@ const char* runtime::HostTensor::get_data_ptr() const
 
 void runtime::HostTensor::write(const void* source, size_t n)
 {
+    runtime::event::Duration d1("HostTensor", "write");
+
     if (n > m_buffer_size)
     {
         throw out_of_range("write access past end of tensor");
@@ -106,6 +109,7 @@ void runtime::HostTensor::write(const void* source, size_t n)
 
 void runtime::HostTensor::read(void* target, size_t n) const
 {
+    runtime::event::Duration d1("HostTensor", "read");
     if (n > m_buffer_size)
     {
         throw out_of_range("read access past end of tensor");

src/ngraph/runtime/interpreter/CMakeLists.txt

@@ -15,8 +15,7 @@
 # ******************************************************************************
 
 if (NGRAPH_INTERPRETER_ENABLE)
-    add_library(interpreter_backend SHARED int_backend.cpp node_wrapper.cpp int_executable.cpp
-        chrome_trace.cpp)
+    add_library(interpreter_backend SHARED int_backend.cpp node_wrapper.cpp int_executable.cpp)
     if(NGRAPH_LIB_VERSIONING_ENABLE)
         set_target_properties(interpreter_backend PROPERTIES
             VERSION ${NGRAPH_VERSION}

src/ngraph/runtime/interpreter/int_executable.cpp

@@ -30,6 +30,7 @@
 #include "ngraph/pass/manager.hpp"
 #include "ngraph/pass/memory_layout.hpp"
 #include "ngraph/runtime/backend_manager.hpp"
+#include "ngraph/runtime/chrome_trace.hpp"
 #include "ngraph/serializer.hpp"
 #include "ngraph/util.hpp"
 
@@ -76,6 +77,8 @@ runtime::interpreter::INTExecutable::INTExecutable(const std::string& model_stri
 bool runtime::interpreter::INTExecutable::call(const vector<shared_ptr<runtime::Tensor>>& outputs,
                                                const vector<shared_ptr<runtime::Tensor>>& inputs)
 {
+    runtime::event::Duration d1("Interpreter", "call");
+
     // convert inputs to HostTensor
     vector<shared_ptr<HostTensor>> func_inputs;
     for (auto tensor : inputs)