message: Minor change in VirtualScheduler logging: there's sometimes a difference between device total uptime and the sum of per-op computation time, because uptime includes waiting for channel communications.
diff: @@ -677,10 +677,10 @@ Costs VirtualScheduler::Summary() const {
  critical_path_costs.estimated_max_memory_per_device[name] =
  max_memory_usage;
  + const Costs::NanoSeconds wall_time_ns = state.GetCurrTime();
  VLOG(1) << "Device = " << name
  << ", num_nodes = " << state.nodes_executed.size()
  - << ", execution_time = " << state.GetCurrTime().count()
  - << ", memory usage: "
  + << ", wall_time_ns = " << wall_time_ns.count() << ", memory usage: "
  << "persistent = "
  << strings::HumanReadableNumBytes(persistent_memory_usage)
  << ", peak = "
  @@ -698,9 +698,11 @@ Costs VirtualScheduler::Summary() const {
  op_to_memory[node->op()] +=
  CalculateOutputSize(node_map_.at(node).output_properties, port);
  }
  + Costs::NanoSeconds total_compute_time_ns;
  for (const auto& op_cost_pair : state.op_to_cost) {
  const auto& op = op_cost_pair.first;
  const auto& cost = op_cost_pair.second.execution_time.count();
  + total_compute_time_ns += op_cost_pair.second.execution_time;
  int64 op_mem_usage = 0;
  auto it = op_to_memory.find(op);
  if (it != op_to_memory.end()) {
  @@ -718,6 +720,15 @@ Costs VirtualScheduler::Summary() const {
  << (persisent_ops.count(op) > 0 ? ": persistent op)" : ")");
  }
  }
  +
  + int utilization = 0;
  + if (wall_time_ns.count() > 0) {
  + utilization = total_compute_time_ns.count() * 100 / wall_time_ns.count();
  + }
  + VLOG(1) << "Device = " << name
  + << ", total_compute_time_ns = " << total_compute_time_ns.count()
  + << ", utilization = " << utilization << "%";
  +
  if (critical_path_costs.execution_time <= state.GetCurrTime()) {
  critical_path_costs = state.device_costs;
  }
  