Dump execution traces with start time and end time

et_feeder/et_feeder.cpp

@@ -4,7 +4,8 @@ using namespace std;
 using namespace Chakra;
 
 ETFeeder::ETFeeder(string filename)
-  : trace_(filename), window_size_(4096 * 256), et_complete_(false) {
+  : filename_(filename), trace_(filename), window_size_(4096 * 256),
+  et_complete_(false) {
   readGlobalMetadata();
   readNextWindow();
 }
@@ -13,11 +14,12 @@ ETFeeder::~ETFeeder() {
 }
 
 void ETFeeder::addNode(shared_ptr<ETFeederNode> node) {
-  dep_graph_[node->getChakraNode()->id()] = node;
+  dep_graph_sim_[node->getChakraNode()->id()] = node;
+  dep_graph_dump_[node->getChakraNode()->id()] = node;
 }
 
 void ETFeeder::removeNode(uint64_t node_id) {
-  dep_graph_.erase(node_id);
+  dep_graph_sim_.erase(node_id);
 
   if (!et_complete_
       && (dep_free_node_queue_.size() < window_size_)) {
@@ -26,7 +28,7 @@ void ETFeeder::removeNode(uint64_t node_id) {
 }
 
 bool ETFeeder::hasNodesToIssue() {
-  return !(dep_graph_.empty() && dep_free_node_queue_.empty());
+  return !(dep_graph_sim_.empty() && dep_free_node_queue_.empty());
 }
 
 shared_ptr<ETFeederNode> ETFeeder::getNextIssuableNode() {
@@ -41,17 +43,17 @@ shared_ptr<ETFeederNode> ETFeeder::getNextIssuableNode() {
 }
 
 void ETFeeder::pushBackIssuableNode(uint64_t node_id) {
-  shared_ptr<ETFeederNode> node = dep_graph_[node_id];
+  shared_ptr<ETFeederNode> node = dep_graph_sim_[node_id];
   dep_free_node_id_set_.emplace(node_id);
   dep_free_node_queue_.emplace(node);
 }
 
 shared_ptr<ETFeederNode> ETFeeder::lookupNode(uint64_t node_id) {
-  return dep_graph_[node_id];
+  return dep_graph_sim_[node_id];
 }
 
 void ETFeeder::freeChildrenNodes(uint64_t node_id) {
-  shared_ptr<ETFeederNode> node = dep_graph_[node_id];
+  shared_ptr<ETFeederNode> node = dep_graph_sim_[node_id];
   for (auto child: node->getChildren()) {
     auto child_chakra = child->getChakraNode();
     for (auto it = child_chakra->mutable_data_deps()->begin();
@@ -69,6 +71,39 @@ void ETFeeder::freeChildrenNodes(uint64_t node_id) {
   }
 }
 
+void ETFeeder::addStartTime(shared_ptr<ETFeederNode> node, uint64_t start_time_micros) {
+  node->setStartTimeMicros(start_time_micros);
+}
+
+void ETFeeder::addEndTime(shared_ptr<ETFeederNode> node, uint64_t end_time_micros) {
+  node->setEndTimeMicros(end_time_micros);
+}
+
+void ETFeeder::dumpUpdatedET() {
+  string dump_filename = filename_;
+
+  const string suffix = ".et";
+  if (dump_filename.size() >= suffix.size() &&
+    dump_filename.compare(dump_filename.size() - suffix.size(), suffix.size(), suffix) == 0) {
+    dump_filename.replace(dump_filename.size() - suffix.size(), suffix.size(), ".sim.et");
+  }
+
+  ProtoOutputStream output_trace_(dump_filename);
+  ChakraProtoMsg::GlobalMetadata metadata;
+  metadata.set_version("0.0.4");
+  output_trace_.write(metadata);
+  for (const auto &it: dep_graph_dump_) {
+    shared_ptr<ChakraProtoMsg::Node> chakra_node = it.second->getChakraNode();
+    ChakraProtoMsg::AttributeProto *attr = chakra_node->add_attr();
+    attr->set_name("start_time");
+    attr->set_uint64_val(it.second->getStartTimeMicros());
+    attr = chakra_node->add_attr();
+    attr->set_name("end_time");
+    attr->set_uint64_val(it.second->getEndTimeMicros());
+    output_trace_.write(*chakra_node);
+  }
+}
+
 void ETFeeder::readGlobalMetadata() {
   shared_ptr<ChakraProtoMsg::GlobalMetadata> pkt_msg = make_shared<ChakraProtoMsg::GlobalMetadata>();
   trace_.read(*pkt_msg);
@@ -83,8 +118,8 @@ shared_ptr<ETFeederNode> ETFeeder::readNode() {
 
   bool dep_unresolved = false;
   for (int i = 0; i < pkt_msg->data_deps_size(); ++i) {
-    auto parent_node = dep_graph_.find(pkt_msg->data_deps(i));
-    if (parent_node != dep_graph_.end()) {
+    auto parent_node = dep_graph_sim_.find(pkt_msg->data_deps(i));
+    if (parent_node != dep_graph_sim_.end()) {
       parent_node->second->addChild(node);
     } else {
       dep_unresolved = true;
@@ -106,8 +141,8 @@ void ETFeeder::resolveDep() {
     vector<uint64_t> dep_unresolved_parent_ids = node->getDepUnresolvedParentIDs();
     for (auto inner_it = dep_unresolved_parent_ids.begin();
         inner_it != dep_unresolved_parent_ids.end();) {
-      auto parent_node = dep_graph_.find(*inner_it);
-      if (parent_node != dep_graph_.end()) {
+      auto parent_node = dep_graph_sim_.find(*inner_it);
+      if (parent_node != dep_graph_sim_.end()) {
         parent_node->second->addChild(node);
         inner_it = dep_unresolved_parent_ids.erase(inner_it);
       } else {
@@ -139,7 +174,7 @@ void ETFeeder::readNextWindow() {
   } while ((num_read < window_size_)
       || (dep_unresolved_node_set_.size() != 0));
 
-  for (auto node_id_node: dep_graph_) {
+  for (auto node_id_node: dep_graph_sim_) {
     uint64_t node_id = node_id_node.first;
     shared_ptr<ETFeederNode> node = node_id_node.second;
     if ((dep_free_node_id_set_.count(node_id) == 0)

et_feeder/et_feeder.h

@@ -2,6 +2,7 @@
 
 #include <memory>
 #include <queue>
+#include <map>
 #include <unordered_map>
 #include <unordered_set>
 #include <vector>
@@ -30,18 +31,23 @@ class ETFeeder {
   void pushBackIssuableNode(uint64_t node_id);
   std::shared_ptr<ETFeederNode> lookupNode(uint64_t node_id);
   void freeChildrenNodes(uint64_t node_id);
+  void addStartTime(std::shared_ptr<ETFeederNode> node, uint64_t start_time_micros);
+  void addEndTime(std::shared_ptr<ETFeederNode> node, uint64_t end_time_micros);
+  void dumpUpdatedET();
 
  private:
   void readGlobalMetadata();
   std::shared_ptr<ETFeederNode> readNode();
   void readNextWindow();
   void resolveDep();
 
+  std::string filename_;
   ProtoInputStream trace_;
   const uint32_t window_size_;
   bool et_complete_;
 
-  std::unordered_map<uint64_t, std::shared_ptr<ETFeederNode>> dep_graph_{};
+  std::unordered_map<uint64_t, std::shared_ptr<ETFeederNode>> dep_graph_sim_{};
+  std::map<uint64_t, std::shared_ptr<ETFeederNode>> dep_graph_dump_{};
   std::unordered_set<uint64_t> dep_free_node_id_set_{};
   std::priority_queue<std::shared_ptr<ETFeederNode>, std::vector<std::shared_ptr<ETFeederNode>>, CompareNodes> dep_free_node_queue_{};
   std::unordered_set<std::shared_ptr<ETFeederNode>> dep_unresolved_node_set_{};

et_feeder/et_feeder_node.cpp

@@ -198,6 +198,22 @@ void ETFeederNode::assign_attr_val(shared_ptr<ChakraProtoMsg::Node> node, int i,
   }
 }
 
+void ETFeederNode::setStartTimeMicros(uint64_t start_time_micros) {
+  start_time_micros_ = start_time_micros;
+}
+
+uint64_t ETFeederNode::getStartTimeMicros() {
+  return start_time_micros_;
+}
+
+void ETFeederNode::setEndTimeMicros(uint64_t end_time_micros) {
+  end_time_micros_ = end_time_micros;
+}
+
+uint64_t ETFeederNode::getEndTimeMicros() {
+  return end_time_micros_;
+}
+
 uint64_t ETFeederNode::id() {
   return id_;
 }

et_feeder/et_feeder_node.h

@@ -18,6 +18,11 @@ class ETFeederNode {
     std::vector<uint64_t> getDepUnresolvedParentIDs();
     void setDepUnresolvedParentIDs(std::vector<uint64_t> const& dep_unresolved_parent_ids);
 
+    void setStartTimeMicros(uint64_t start_time_micros);
+    uint64_t getStartTimeMicros();
+    void setEndTimeMicros(uint64_t end_time_micros);
+    uint64_t getEndTimeMicros();
+
     uint64_t id();
     std::string name();
     bool is_cpu_op();
@@ -58,6 +63,8 @@ class ETFeederNode {
     uint32_t comm_src_;
     uint32_t comm_dst_;
     uint32_t comm_tag_;
+    uint64_t start_time_micros_;
+    uint64_t end_time_micros_;
 };
 
 } // namespace Chakra