runtime/onert/core/src/exec/ExecutionObservers.cc

   1 /*
   2  * Copyright (c) 2019 Samsung Electronics Co., Ltd. All Rights Reserved
   3  *
   4  * Licensed under the Apache License, Version 2.0 (the "License");
   5  * you may not use this file except in compliance with the License.
   6  * You may obtain a copy of the License at
   7  *
   8  *    http://www.apache.org/licenses/LICENSE-2.0
   9  *
  10  * Unless required by applicable law or agreed to in writing, software
  11  * distributed under the License is distributed on an "AS IS" BASIS,
  12  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
  13  * See the License for the specific language governing permissions and
  14  * limitations under the License.
  15  */
  16
  17 #include "exec/ExecutionObservers.h"
  18
  19 #include <string>
  20 #include <sstream>
  21
  22 #include "util/logging.h"
  23 #include "exec/IExecutor.h"
  24 #include "misc/polymorphic_downcast.h"
  25 #include "ir/OpSequence.h"
  26 #include "util/EventWriter.h"
  27 #include "util/Utils.h"
  28
  29 namespace
  30 {
  31
  32 void setUserData(const onert::ir::Graph &g, const onert::ir::OpSequence *op_seq,
  33                  decltype(EventCollector::Event::userData) &data)
  34 {
  35   if (op_seq->size() == 0)
  36     return;
  37
  38   // From a tensor of shape [a, b, c], this will return a string "shape(a b c)".
  39   // String like "[1, 2, 3]" looks better but this will be considered as a list in Json
  40   // so text search (e.g., Ctrl-F in Chrome Tracing) could be difficult
  41   auto build_shape_str = [&](onert::ir::OperandIndex operand_idx) {
  42     std::string shape_str;
  43     auto &shape = g.operands().at(operand_idx).info().shape();
  44     for (int i = 0; i < shape.rank(); i++)
  45     {
  46       if (i == 0)
  47         shape_str = "shape(" + std::to_string(shape.dim(i));
  48       else
  49         shape_str += " " + std::to_string(shape.dim(i));
  50     }
  51     shape_str += ")";
  52
  53     return shape_str;
  54   };
  55
  56   const auto &first_op_idx = op_seq->operations().at(0);
  57   const auto &first_op_node = g.operations().at(first_op_idx);
  58
  59   auto &inputs = first_op_node.getInputs();
  60   auto size = inputs.size();
  61   for (size_t i = 0; i < size; i++)
  62   {
  63     auto operand_idx = inputs.at(i);
  64     if (operand_idx.undefined())
  65       continue;
  66
  67     std::string key("input_shape_" + std::to_string(i));
  68     std::string value = build_shape_str(operand_idx);
  69     data.emplace_back(std::make_pair(key, value));
  70   }
  71
  72   // add other userData as needed
  73 }
  74
  75 } // namespace
  76
  77 namespace onert
  78 {
  79
  80 namespace exec
  81 {
  82
  83 void ProfileObserver::handleJobBegin(onert::exec::IExecutor *, ir::SubgraphIndex,
  84                                      const ir::OpSequence *, const onert::backend::Backend *backend)
  85 {
  86   _timer = backend->config()->timer();
  87   if (_timer == nullptr)
  88     throw std::runtime_error("To profile backend timer() method must be implemented");
  89   _timer->handleBegin();
  90 }
  91
  92 void ProfileObserver::handleJobEnd(IExecutor *exec, ir::SubgraphIndex, const ir::OpSequence *op_seq,
  93                                    const backend::Backend *backend)
  94 {
  95   _timer->handleEnd();
  96   const auto timer_res = _timer->getTime();
  97
  98   // NOTE This assumes there is just one operation in a op_seq
  99   const auto &node = _graph.operations().at(op_seq->operations().at(0));
 100   auto node_name = node.name();
 101   VERBOSE(ProfileInfo) << "Time for " << node_name << " : " << timer_res << std::endl;
 102
 103   // fill ExecTime:
 104   bool is_quantized = exec->graph().operands().at(node.getInputs().at(0)).typeInfo().type() ==
 105                       ir::DataType::QUANT_UINT8_ASYMM;
 106
 107   uint32_t size = 0;
 108   for (const auto &ind : (node.getInputs() + node.getOutputs()) | ir::Remove::UNDEFINED)
 109   {
 110     size += exec->graph().operands().at(ind).info().total_size();
 111   }
 112   if (node_name == "Permute")
 113   {
 114     // TODO Change it to updateOperationExecTime()
 115     _et->updatePermuteTime(backend, backend, is_quantized, size, timer_res);
 116   }
 117   else
 118   {
 119     _et->updateOperationExecTime(backend, node_name, is_quantized, size, timer_res);
 120   }
 121 };
 122
 123 TracingObserver::TracingObserver(const std::string &filepath, const ir::Graph &graph,
 124                                  const util::TracingCtx *tracing_ctx)
 125     : _recorder{std::make_unique<EventRecorder>()}, _collector{_recorder.get()}, _graph{graph},
 126       _tracing_ctx{tracing_ctx}
 127 {
 128   // TODO Remove below after using _tracing_ctx
 129   UNUSED_RELEASE(_tracing_ctx);
 130
 131   _event_writer = EventWriter::get(filepath);
 132   _event_writer->startToUse();
 133 }
 134
 135 TracingObserver::~TracingObserver()
 136 {
 137   try
 138   {
 139     _event_writer->readyToFlush(std::move(_recorder));
 140   }
 141   catch (const std::exception &e)
 142   {
 143     std::cerr << "E: Fail to record event in TracingObserver: " << e.what() << std::endl;
 144   }
 145 }
 146
 147 void TracingObserver::handleSubgraphBegin(ir::SubgraphIndex subg_ind)
 148 {
 149   // TODO Write subg_ind into profling result
 150   UNUSED_RELEASE(subg_ind);
 151   _collector.onEvent(EventCollector::Event{EventCollector::Edge::BEGIN, "runtime", "Graph"});
 152 }
 153
 154 void TracingObserver::handleJobBegin(IExecutor *, ir::SubgraphIndex subg_ind,
 155                                      const ir::OpSequence *op_seq, const backend::Backend *backend)
 156 {
 157   // TODO Write subg_ind into profling result
 158   UNUSED_RELEASE(subg_ind);
 159
 160   std::string backend_id = backend->config()->id();
 161
 162   auto ev = EventCollector::Event{EventCollector::Edge::BEGIN, backend_id,
 163                                   opSequenceTag(op_seq, _graph.operations())};
 164   // add shape of inputs
 165   setUserData(_graph, op_seq, ev.userData);
 166
 167   _collector.onEvent(ev);
 168 }
 169
 170 void TracingObserver::handleJobEnd(IExecutor *, ir::SubgraphIndex subg_ind,
 171                                    const ir::OpSequence *op_seq, const backend::Backend *backend)
 172 {
 173   // TODO Write subg_ind into profling result
 174   UNUSED_RELEASE(subg_ind);
 175
 176   std::string backend_id = backend->config()->id();
 177   _collector.onEvent(EventCollector::Event{EventCollector::Edge::END, backend_id,
 178                                            opSequenceTag(op_seq, _graph.operations())});
 179 }
 180
 181 void TracingObserver::handleSubgraphEnd(ir::SubgraphIndex subg_ind)
 182 {
 183   // TODO Write subg_ind into profling result
 184   UNUSED_RELEASE(subg_ind);
 185
 186   _collector.onEvent(EventCollector::Event{EventCollector::Edge::END, "runtime", "Graph"});
 187 }
 188
 189 std::string TracingObserver::opSequenceTag(const ir::OpSequence *op_seq,
 190                                            const ir::Operations &operations)
 191 {
 192   if (op_seq->size() == 0)
 193     return "Empty OpSequence";
 194
 195   const auto &first_op_idx = op_seq->operations().at(0);
 196   const auto &first_op_node = operations.at(first_op_idx);
 197   std::string tag = "$" + std::to_string(first_op_idx.value());
 198   tag += " " + first_op_node.name();
 199   if (op_seq->size() > 1)
 200   {
 201     tag += " (+" + std::to_string(op_seq->size() - 1) + ")";
 202   }
 203   return tag;
 204 }
 205
 206 } // namespace exec
 207
 208 } // namespace onert