Add more trace events to interesting places. Bug: webrtc:12840 Change-Id: I57e5373ae33060bd3743cea8ada21c845cbbd944 Reviewed-on: https://webrtc-review.googlesource.com/c/src/+/221365 Commit-Queue: Markus Handell <handellm@webrtc.org> Reviewed-by: Harald Alvestrand <hta@webrtc.org> Cr-Commit-Position: refs/heads/master@{#34237}
diff --git a/p2p/base/p2p_transport_channel.cc b/p2p/base/p2p_transport_channel.cc index eff79ab..836721c 100644 --- a/p2p/base/p2p_transport_channel.cc +++ b/p2p/base/p2p_transport_channel.cc
@@ -43,6 +43,7 @@ #include "rtc_base/task_utils/to_queued_task.h" #include "rtc_base/third_party/sigslot/sigslot.h" #include "rtc_base/time_utils.h" +#include "rtc_base/trace_event.h" #include "system_wrappers/include/field_trial.h" #include "system_wrappers/include/metrics.h" @@ -193,6 +194,7 @@ true /* presume_writable_when_fully_relayed */, REGATHER_ON_FAILED_NETWORKS_INTERVAL, RECEIVING_SWITCHING_DELAY) { + TRACE_EVENT0("webrtc", "P2PTransportChannel::P2PTransportChannel"); RTC_DCHECK(allocator_ != nullptr); weak_ping_interval_ = GetWeakPingIntervalInFieldTrial(); // Validate IceConfig even for mostly built-in constant default values in case @@ -247,6 +249,7 @@ ice_controller_factory) {} P2PTransportChannel::~P2PTransportChannel() { + TRACE_EVENT0("webrtc", "P2PTransportChannel::~P2PTransportChannel"); RTC_DCHECK_RUN_ON(network_thread_); std::vector<Connection*> copy(connections().begin(), connections().end()); for (Connection* con : copy) {
diff --git a/p2p/base/port.cc b/p2p/base/port.cc index d24d40f..0a123b4 100644 --- a/p2p/base/port.cc +++ b/p2p/base/port.cc
@@ -33,6 +33,7 @@ #include "rtc_base/string_utils.h" #include "rtc_base/strings/string_builder.h" #include "rtc_base/third_party/base64/base64.h" +#include "rtc_base/trace_event.h" #include "system_wrappers/include/field_trial.h" namespace { @@ -836,6 +837,7 @@ // Call to stop any currently pending operations from running. void Port::CancelPendingTasks() { + TRACE_EVENT0("webrtc", "Port::CancelPendingTasks"); RTC_DCHECK_RUN_ON(thread_); thread_->Clear(this); }
diff --git a/p2p/client/basic_port_allocator.cc b/p2p/client/basic_port_allocator.cc index 7e1f970..a190fb7 100644 --- a/p2p/client/basic_port_allocator.cc +++ b/p2p/client/basic_port_allocator.cc
@@ -27,6 +27,7 @@ #include "rtc_base/checks.h" #include "rtc_base/helpers.h" #include "rtc_base/logging.h" +#include "rtc_base/trace_event.h" #include "system_wrappers/include/field_trial.h" #include "system_wrappers/include/metrics.h" @@ -268,12 +269,16 @@ network_manager_started_(false), allocation_sequences_created_(false), turn_port_prune_policy_(allocator->turn_port_prune_policy()) { + TRACE_EVENT0("webrtc", + "BasicPortAllocatorSession::BasicPortAllocatorSession"); allocator_->network_manager()->SignalNetworksChanged.connect( this, &BasicPortAllocatorSession::OnNetworksChanged); allocator_->network_manager()->StartUpdating(); } BasicPortAllocatorSession::~BasicPortAllocatorSession() { + TRACE_EVENT0("webrtc", + "BasicPortAllocatorSession::~BasicPortAllocatorSession"); RTC_DCHECK_RUN_ON(network_thread_); allocator_->network_manager()->StopUpdating(); if (network_thread_ != NULL) @@ -1248,6 +1253,7 @@ } void AllocationSequence::Clear() { + TRACE_EVENT0("webrtc", "AllocationSequence::Clear"); udp_port_ = NULL; relay_ports_.clear(); }
diff --git a/pc/channel.cc b/pc/channel.cc index a8ecd4b..8630703 100644 --- a/pc/channel.cc +++ b/pc/channel.cc
@@ -220,6 +220,7 @@ } bool BaseChannel::SetRtpTransport(webrtc::RtpTransportInternal* rtp_transport) { + TRACE_EVENT0("webrtc", "BaseChannel::SetRtpTransport"); RTC_DCHECK_RUN_ON(network_thread()); if (rtp_transport == rtp_transport_) { return true; @@ -524,6 +525,7 @@ } void BaseChannel::UpdateWritableState_n() { + TRACE_EVENT0("webrtc", "BaseChannel::UpdateWritableState_n"); if (rtp_transport_->IsWritable(/*rtcp=*/true) && rtp_transport_->IsWritable(/*rtcp=*/false)) { ChannelWritable_n(); @@ -533,6 +535,7 @@ } void BaseChannel::ChannelWritable_n() { + TRACE_EVENT0("webrtc", "BaseChannel::ChannelWritable_n"); if (writable_) { return; } @@ -552,6 +555,7 @@ } void BaseChannel::ChannelNotWritable_n() { + TRACE_EVENT0("webrtc", "BaseChannel::ChannelNotWritable_n"); if (!writable_) { return; }
diff --git a/pc/jsep_transport.cc b/pc/jsep_transport.cc index dc4649b..e720888 100644 --- a/pc/jsep_transport.cc +++ b/pc/jsep_transport.cc
@@ -26,6 +26,7 @@ #include "rtc_base/logging.h" #include "rtc_base/ref_counted_object.h" #include "rtc_base/strings/string_builder.h" +#include "rtc_base/trace_event.h" using webrtc::SdpType; @@ -104,6 +105,7 @@ ? rtc::make_ref_counted<webrtc::SctpTransport>( std::move(sctp_transport)) : nullptr) { + TRACE_EVENT0("webrtc", "JsepTransport::JsepTransport"); RTC_DCHECK(ice_transport_); RTC_DCHECK(rtp_dtls_transport_); // |rtcp_ice_transport_| must be present iff |rtcp_dtls_transport_| is @@ -129,6 +131,7 @@ } JsepTransport::~JsepTransport() { + TRACE_EVENT0("webrtc", "JsepTransport::~JsepTransport"); if (sctp_transport_) { sctp_transport_->Clear(); } @@ -147,7 +150,7 @@ const JsepTransportDescription& jsep_description, SdpType type) { webrtc::RTCError error; - + TRACE_EVENT0("webrtc", "JsepTransport::SetLocalJsepTransportDescription"); RTC_DCHECK_RUN_ON(network_thread_); IceParameters ice_parameters = @@ -233,6 +236,7 @@ webrtc::RTCError JsepTransport::SetRemoteJsepTransportDescription( const JsepTransportDescription& jsep_description, webrtc::SdpType type) { + TRACE_EVENT0("webrtc", "JsepTransport::SetLocalJsepTransportDescription"); webrtc::RTCError error; RTC_DCHECK_RUN_ON(network_thread_); @@ -344,6 +348,7 @@ } bool JsepTransport::GetStats(TransportStats* stats) { + TRACE_EVENT0("webrtc", "JsepTransport::GetStats"); RTC_DCHECK_RUN_ON(network_thread_); stats->transport_name = mid(); stats->channel_stats.clear(); @@ -362,6 +367,7 @@ webrtc::RTCError JsepTransport::VerifyCertificateFingerprint( const rtc::RTCCertificate* certificate, const rtc::SSLFingerprint* fingerprint) const { + TRACE_EVENT0("webrtc", "JsepTransport::VerifyCertificateFingerprint"); RTC_DCHECK_RUN_ON(network_thread_); if (!fingerprint) { return webrtc::RTCError(webrtc::RTCErrorType::INVALID_PARAMETER, @@ -400,6 +406,7 @@ void JsepTransport::SetRemoteIceParameters( const IceParameters& ice_parameters, IceTransportInternal* ice_transport) { + TRACE_EVENT0("webrtc", "JsepTransport::SetRemoteIceParameters"); RTC_DCHECK_RUN_ON(network_thread_); RTC_DCHECK(ice_transport); RTC_DCHECK(remote_description_);
diff --git a/pc/jsep_transport_controller.cc b/pc/jsep_transport_controller.cc index 78aa032..a124389 100644 --- a/pc/jsep_transport_controller.cc +++ b/pc/jsep_transport_controller.cc
@@ -32,6 +32,7 @@ #include "rtc_base/net_helper.h" #include "rtc_base/socket_address.h" #include "rtc_base/thread.h" +#include "rtc_base/trace_event.h" using webrtc::SdpType; @@ -77,6 +78,7 @@ RTCError JsepTransportController::SetLocalDescription( SdpType type, const cricket::SessionDescription* description) { + TRACE_EVENT0("webrtc", "JsepTransportController::SetLocalDescription"); if (!network_thread_->IsCurrent()) { return network_thread_->Invoke<RTCError>( RTC_FROM_HERE, [=] { return SetLocalDescription(type, description); }); @@ -97,6 +99,7 @@ RTCError JsepTransportController::SetRemoteDescription( SdpType type, const cricket::SessionDescription* description) { + TRACE_EVENT0("webrtc", "JsepTransportController::SetRemoteDescription"); if (!network_thread_->IsCurrent()) { return network_thread_->Invoke<RTCError>( RTC_FROM_HERE, [=] { return SetRemoteDescription(type, description); }); @@ -539,6 +542,7 @@ bool local, SdpType type, const cricket::SessionDescription* description) { + TRACE_EVENT0("webrtc", "JsepTransportController::ApplyDescription_n"); RTC_DCHECK(description); if (local) { @@ -866,6 +870,7 @@ bool JsepTransportController::HandleBundledContent( const cricket::ContentInfo& content_info, const cricket::ContentGroup& bundle_group) { + TRACE_EVENT0("webrtc", "JsepTransportController::HandleBundledContent"); RTC_DCHECK(bundle_group.FirstContentName()); auto jsep_transport = GetJsepTransportByName(*bundle_group.FirstContentName()); @@ -887,6 +892,7 @@ bool JsepTransportController::SetTransportForMid( const std::string& mid, cricket::JsepTransport* jsep_transport) { + TRACE_EVENT0("webrtc", "JsepTransportController::SetTransportForMid"); RTC_DCHECK_RUN_ON(network_thread_); RTC_DCHECK(jsep_transport); @@ -924,6 +930,8 @@ const cricket::TransportInfo& transport_info, const std::vector<int>& encrypted_extension_ids, int rtp_abs_sendtime_extn_id) { + TRACE_EVENT0("webrtc", + "JsepTransportController::CreateJsepTransportDescription"); const cricket::MediaContentDescription* content_desc = content_info.media_description(); RTC_DCHECK(content_desc); @@ -1127,6 +1135,7 @@ void JsepTransportController::MaybeDestroyJsepTransport( const std::string& mid) { + TRACE_EVENT0("webrtc", "JsepTransportController::MaybeDestroyJsepTransport"); auto jsep_transport = GetJsepTransportByName(mid); if (!jsep_transport) { return; @@ -1280,6 +1289,7 @@ } void JsepTransportController::UpdateAggregateStates_n() { + TRACE_EVENT0("webrtc", "JsepTransportController::UpdateAggregateStates_n"); auto dtls_transports = GetDtlsTransports(); cricket::IceConnectionState new_connection_state = cricket::kIceConnectionConnecting;
diff --git a/pc/peer_connection.cc b/pc/peer_connection.cc index 2ef00de..54b4934 100644 --- a/pc/peer_connection.cc +++ b/pc/peer_connection.cc
@@ -2188,6 +2188,7 @@ std::map<std::string, cricket::TransportStats> PeerConnection::GetTransportStatsByNames( const std::set<std::string>& transport_names) { + TRACE_EVENT0("webrtc", "PeerConnection::GetTransportStatsByNames"); RTC_DCHECK_RUN_ON(network_thread()); if (!network_thread_safety_->alive()) return {}; @@ -2636,6 +2637,7 @@ // Runs on network_thread(). void PeerConnection::ReportTransportStats() { + TRACE_EVENT0("webrtc", "PeerConnection::ReportTransportStats"); rtc::Thread::ScopedDisallowBlockingCalls no_blocking_calls; std::map<std::string, std::set<cricket::MediaType>> media_types_by_transport_name;
diff --git a/pc/rtc_stats_collector.cc b/pc/rtc_stats_collector.cc index d7b7ba7..4b38abc 100644 --- a/pc/rtc_stats_collector.cc +++ b/pc/rtc_stats_collector.cc
@@ -1273,6 +1273,8 @@ void RTCStatsCollector::ProducePartialResultsOnNetworkThread( int64_t timestamp_us, absl::optional<std::string> sctp_transport_name) { + TRACE_EVENT0("webrtc", + "RTCStatsCollector::ProducePartialResultsOnNetworkThread"); RTC_DCHECK_RUN_ON(network_thread_); rtc::Thread::ScopedDisallowBlockingCalls no_blocking_calls;
diff --git a/pc/sdp_offer_answer.cc b/pc/sdp_offer_answer.cc index 761ae7c..8aa1947 100644 --- a/pc/sdp_offer_answer.cc +++ b/pc/sdp_offer_answer.cc
@@ -1251,6 +1251,7 @@ std::unique_ptr<SessionDescriptionInterface> desc, const std::map<std::string, const cricket::ContentGroup*>& bundle_groups_by_mid) { + TRACE_EVENT0("webrtc", "SdpOfferAnswerHandler::ApplyLocalDescription"); RTC_DCHECK_RUN_ON(signaling_thread()); RTC_DCHECK(desc); @@ -1540,6 +1541,7 @@ std::unique_ptr<SessionDescriptionInterface> desc, const std::map<std::string, const cricket::ContentGroup*>& bundle_groups_by_mid) { + TRACE_EVENT0("webrtc", "SdpOfferAnswerHandler::ApplyRemoteDescription"); RTC_DCHECK_RUN_ON(signaling_thread()); RTC_DCHECK(desc); @@ -2025,6 +2027,7 @@ void SdpOfferAnswerHandler::CreateAnswer( CreateSessionDescriptionObserver* observer, const PeerConnectionInterface::RTCOfferAnswerOptions& options) { + TRACE_EVENT0("webrtc", "SdpOfferAnswerHandler::CreateAnswer"); RTC_DCHECK_RUN_ON(signaling_thread()); // Chain this operation. If asynchronous operations are pending on the chain, // this operation will be queued to be invoked, otherwise the contents of the @@ -2325,6 +2328,7 @@ void SdpOfferAnswerHandler::AddIceCandidate( std::unique_ptr<IceCandidateInterface> candidate, std::function<void(RTCError)> callback) { + TRACE_EVENT0("webrtc", "SdpOfferAnswerHandler::AddIceCandidate"); RTC_DCHECK_RUN_ON(signaling_thread()); // Chain this operation. If asynchronous operations are pending on the chain, // this operation will be queued to be invoked, otherwise the contents of the @@ -2456,6 +2460,7 @@ void SdpOfferAnswerHandler::ChangeSignalingState( PeerConnectionInterface::SignalingState signaling_state) { + TRACE_EVENT0("webrtc", "SdpOfferAnswerHandler::ChangeSignalingState"); RTC_DCHECK_RUN_ON(signaling_thread()); if (signaling_state_ == signaling_state) { return; @@ -2660,6 +2665,7 @@ } RTCError SdpOfferAnswerHandler::Rollback(SdpType desc_type) { + TRACE_EVENT0("webrtc", "SdpOfferAnswerHandler::Rollback"); auto state = signaling_state(); if (state != PeerConnectionInterface::kHaveLocalOffer && state != PeerConnectionInterface::kHaveRemoteOffer) { @@ -3119,6 +3125,8 @@ const SessionDescriptionInterface* old_remote_description, const std::map<std::string, const cricket::ContentGroup*>& bundle_groups_by_mid) { + TRACE_EVENT0("webrtc", + "SdpOfferAnswerHandler::UpdateTransceiversAndDataChannels"); RTC_DCHECK_RUN_ON(signaling_thread()); RTC_DCHECK(IsUnifiedPlan()); @@ -3205,6 +3213,7 @@ const ContentInfo& content, const ContentInfo* old_local_content, const ContentInfo* old_remote_content) { + TRACE_EVENT0("webrtc", "SdpOfferAnswerHandler::AssociateTransceiver"); RTC_DCHECK(IsUnifiedPlan()); #if RTC_DCHECK_IS_ON // If this is an offer then the m= section might be recycled. If the m= @@ -3338,6 +3347,7 @@ transceiver, const cricket::ContentInfo& content, const cricket::ContentGroup* bundle_group) { + TRACE_EVENT0("webrtc", "SdpOfferAnswerHandler::UpdateTransceiverChannel"); RTC_DCHECK(IsUnifiedPlan()); RTC_DCHECK(transceiver); cricket::ChannelInterface* channel = transceiver->internal()->channel(); @@ -4022,6 +4032,7 @@ void SdpOfferAnswerHandler::UpdateLocalSenders( const std::vector<cricket::StreamParams>& streams, cricket::MediaType media_type) { + TRACE_EVENT0("webrtc", "SdpOfferAnswerHandler::UpdateLocalSenders"); RTC_DCHECK_RUN_ON(signaling_thread()); std::vector<RtpSenderInfo>* current_senders = rtp_manager()->GetLocalSenderInfos(media_type); @@ -4064,6 +4075,7 @@ bool default_sender_needed, cricket::MediaType media_type, StreamCollection* new_streams) { + TRACE_EVENT0("webrtc", "SdpOfferAnswerHandler::UpdateRemoteSendersList"); RTC_DCHECK_RUN_ON(signaling_thread()); RTC_DCHECK(!IsUnifiedPlan()); @@ -4163,6 +4175,7 @@ } void SdpOfferAnswerHandler::EnableSending() { + TRACE_EVENT0("webrtc", "SdpOfferAnswerHandler::EnableSending"); RTC_DCHECK_RUN_ON(signaling_thread()); for (const auto& transceiver : transceivers()->ListInternal()) { cricket::ChannelInterface* channel = transceiver->channel(); @@ -4177,6 +4190,7 @@ cricket::ContentSource source, const std::map<std::string, const cricket::ContentGroup*>& bundle_groups_by_mid) { + TRACE_EVENT0("webrtc", "SdpOfferAnswerHandler::PushdownMediaDescription"); const SessionDescriptionInterface* sdesc = (source == cricket::CS_LOCAL ? local_description() : remote_description()); @@ -4270,6 +4284,7 @@ RTCError SdpOfferAnswerHandler::PushdownTransportDescription( cricket::ContentSource source, SdpType type) { + TRACE_EVENT0("webrtc", "SdpOfferAnswerHandler::PushdownTransportDescription"); RTC_DCHECK_RUN_ON(signaling_thread()); if (source == cricket::CS_LOCAL) { @@ -4286,6 +4301,7 @@ } void SdpOfferAnswerHandler::RemoveStoppedTransceivers() { + TRACE_EVENT0("webrtc", "SdpOfferAnswerHandler::RemoveStoppedTransceivers"); RTC_DCHECK_RUN_ON(signaling_thread()); // 3.2.10.1: For each transceiver in the connection's set of transceivers // run the following steps: @@ -4505,6 +4521,7 @@ } RTCError SdpOfferAnswerHandler::CreateChannels(const SessionDescription& desc) { + TRACE_EVENT0("webrtc", "SdpOfferAnswerHandler::CreateChannels"); // Creating the media channels. Transports should already have been created // at this point. RTC_DCHECK_RUN_ON(signaling_thread()); @@ -4545,6 +4562,7 @@ // TODO(steveanton): Perhaps this should be managed by the RtpTransceiver. cricket::VoiceChannel* SdpOfferAnswerHandler::CreateVoiceChannel( const std::string& mid) { + TRACE_EVENT0("webrtc", "SdpOfferAnswerHandler::CreateVoiceChannel"); RTC_DCHECK_RUN_ON(signaling_thread()); if (!channel_manager()->media_engine()) return nullptr; @@ -4563,6 +4581,7 @@ // TODO(steveanton): Perhaps this should be managed by the RtpTransceiver. cricket::VideoChannel* SdpOfferAnswerHandler::CreateVideoChannel( const std::string& mid) { + TRACE_EVENT0("webrtc", "SdpOfferAnswerHandler::CreateVideoChannel"); RTC_DCHECK_RUN_ON(signaling_thread()); if (!channel_manager()->media_engine()) return nullptr; @@ -4600,6 +4619,7 @@ void SdpOfferAnswerHandler::DestroyTransceiverChannel( rtc::scoped_refptr<RtpTransceiverProxyWithInternal<RtpTransceiver>> transceiver) { + TRACE_EVENT0("webrtc", "SdpOfferAnswerHandler::DestroyTransceiverChannel"); RTC_DCHECK(transceiver); RTC_LOG_THREAD_BLOCK_COUNT(); @@ -4648,6 +4668,7 @@ void SdpOfferAnswerHandler::DestroyChannelInterface( cricket::ChannelInterface* channel) { + TRACE_EVENT0("webrtc", "SdpOfferAnswerHandler::DestroyChannelInterface"); RTC_DCHECK_RUN_ON(signaling_thread()); RTC_DCHECK(channel_manager()->media_engine()); RTC_DCHECK(channel); @@ -4802,6 +4823,8 @@ cricket::ContentSource source, const std::map<std::string, const cricket::ContentGroup*>& bundle_groups_by_mid) { + TRACE_EVENT0("webrtc", + "SdpOfferAnswerHandler::UpdatePayloadTypeDemuxingState"); RTC_DCHECK_RUN_ON(signaling_thread()); // We may need to delete any created default streams and disable creation of // new ones on the basis of payload type. This is needed to avoid SSRC
diff --git a/pc/srtp_transport.cc b/pc/srtp_transport.cc index ee07349..c90b3fa 100644 --- a/pc/srtp_transport.cc +++ b/pc/srtp_transport.cc
@@ -201,12 +201,12 @@ void SrtpTransport::OnRtpPacketReceived(rtc::CopyOnWriteBuffer packet, int64_t packet_time_us) { + TRACE_EVENT0("webrtc", "SrtpTransport::OnRtpPacketReceived"); if (!IsSrtpActive()) { RTC_LOG(LS_WARNING) << "Inactive SRTP transport received an RTP packet. Drop it."; return; } - TRACE_EVENT0("webrtc", "SRTP Decode"); char* data = packet.MutableData<char>(); int len = rtc::checked_cast<int>(packet.size()); if (!UnprotectRtp(data, len, &len)) { @@ -233,12 +233,12 @@ void SrtpTransport::OnRtcpPacketReceived(rtc::CopyOnWriteBuffer packet, int64_t packet_time_us) { + TRACE_EVENT0("webrtc", "SrtpTransport::OnRtcpPacketReceived"); if (!IsSrtpActive()) { RTC_LOG(LS_WARNING) << "Inactive SRTP transport received an RTCP packet. Drop it."; return; } - TRACE_EVENT0("webrtc", "SRTP Decode"); char* data = packet.MutableData<char>(); int len = rtc::checked_cast<int>(packet.size()); if (!UnprotectRtcp(data, len, &len)) {
diff --git a/pc/stats_collector.cc b/pc/stats_collector.cc index 6d4c224..1728cb4 100644 --- a/pc/stats_collector.cc +++ b/pc/stats_collector.cc
@@ -50,6 +50,7 @@ #include "rtc_base/string_encode.h" #include "rtc_base/thread.h" #include "rtc_base/time_utils.h" +#include "rtc_base/trace_event.h" #include "system_wrappers/include/field_trial.h" namespace webrtc { @@ -849,6 +850,7 @@ } std::map<std::string, std::string> StatsCollector::ExtractSessionInfo() { + TRACE_EVENT0("webrtc", "StatsCollector::ExtractSessionInfo"); RTC_DCHECK_RUN_ON(pc_->signaling_thread()); SessionStats stats; @@ -870,6 +872,7 @@ RtpTransceiverProxyWithInternal<RtpTransceiver>>>& transceivers, absl::optional<std::string> sctp_transport_name, absl::optional<std::string> sctp_mid) { + TRACE_EVENT0("webrtc", "StatsCollector::ExtractSessionInfo_n"); RTC_DCHECK_RUN_ON(pc_->network_thread()); rtc::Thread::ScopedDisallowBlockingCalls no_blocking_calls; SessionStats stats;