Added ConnectionTimeObserver to calculate the times to authenticate and connect.

remoting/test/connection_time_observer.cc

+// Copyright 2015 The Chromium Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style license that can be
+// found in the LICENSE file.
+
+#include "remoting/test/connection_time_observer.h"
+
+#include <utility>
+
+#include "base/strings/stringprintf.h"
+#include "base/time/time.h"
+#include "base/timer/timer.h"
+
+namespace remoting {
+namespace test {
+
+ConnectionTimeObserver::ConnectionTimeObserver() {
+}
+
+ConnectionTimeObserver::~ConnectionTimeObserver() {
+}
+
+void ConnectionTimeObserver::SetTransitionTimesMapForTest(
+    const std::map<protocol::ConnectionToHost::State, base::TimeTicks>& map) {
+  transition_times_map_ = map;
+}
+
+void ConnectionTimeObserver::ConnectionStateChanged(
+    protocol::ConnectionToHost::State state,
+    protocol::ErrorCode error_code) {
+  if (transition_times_map_.find(state) != transition_times_map_.end()) {
+    std::string connection_state =
+        protocol::ConnectionToHost::StateToString(state);
+    LOG(ERROR) << connection_state << " state has already been set";
+    return;
+  }
+  transition_times_map_.insert(std::make_pair(state, base::TimeTicks::Now()));
+  current_connection_state_ = state;
+}
+
+void ConnectionTimeObserver::DisplayConnectionStats() const {
+  protocol::ConnectionToHost::State initializing =
+      protocol::ConnectionToHost::State::INITIALIZING;
+  protocol::ConnectionToHost::State current_state = initializing;
+
+  const char kStateChangeTitleFormatString[] = "%-35s%-15s";
+  LOG(INFO) << base::StringPrintf(kStateChangeTitleFormatString,
+      "State to State", "Delta Time");
+  LOG(INFO) << base::StringPrintf(kStateChangeTitleFormatString,
+      "--------------", "----------");
+
+  // Note: the order of |connected_states| mimics the expected order of when a
+  // connection is made.
+  std::vector<protocol::ConnectionToHost::State> connected_states;
+  connected_states.push_back(protocol::ConnectionToHost::State::CONNECTING);
+  connected_states.push_back(protocol::ConnectionToHost::State::AUTHENTICATED);
+  connected_states.push_back(protocol::ConnectionToHost::State::CONNECTED);
+  connected_states.push_back(protocol::ConnectionToHost::State::FAILED);
+
+  const char kStateChangeFormatString[] = "%-13s to %-18s%-7dms";
+  auto iter_end = transition_times_map_.end();
+  for (protocol::ConnectionToHost::State state : connected_states) {
+    auto iter_state = transition_times_map_.find(state);
+    if (iter_state != iter_end) {
+      int state_transition_time =
+          GetStateTransitionTime(current_state, state).InMilliseconds();
+      LOG(INFO) << base::StringPrintf(kStateChangeFormatString,
+          protocol::ConnectionToHost::StateToString(current_state),
+          protocol::ConnectionToHost::StateToString(state),
+          state_transition_time);
+      current_state = state;
+    }
+  }
+
+  int connected_time =
+      GetStateTransitionTime(initializing, current_state).InMilliseconds();
+
+  // |current state| will either be FAILED or CONNECTED.
+  LOG(INFO) << "Total Connection Duration (INITIALIZING to "
+            << protocol::ConnectionToHost::StateToString(current_state) << "): "
+            << connected_time << " ms";
+}
+
+base::TimeDelta ConnectionTimeObserver::GetStateTransitionTime(
+    protocol::ConnectionToHost::State start,
+    protocol::ConnectionToHost::State end) const {
+  auto iter_end = transition_times_map_.end();
+
+  auto iter_start_state = transition_times_map_.find(start);
+  std::string start_state = protocol::ConnectionToHost::StateToString(start);
+  if (iter_start_state == iter_end) {
+    LOG(ERROR) << "No time found for state: " << start_state;
+    return base::TimeDelta::Max();
+  }
+
+  auto iter_end_state = transition_times_map_.find(end);
+  std::string end_state = protocol::ConnectionToHost::StateToString(end);
+  if (iter_end_state == iter_end) {
+    LOG(ERROR) << "No time found for state: " << end_state;
+    return base::TimeDelta::Max();
+  }
+
+  base::TimeDelta delta = iter_end_state->second - iter_start_state->second;
+  if (delta.InMilliseconds() < 0) {
+    LOG(ERROR) << "Transition delay is negative. Check the state ordering: "
+               << "[start: " << start_state << ", end: " << end_state << "]";
+    return base::TimeDelta::Max();
+  }
+
+  return delta;
+}
+
+}  // namespace test
+}  // namespace remoting