Add logging of "use candidate" and when we switch ICE "best" connections.

R=guoweis@webrtc.org

Review URL: https://webrtc-codereview.appspot.com/46309004

Cr-Commit-Position: refs/heads/master@{#9197}
diff --git a/webrtc/p2p/base/p2ptransportchannel.cc b/webrtc/p2p/base/p2ptransportchannel.cc
index ef21559..a1f8967 100644
--- a/webrtc/p2p/base/p2ptransportchannel.cc
+++ b/webrtc/p2p/base/p2ptransportchannel.cc
@@ -623,15 +623,20 @@
   ASSERT(worker_thread_ == rtc::Thread::Current());
   ASSERT(ice_role_ == ICEROLE_CONTROLLED);
   ASSERT(protocol_type_ == ICEPROTO_RFC5245);
+
   if (conn->write_state() == Connection::STATE_WRITABLE) {
     if (best_connection_ != conn) {
       pending_best_connection_ = NULL;
+      LOG(LS_INFO) << "Switching best connection on controlled side: "
+                   << conn->ToString();
       SwitchBestConnectionTo(conn);
       // Now we have selected the best connection, time to prune other existing
       // connections and update the read/write state of the channel.
       RequestSort();
     }
   } else {
+    LOG(LS_INFO) << "Not switching the best connection on controlled side yet,"
+                 << " because it's not writable: " << conn->ToString();
     pending_best_connection_ = conn;
   }
 }
@@ -988,8 +993,11 @@
 
   // If necessary, switch to the new choice.
   if (protocol_type_ != ICEPROTO_RFC5245 || ice_role_ == ICEROLE_CONTROLLING) {
-    if (ShouldSwitch(best_connection_, top_connection))
+    if (ShouldSwitch(best_connection_, top_connection)) {
+      LOG(LS_INFO) << "Switching best connection on controlling side: "
+                   << top_connection->ToString();
       SwitchBestConnectionTo(top_connection);
+    }
   }
 
   // We can prune any connection for which there is a connected, writable
@@ -1265,6 +1273,8 @@
   if (protocol_type_ == ICEPROTO_RFC5245 && ice_role_ == ICEROLE_CONTROLLED) {
     if (connection == pending_best_connection_ && connection->writable()) {
       pending_best_connection_ = NULL;
+      LOG(LS_INFO) << "Switching best connection on controlled side"
+                   << " because it's now writable: " << connection->ToString();
       SwitchBestConnectionTo(connection);
     }
   }
@@ -1301,6 +1311,7 @@
   // Since this connection is no longer an option, we can just set best to NULL
   // and re-choose a best assuming that there was no best connection.
   if (best_connection_ == connection) {
+    LOG(LS_INFO) << "Best connection destroyed.  Will choose a new one.";
     SwitchBestConnectionTo(NULL);
     RequestSort();
   }
diff --git a/webrtc/p2p/base/port.cc b/webrtc/p2p/base/port.cc
index df5f461..ee3991d 100644
--- a/webrtc/p2p/base/port.cc
+++ b/webrtc/p2p/base/port.cc
@@ -1319,16 +1319,17 @@
     ReceivedPing();
   }
 
-  // TODO(pthatcher): Figure out how to use LOG_CHECK_LEVEL with a
-  // variable.  rtc:LogCheckLevel doesn't work within Chrome.
   if (LOG_CHECK_LEVEL_V(sev)) {
+    bool use_candidate = (
+        response->GetByteString(STUN_ATTR_USE_CANDIDATE) != nullptr);
     std::string pings;
     PrintPingsSinceLastResponse(&pings, 5);
     LOG_JV(sev, this) << "Received STUN ping response"
-                        << ", id=" << rtc::hex_encode(request->id())
-                        << ", code=0"  // Makes logging easier to parse.
-                        << ", rtt=" << rtt
-                        << ", pings_since_last_response=" << pings;
+                      << ", id=" << rtc::hex_encode(request->id())
+                      << ", code=0"  // Makes logging easier to parse.
+                      << ", rtt=" << rtt
+                      << ", use_candidate=" << use_candidate
+                      << ", pings_since_last_response=" << pings;
   }
 
   pings_since_last_response_.clear();
@@ -1388,8 +1389,10 @@
 void Connection::OnConnectionRequestSent(ConnectionRequest* request) {
   // Log at LS_INFO if we send a ping on an unwritable connection.
   rtc::LoggingSeverity sev = !writable() ? rtc::LS_INFO : rtc::LS_VERBOSE;
+  bool use_candidate = use_candidate_attr();
   LOG_JV(sev, this) << "Sent STUN ping"
-                    << ", id=" << rtc::hex_encode(request->id());
+                    << ", id=" << rtc::hex_encode(request->id())
+                    << ", use_candidate=" << use_candidate;
 }
 
 void Connection::CheckTimeout() {