Added ConnectionTimeObserver to calculate the times to authenticate and connect.

remoting/test/connection_time_observer.cc

Index: remoting/test/connection_time_observer.cc
diff --git a/remoting/test/connection_time_observer.cc b/remoting/test/connection_time_observer.cc
new file mode 100644
index 0000000000000000000000000000000000000000..7f5e6fac68712b275e5df771acb78c0736592e3d
--- /dev/null
+++ b/remoting/test/connection_time_observer.cc
@@ -0,0 +1,83 @@
+// 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/time/time.h"
+
+namespace {

[Sergey Ulanov, 2015/07/23 19:20:57]

Move this inside remoting::test namespace then you wouldn't need to specify
namespace inside the function.

[tonychun, 2015/07/24 01:41:47]

Done.

+
+std::string GetStateAsString(
+    const remoting::protocol::ConnectionToHost::State& state) {
+  switch (state) {
+    case remoting::protocol::ConnectionToHost::State::INITIALIZING:
+      return "INITIALIZING";
+    case remoting::protocol::ConnectionToHost::State::CONNECTING:
+      return "CONNECTING";
+    case remoting::protocol::ConnectionToHost::State::AUTHENTICATED:
+      return "AUTHENTICATED";
+    case remoting::protocol::ConnectionToHost::State::CONNECTED:
+      return "CONNECTED";
+    case remoting::protocol::ConnectionToHost::State::FAILED:
+      return "FAILED";
+    case remoting::protocol::ConnectionToHost::State::CLOSED:
+      return "CLOSED";
+    default:
+      LOG(ERROR) << "Unknown current state";

[joedow, 2015/07/23 16:57:54]

When printing errors in default cases it is useful to include the value that was
unknown.  The error above should be "Unknown state: " << state;

[tonychun, 2015/07/24 01:41:47]

Done.

+      NOTREACHED();
+      return std::string();
+  }
+}
+
+}  // namespace
+
+namespace remoting {
+namespace test {
+
+ConnectionTimeObserver::ConnectionTimeObserver() {
+  // Stores TimeTicks at INITIALIZING state when observer is constructed.
+  transition_times_map_.insert(
+      std::make_pair(current_state_, base::TimeTicks::Now()));

[joedow, 2015/07/23 16:57:54]

I don't think this should occur in the C'Tor, you are essentially dictating
usage of the class (i.e. it must be instantiated just before you start a
connection).  Someone may want to create it as part of a class and attach/detach
in different functions, in that case this value is going to be WAY off.

A better solution would be to have the client call
"ConnectionStateChanged(Initializing)" manually just before creating the
connection.

[tonychun, 2015/07/24 01:41:47]

Done.

+}
+
+ConnectionTimeObserver::~ConnectionTimeObserver() {
+}
+
+void ConnectionTimeObserver::ConnectionStateChanged(
+    protocol::ConnectionToHost::State state,
+    protocol::ErrorCode error_code) {
+  // Save the current TimeTick of the new state into |transition_times_map_|.

[joedow, 2015/07/23 16:57:54]

Please remove comment, it is just stating what the next line of codes does.

[tonychun, 2015/07/24 01:41:47]

Done.

+  transition_times_map_.insert(std::make_pair(state, base::TimeTicks::Now()));
+
+  VLOG(1) << "Delta Time from " << GetStateAsString(current_state_)
+          << " to " << GetStateAsString(state)
+          << ": " << GetStateTransitionDelay(current_state_, state) << " ms";
+
+  // Update the current state of the client.

[joedow, 2015/07/23 16:57:54]

please remove comment, documenting code, same as other comments about comments
in this file.

[tonychun, 2015/07/24 01:41:46]

Done.

+  current_state_ = state;
+}
+
+int ConnectionTimeObserver::GetStateTransitionDelay(

[joedow, 2015/07/23 16:57:54]

Can you update the function name?  It isn't obvious what units the int value
returned represents.  It should be something like GetStateTransitionDelayMs()

[tonychun, 2015/07/24 01:41:47]

I'm keeping it the way it is, but returning base::TimeDelta instead.

+    const protocol::ConnectionToHost::State& start_state,
+    const protocol::ConnectionToHost::State& end_state) const {
+  auto iter_start_state = transition_times_map_.find(start_state);
+  auto iter_end_state = transition_times_map_.find(end_state);
+  auto iter_end = transition_times_map_.end();
+
+  // If either one of the states aren't found, log an error and return -1.
+  // Otherwise, return the delta time between the two states.

[joedow, 2015/07/23 16:57:54]

This comment isn't really needed, I can see what is going on from reading the
code.  Comments should document intent and assumptions but not act as pseudocode
(otherwise you need to update the pseudocode when the actual code changes)

[tonychun, 2015/07/24 01:41:47]

Good point. Thanks.

+  if (iter_start_state == iter_end) {

[joedow, 2015/07/23 16:57:54]

A better pattern for the return values would be to create a 'int
connection_delay_ms = 0;' above the if/else if/else block and only set the value
in the success case.  Then you can have a single return statement which would
make this logic cleaner.

[tonychun, 2015/07/24 01:41:47]

Done.

+    LOG(ERROR) << "No time found for state " << GetStateAsString(start_state);
+  } else if (iter_end_state == iter_end) {
+    LOG(ERROR) << "No time found for state " << GetStateAsString(end_state);
+  } else {
+    return (iter_end_state->second - iter_start_state->second).InMilliseconds();

[joedow, 2015/07/23 16:57:54]

You may want to check this value to ensure it isn't negative, otherwise log an
error.

[tonychun, 2015/07/24 01:41:47]

Done.

+  }
+  return -1;

[joedow, 2015/07/23 16:57:54]

I wonder if 0 is a better option.  No action should ever take 0ms.  Using
negative values might cause odd formatting and logic issues whereas 0 is pretty
obvious that there is a problem.

[Sergey Ulanov, 2015/07/23 19:20:57]

Normally we handle error cases first, and the end should be non-error case,
i.e.:

auto iter_start_state = transition_times_map_.find(start_state);
if (iter_start_state == iter_end) {
  LOG(ERROR) << "No time found for state " << GetStateAsString(start_state);
  return -1;
}

auto iter_end_state = transition_times_map_.find(end_state);
if (iter_end_state == iter_end) {
  LOG(ERROR) << "No time found for state " << GetStateAsString(end_state);
  return -1;
}

return iter_end_state->second - iter_start_state->second;

[Sergey Ulanov, 2015/07/23 19:20:57]

With base::TimeDelta result this can TimeDelta::Max()

[tonychun, 2015/07/24 01:41:47]

Done.

+}
+

[joedow, 2015/07/23 16:57:54]

I think it would be good to add a function that rolls up the stats
(DisplayConnectionStats()) that will show total time as well as time between
transitions.

[tonychun, 2015/07/24 01:41:47]

Done.

+}  // namespace test
+}  // namespace remoting