Avijit/event traces (#2674)

* Added the initial rev. of the Event tracing

* Fixed the API and format

* Updated based on review feedback

* More updates based on code review feedback

* Fixxed format again

* More update based on PR review comments

* Fixed format

* Fix a compilation error that doesn't show up in local system!

src/ngraph/CMakeLists.txt

@@ -57,6 +57,8 @@ set (SRC
     dimension.cpp
     dimension.hpp
     except.hpp
+    event_tracing.hpp
+    event_tracing.cpp
     file_util.cpp
     file_util.hpp
     function.cpp

src/ngraph/event_tracing.cpp

+//*****************************************************************************
+// Copyright 2019 Intel Corporation
+//
+// 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 <iostream>
+#include <sstream>
+#include <string>
+
+#include "event_tracing.hpp"
+#include "nlohmann/json.hpp"
+
+using namespace std;
+
+mutex ngraph::Event::s_file_mutex;
+ofstream ngraph::Event::s_event_log;
+bool ngraph::Event::s_tracing_enabled = false;
+
+void ngraph::Event::write_trace(const ngraph::Event& event)
+{
+    lock_guard<mutex> lock(s_file_mutex);
+    if (!is_tracing_enabled())
+    {
+        return;
+    }
+
+    static bool so_initialized = false;
+    if (!so_initialized)
+    {
+        // Open the file
+        s_event_log.open("ngraph_event_trace.json", ios_base::trunc);
+        s_event_log << "[\n";
+        s_event_log << event.to_json() << "\n";
+        so_initialized = true;
+        return;
+    }
+
+    s_event_log << ",\n";
+    s_event_log << event.to_json() << "\n" << flush;
+}
+
+string ngraph::Event::to_json() const
+{
+    ostringstream thread_id;
+    thread_id << this_thread::get_id();
+
+    nlohmann::json json_start = {{"name", m_name},
+                                 {"cat", m_category},
+                                 {"ph", "B"},
+                                 {"pid", m_pid},
+                                 {"tid", thread_id.str()},
+                                 {"ts", m_start.time_since_epoch().count() / 1000},
+                                 {"args", m_args}};
+    nlohmann::json json_end = {{"name", m_name},
+                               {"cat", m_category},
+                               {"ph", "E"},
+                               {"pid", m_pid},
+                               {"tid", thread_id.str()},
+                               {"ts", m_stop.time_since_epoch().count() / 1000},
+                               {"args", m_args}};
+    ostringstream output;
+    output << json_start << ",\n" << json_end;
+    return output.str();
+}

src/ngraph/event_tracing.hpp

+//*****************************************************************************
+// Copyright 2019 Intel Corporation
+//
+// 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.
+//*****************************************************************************
+
+#pragma once
+
+#include <chrono>
+#include <fstream>
+#include <iostream>
+#include <mutex>
+#include <string>
+#include <thread>
+#include <unistd.h>
+
+namespace ngraph
+{
+    //
+    // This class records timestamps for a given user defined event and
+    // produces output in the chrome tracing format that can be used to view
+    // the events of a running program
+    //
+    // Following is the format of a trace event
+    //
+    // {
+    //   "name": "myName",
+    //   "cat": "category,list",
+    //   "ph": "B",
+    //   "ts": 12345,
+    //   "pid": 123,
+    //   "tid": 456,
+    //   "args": {
+    //     "someArg": 1,
+    //     "anotherArg": {
+    //       "value": "my value"
+    //     }
+    //   }
+    // }
+    //
+    // The trace file format is defined here:
+    // https://docs.google.com/document/d/1CvAClvFfyA5R-PhYUmn5OOQtYMH4h6I0nSsKchNAySU/preview
+    //
+    // The trace file can be viewed by Chrome browser using the
+    // URL: chrome://tracing/
+    //
+    // More information about this is at:
+    // http://dev.chromium.org/developers/how-tos/trace-event-profiling-tool
+
+    class Event
+    {
+    public:
+        explicit Event(const std::string& name,
+                       const std::string& category,
+                       const std::string& args)
+            : m_pid(getpid())
+            , m_start(std::chrono::high_resolution_clock::now())
+            , m_stopped(false)
+            , m_name(name)
+            , m_category(category)
+            , m_args(args)
+        {
+            m_stop = m_start;
+        }
+
+        void Stop()
+        {
+            if (m_stopped)
+            {
+                return;
+            }
+            m_stopped = true;
+            m_stop = std::chrono::high_resolution_clock::now();
+        }
+
+        static void write_trace(const Event& event);
+        static bool is_tracing_enabled()
+        {
+            static bool s_check_env = true;
+            if (s_check_env)
+            {
+                s_check_env = false;
+                if (std::getenv("NGRAPH_ENABLE_TRACING") != nullptr)
+                {
+                    s_tracing_enabled = true;
+                }
+            }
+            return s_tracing_enabled;
+        }
+        static void enable_event_tracing() { s_tracing_enabled = true; }
+        static void disable_event_tracing() { s_tracing_enabled = false; }
+        std::string to_json() const;
+
+        Event(const Event&) = delete;
+        Event& operator=(Event const&) = delete;
+
+    private:
+        int m_pid;
+        std::chrono::time_point<std::chrono::high_resolution_clock> m_start;
+        std::chrono::time_point<std::chrono::high_resolution_clock> m_stop;
+        bool m_stopped;
+        std::string m_name;
+        std::string m_category;
+        std::string m_args;
+
+        static std::mutex s_file_mutex;
+        static std::ofstream s_event_log;
+        static bool s_tracing_enabled;
+    };
+
+} // namespace ngraph

test/CMakeLists.txt

@@ -41,6 +41,7 @@ set(SRC
     cpio.cpp
     cse.cpp
     element_type.cpp
+    event_tracing.cpp
     file_util.cpp
     includes.cpp
     input_output_assign.cpp

test/event_tracing.cpp

+//*****************************************************************************
+// Copyright 2019 Intel Corporation
+//
+// 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 <fstream>
+#include <iostream>
+#include <mutex>
+#include <stdlib.h>
+#include <vector>
+#include "nlohmann/json.hpp"
+
+#include "gtest/gtest.h"
+#include "ngraph/event_tracing.hpp"
+#include "ngraph/file_util.hpp"
+
+using namespace std;
+
+TEST(event_tracing, event_file)
+{
+    // Set the environment variable to ensure logging
+    ngraph::Event::enable_event_tracing();
+    std::vector<std::thread> threads;
+    std::mutex mtx;
+    for (auto i = 0; i < 10; i++)
+    {
+        int id = i;
+        std::thread next_thread([&] {
+            std::ostringstream oss;
+            oss << "Event: " << id;
+            ngraph::Event event(oss.str(), "Dummy", "none");
+            std::this_thread::sleep_for(std::chrono::milliseconds(200));
+            event.Stop();
+            ngraph::Event::write_trace(event);
+        });
+        std::this_thread::sleep_for(std::chrono::milliseconds(200));
+        threads.push_back(std::move(next_thread));
+    }
+
+    std::this_thread::sleep_for(std::chrono::milliseconds(200));
+
+    for (auto& next : threads)
+    {
+        next.join();
+    }
+
+    // Now read the file
+    auto json_string = ngraph::file_util::read_file_to_string("ngraph_event_trace.json");
+    nlohmann::json json_from_file(json_string);
+
+    // Validate the JSON objects - there should be 10 of them
+    // TODO
+    ngraph::Event::disable_event_tracing();
+}