Add tracing to public PeerConnection methods.

Adds tracing specifically to Close, for creating streams and also moves
tracing for SetLocal/RemoteDescription from WebRtcSession. Also adding
some tracing in ChannelManager to see what's taking time inside Close.

BUG=webrtc:5167
R=tommi@webrtc.org

Review URL: https://codereview.webrtc.org/1509903002 .

Cr-Commit-Position: refs/heads/master@{#10943}

talk/app/webrtc/peerconnection.cc

@@ -51,6 +51,7 @@
 #include "webrtc/base/logging.h"
 #include "webrtc/base/stringencode.h"
 #include "webrtc/base/stringutils.h"
+#include "webrtc/base/trace_event.h"
 #include "webrtc/p2p/client/basicportallocator.h"
 #include "webrtc/system_wrappers/include/field_trial.h"
 
@@ -595,6 +596,7 @@ PeerConnection::PeerConnection(PeerConnectionFactory* factory)
       remote_streams_(StreamCollection::Create()) {}
 
 PeerConnection::~PeerConnection() {
+  TRACE_EVENT0("webrtc", "PeerConnection::~PeerConnection");
   RTC_DCHECK(signaling_thread()->IsCurrent());
   // Finish any pending deletions.
   signaling_thread()->Clear(this, MSG_DELETE, nullptr);
@@ -638,6 +640,7 @@ bool PeerConnection::Initialize(
     rtc::scoped_ptr<cricket::PortAllocator> allocator,
     rtc::scoped_ptr<DtlsIdentityStoreInterface> dtls_identity_store,
     PeerConnectionObserver* observer) {
+  TRACE_EVENT0("webrtc", "PeerConnection::Initialize");
   RTC_DCHECK(observer != nullptr);
   if (!observer) {
     return false;
@@ -728,6 +731,7 @@ PeerConnection::remote_streams() {
 }
 
 bool PeerConnection::AddStream(MediaStreamInterface* local_stream) {
+  TRACE_EVENT0("webrtc", "PeerConnection::AddStream");
   if (IsClosed()) {
     return false;
   }
@@ -788,6 +792,7 @@ bool PeerConnection::AddStream(MediaStreamInterface* local_stream) {
 // TODO(deadbeef): Don't destroy RtpSenders here; they should be kept around
 // indefinitely, when we have unified plan SDP.
 void PeerConnection::RemoveStream(MediaStreamInterface* local_stream) {
+  TRACE_EVENT0("webrtc", "PeerConnection::RemoveStream");
   for (const auto& track : local_stream->GetAudioTracks()) {
     auto sender = FindSenderForTrack(track.get());
     if (sender == senders_.end()) {
@@ -819,6 +824,7 @@ void PeerConnection::RemoveStream(MediaStreamInterface* local_stream) {
 
 rtc::scoped_refptr<DtmfSenderInterface> PeerConnection::CreateDtmfSender(
     AudioTrackInterface* track) {
+  TRACE_EVENT0("webrtc", "PeerConnection::CreateDtmfSender");
   if (!track) {
     LOG(LS_ERROR) << "CreateDtmfSender - track is NULL.";
     return NULL;
@@ -839,6 +845,7 @@ rtc::scoped_refptr<DtmfSenderInterface> PeerConnection::CreateDtmfSender(
 
 rtc::scoped_refptr<RtpSenderInterface> PeerConnection::CreateSender(
     const std::string& kind) {
+  TRACE_EVENT0("webrtc", "PeerConnection::CreateSender");
   RtpSenderInterface* new_sender;
   if (kind == MediaStreamTrackInterface::kAudioKind) {
     new_sender = new AudioRtpSender(session_.get(), stats_.get());
@@ -874,6 +881,7 @@ PeerConnection::GetReceivers() const {
 bool PeerConnection::GetStats(StatsObserver* observer,
                               MediaStreamTrackInterface* track,
                               StatsOutputLevel level) {
+  TRACE_EVENT0("webrtc", "PeerConnection::GetStats");
   RTC_DCHECK(signaling_thread()->IsCurrent());
   if (!VERIFY(observer != NULL)) {
     LOG(LS_ERROR) << "GetStats - observer is NULL.";
@@ -908,6 +916,7 @@ rtc::scoped_refptr<DataChannelInterface>
 PeerConnection::CreateDataChannel(
     const std::string& label,
     const DataChannelInit* config) {
+  TRACE_EVENT0("webrtc", "PeerConnection::CreateDataChannel");
   bool first_datachannel = !HasDataChannels();
 
   rtc::scoped_ptr<InternalDataChannelInit> internal_config;
@@ -931,6 +940,7 @@ PeerConnection::CreateDataChannel(
 
 void PeerConnection::CreateOffer(CreateSessionDescriptionObserver* observer,
                                  const MediaConstraintsInterface* constraints) {
+  TRACE_EVENT0("webrtc", "PeerConnection::CreateOffer");
   if (!VERIFY(observer != nullptr)) {
     LOG(LS_ERROR) << "CreateOffer - observer is NULL.";
     return;
@@ -982,6 +992,7 @@ void PeerConnection::CreateOffer(CreateSessionDescriptionObserver* observer,
 
 void PeerConnection::CreateOffer(CreateSessionDescriptionObserver* observer,
                                  const RTCOfferAnswerOptions& options) {
+  TRACE_EVENT0("webrtc", "PeerConnection::CreateOffer");
   if (!VERIFY(observer != nullptr)) {
     LOG(LS_ERROR) << "CreateOffer - observer is NULL.";
     return;
@@ -1001,6 +1012,7 @@ void PeerConnection::CreateOffer(CreateSessionDescriptionObserver* observer,
 void PeerConnection::CreateAnswer(
     CreateSessionDescriptionObserver* observer,
     const MediaConstraintsInterface* constraints) {
+  TRACE_EVENT0("webrtc", "PeerConnection::CreateAnswer");
   if (!VERIFY(observer != nullptr)) {
     LOG(LS_ERROR) << "CreateAnswer - observer is NULL.";
     return;
@@ -1020,6 +1032,7 @@ void PeerConnection::CreateAnswer(
 void PeerConnection::SetLocalDescription(
     SetSessionDescriptionObserver* observer,
     SessionDescriptionInterface* desc) {
+  TRACE_EVENT0("webrtc", "PeerConnection::SetLocalDescription");
   if (!VERIFY(observer != nullptr)) {
     LOG(LS_ERROR) << "SetLocalDescription - observer is NULL.";
     return;
@@ -1097,6 +1110,7 @@ void PeerConnection::SetLocalDescription(
 void PeerConnection::SetRemoteDescription(
     SetSessionDescriptionObserver* observer,
     SessionDescriptionInterface* desc) {
+  TRACE_EVENT0("webrtc", "PeerConnection::SetRemoteDescription");
   if (!VERIFY(observer != nullptr)) {
     LOG(LS_ERROR) << "SetRemoteDescription - observer is NULL.";
     return;
@@ -1198,6 +1212,7 @@ void PeerConnection::SetRemoteDescription(
 }
 
 bool PeerConnection::SetConfiguration(const RTCConfiguration& config) {
+  TRACE_EVENT0("webrtc", "PeerConnection::SetConfiguration");
   if (port_allocator_) {
     std::vector<PortAllocatorFactoryInterface::StunConfiguration> stuns;
     std::vector<PortAllocatorFactoryInterface::TurnConfiguration> turns;
@@ -1216,10 +1231,12 @@ bool PeerConnection::SetConfiguration(const RTCConfiguration& config) {
 
 bool PeerConnection::AddIceCandidate(
     const IceCandidateInterface* ice_candidate) {
+  TRACE_EVENT0("webrtc", "PeerConnection::AddIceCandidate");
   return session_->ProcessIceMessage(ice_candidate);
 }
 
 void PeerConnection::RegisterUMAObserver(UMAObserver* observer) {
+  TRACE_EVENT0("webrtc", "PeerConnection::RegisterUmaObserver");
   uma_observer_ = observer;
 
   if (session_) {
@@ -1249,6 +1266,7 @@ const SessionDescriptionInterface* PeerConnection::remote_description() const {
 }
 
 void PeerConnection::Close() {
+  TRACE_EVENT0("webrtc", "PeerConnection::Close");
   // Update stats here so that we have the most recent stats for tracks and
   // streams before the channels are closed.
   stats_->UpdateStats(kStatsOutputLevelStandard);

talk/app/webrtc/webrtcsession.cc

@@ -50,7 +50,6 @@
 #include "webrtc/base/logging.h"
 #include "webrtc/base/stringencode.h"
 #include "webrtc/base/stringutils.h"
-#include "webrtc/base/trace_event.h"
 #include "webrtc/call.h"
 #include "webrtc/p2p/base/portallocator.h"
 #include "webrtc/p2p/base/transportchannel.h"
@@ -791,7 +790,6 @@ void WebRtcSession::CreateAnswer(
 
 bool WebRtcSession::SetLocalDescription(SessionDescriptionInterface* desc,
                                         std::string* err_desc) {
-  TRACE_EVENT0("webrtc", "WebRtcSession::SetLocalDescription");
   ASSERT(signaling_thread()->IsCurrent());
 
   // Takes the ownership of |desc| regardless of the result.
@@ -846,7 +844,6 @@ bool WebRtcSession::SetLocalDescription(SessionDescriptionInterface* desc,
 
 bool WebRtcSession::SetRemoteDescription(SessionDescriptionInterface* desc,
                                          std::string* err_desc) {
-  TRACE_EVENT0("webrtc", "WebRtcSession::SetRemoteDescription");
   ASSERT(signaling_thread()->IsCurrent());
 
   // Takes the ownership of |desc| regardless of the result.

talk/session/media/channelmanager.cc

@@ -49,6 +49,7 @@
 #include "webrtc/base/sigslotrepeater.h"
 #include "webrtc/base/stringencode.h"
 #include "webrtc/base/stringutils.h"
+#include "webrtc/base/trace_event.h"
 
 namespace cricket {
 
@@ -288,6 +289,7 @@ VoiceChannel* ChannelManager::CreateVoiceChannel_w(
 }
 
 void ChannelManager::DestroyVoiceChannel(VoiceChannel* voice_channel) {
+  TRACE_EVENT0("webrtc", "ChannelManager::DestroyVoiceChannel");
   if (voice_channel) {
     worker_thread_->Invoke<void>(
         Bind(&ChannelManager::DestroyVoiceChannel_w, this, voice_channel));
@@ -295,6 +297,7 @@ void ChannelManager::DestroyVoiceChannel(VoiceChannel* voice_channel) {
 }
 
 void ChannelManager::DestroyVoiceChannel_w(VoiceChannel* voice_channel) {
+  TRACE_EVENT0("webrtc", "ChannelManager::DestroyVoiceChannel_w");
   // Destroy voice channel.
   ASSERT(initialized_);
   ASSERT(worker_thread_ == rtc::Thread::Current());
@@ -344,6 +347,7 @@ VideoChannel* ChannelManager::CreateVideoChannel_w(
 }
 
 void ChannelManager::DestroyVideoChannel(VideoChannel* video_channel) {
+  TRACE_EVENT0("webrtc", "ChannelManager::DestroyVideoChannel");
   if (video_channel) {
     worker_thread_->Invoke<void>(
         Bind(&ChannelManager::DestroyVideoChannel_w, this, video_channel));
@@ -351,6 +355,7 @@ void ChannelManager::DestroyVideoChannel(VideoChannel* video_channel) {
 }
 
 void ChannelManager::DestroyVideoChannel_w(VideoChannel* video_channel) {
+  TRACE_EVENT0("webrtc", "ChannelManager::DestroyVideoChannel_w");
   // Destroy video channel.
   ASSERT(initialized_);
   ASSERT(worker_thread_ == rtc::Thread::Current());
@@ -401,6 +406,7 @@ DataChannel* ChannelManager::CreateDataChannel_w(
 }
 
 void ChannelManager::DestroyDataChannel(DataChannel* data_channel) {
+  TRACE_EVENT0("webrtc", "ChannelManager::DestroyDataChannel");
   if (data_channel) {
     worker_thread_->Invoke<void>(
         Bind(&ChannelManager::DestroyDataChannel_w, this, data_channel));
@@ -408,6 +414,7 @@ void ChannelManager::DestroyDataChannel(DataChannel* data_channel) {
 }
 
 void ChannelManager::DestroyDataChannel_w(DataChannel* data_channel) {
+  TRACE_EVENT0("webrtc", "ChannelManager::DestroyDataChannel_w");
   // Destroy data channel.
   ASSERT(initialized_);
   DataChannels::iterator it = std::find(data_channels_.begin(),