Log content name (aka mid) in messages from channel.cc
Logging of content name (mid) is valuable to debug issues
in scenarios with multiple m= line sections in SDP.
For example, video conferencing applications which
uses SFU and Unified Plan SDPs will likely to leverage
from more detailed logs when issues need to be debugged.
Bug: webrtc:10139
Change-Id: Id52ba3ad54af5caa0f8c03daaa51bdb0caf9fe67
Reviewed-on: https://webrtc-review.googlesource.com/c/src/+/175115
Commit-Queue: Tommi <tommi@webrtc.org>
Reviewed-by: Tommi <tommi@webrtc.org>
Cr-Commit-Position: refs/heads/master@{#31302}
diff --git a/pc/channel.cc b/pc/channel.cc
index f83f5cd..8a3a800 100644
--- a/pc/channel.cc
+++ b/pc/channel.cc
@@ -142,7 +142,7 @@
RTC_DCHECK_RUN_ON(worker_thread_);
RTC_DCHECK(ssrc_generator_);
demuxer_criteria_.mid = content_name;
- RTC_LOG(LS_INFO) << "Created channel for " << content_name;
+ RTC_LOG(LS_INFO) << "Created channel: " << ToString();
}
BaseChannel::~BaseChannel() {
@@ -156,12 +156,23 @@
// the media channel may try to send on the dead transport channel. NULLing
// is not an effective strategy since the sends will come on another thread.
media_channel_.reset();
- RTC_LOG(LS_INFO) << "Destroyed channel: " << content_name_;
+ RTC_LOG(LS_INFO) << "Destroyed channel: " << ToString();
+}
+
+std::string BaseChannel::ToString() const {
+ rtc::StringBuilder sb;
+ sb << "{mid: " << content_name_;
+ if (media_channel_) {
+ sb << ", media_type: " << MediaTypeToString(media_channel_->media_type());
+ }
+ sb << "}";
+ return sb.Release();
}
bool BaseChannel::ConnectToRtpTransport() {
RTC_DCHECK(rtp_transport_);
if (!RegisterRtpDemuxerSink()) {
+ RTC_LOG(LS_ERROR) << "Failed to set up demuxing for " << ToString();
return false;
}
rtp_transport_->SignalReadyToSend.connect(
@@ -237,7 +248,8 @@
transport_name_ = rtp_transport_->transport_name();
if (!ConnectToRtpTransport()) {
- RTC_LOG(LS_ERROR) << "Failed to connect to the new RtpTransport.";
+ RTC_LOG(LS_ERROR) << "Failed to connect to the new RtpTransport for "
+ << ToString() << ".";
return false;
}
OnTransportReadyToSend(rtp_transport_->IsReadyToSend());
@@ -349,7 +361,7 @@
void BaseChannel::OnNetworkRouteChanged(
absl::optional<rtc::NetworkRoute> network_route) {
- RTC_LOG(LS_INFO) << "Network route was changed.";
+ RTC_LOG(LS_INFO) << "Network route for " << ToString() << " was changed.";
RTC_DCHECK(network_thread_->IsCurrent());
rtc::NetworkRoute new_route;
@@ -404,7 +416,7 @@
// Protect ourselves against crazy data.
if (!IsValidRtpPacketSize(packet_type, packet->size())) {
- RTC_LOG(LS_ERROR) << "Dropping outgoing " << content_name_ << " "
+ RTC_LOG(LS_ERROR) << "Dropping outgoing " << ToString() << " "
<< RtpPacketTypeToString(packet_type)
<< " packet: wrong size=" << packet->size();
return false;
@@ -420,16 +432,16 @@
}
// However, there shouldn't be any RTP packets sent before SRTP is set up
// (and SetSend(true) is called).
- RTC_LOG(LS_ERROR)
- << "Can't send outgoing RTP packet when SRTP is inactive"
- " and crypto is required";
+ RTC_LOG(LS_ERROR) << "Can't send outgoing RTP packet for " << ToString()
+ << " when SRTP is inactive and crypto is required";
RTC_NOTREACHED();
return false;
}
std::string packet_type = rtcp ? "RTCP" : "RTP";
RTC_LOG(LS_WARNING) << "Sending an " << packet_type
- << " packet without encryption.";
+ << " packet without encryption for " << ToString()
+ << ".";
}
// Bon voyage.
@@ -463,7 +475,8 @@
// for us to just eat packets here. This is all sidestepped if RTCP mux
// is used anyway.
RTC_LOG(LS_WARNING) << "Can't process incoming RTP packet when "
- "SRTP is inactive and crypto is required";
+ "SRTP is inactive and crypto is required "
+ << ToString();
return;
}
@@ -504,7 +517,7 @@
if (enabled_)
return;
- RTC_LOG(LS_INFO) << "Channel enabled";
+ RTC_LOG(LS_INFO) << "Channel enabled: " << ToString();
enabled_ = true;
UpdateMediaSendRecvState_w();
}
@@ -514,7 +527,7 @@
if (!enabled_)
return;
- RTC_LOG(LS_INFO) << "Channel disabled";
+ RTC_LOG(LS_INFO) << "Channel disabled: " << ToString();
enabled_ = false;
UpdateMediaSendRecvState_w();
}
@@ -534,7 +547,7 @@
return;
}
- RTC_LOG(LS_INFO) << "Channel writable (" << content_name_ << ")"
+ RTC_LOG(LS_INFO) << "Channel writable (" << ToString() << ")"
<< (was_ever_writable_ ? "" : " for the first time");
was_ever_writable_ = true;
@@ -547,7 +560,7 @@
if (!writable_)
return;
- RTC_LOG(LS_INFO) << "Channel not writable (" << content_name_ << ")";
+ RTC_LOG(LS_INFO) << "Channel not writable (" << ToString() << ")";
writable_ = false;
UpdateMediaSendRecvState();
}
@@ -632,7 +645,8 @@
}
if (media_channel()->AddSendStream(new_stream)) {
- RTC_LOG(LS_INFO) << "Add send stream ssrc: " << new_stream.ssrcs[0];
+ RTC_LOG(LS_INFO) << "Add send stream ssrc: " << new_stream.ssrcs[0]
+ << " into " << ToString();
} else {
rtc::StringBuilder desc;
desc << "Failed to add send stream ssrc: " << new_stream.first_ssrc();
@@ -655,11 +669,13 @@
// the unsignaled stream params that are cached.
if (!old_stream.has_ssrcs() && !HasStreamWithNoSsrcs(streams)) {
ResetUnsignaledRecvStream_w();
- RTC_LOG(LS_INFO) << "Reset unsignaled remote stream.";
+ RTC_LOG(LS_INFO) << "Reset unsignaled remote stream for " << ToString()
+ << ".";
} else if (old_stream.has_ssrcs() &&
!GetStreamBySsrc(streams, old_stream.first_ssrc())) {
if (RemoveRecvStream_w(old_stream.first_ssrc())) {
- RTC_LOG(LS_INFO) << "Remove remote ssrc: " << old_stream.first_ssrc();
+ RTC_LOG(LS_INFO) << "Remove remote ssrc: " << old_stream.first_ssrc()
+ << " from " << ToString() << ".";
} else {
rtc::StringBuilder desc;
desc << "Failed to remove remote stream with ssrc "
@@ -681,13 +697,15 @@
RTC_LOG(LS_INFO) << "Add remote ssrc: "
<< (new_stream.has_ssrcs()
? std::to_string(new_stream.first_ssrc())
- : "unsignaled");
+ : "unsignaled")
+ << " to " << ToString();
} else {
rtc::StringBuilder desc;
desc << "Failed to add remote stream ssrc: "
<< (new_stream.has_ssrcs()
? std::to_string(new_stream.first_ssrc())
- : "unsignaled");
+ : "unsignaled")
+ << " to " << ToString();
SafeSetError(desc.str(), error_desc);
ret = false;
}
@@ -697,7 +715,9 @@
new_stream.ssrcs.end());
}
// Re-register the sink to update the receiving ssrcs.
- RegisterRtpDemuxerSink();
+ if (!RegisterRtpDemuxerSink()) {
+ RTC_LOG(LS_ERROR) << "Failed to set up demuxing for " << ToString();
+ }
remote_streams_ = streams;
return ret;
}
@@ -813,7 +833,8 @@
bool send = IsReadyToSendMedia_w();
media_channel()->SetSend(send);
- RTC_LOG(LS_INFO) << "Changing voice state, recv=" << recv << " send=" << send;
+ RTC_LOG(LS_INFO) << "Changing voice state, recv=" << recv << " send=" << send
+ << " for " << ToString();
}
bool VoiceChannel::SetLocalContent_w(const MediaContentDescription* content,
@@ -821,7 +842,7 @@
std::string* error_desc) {
TRACE_EVENT0("webrtc", "VoiceChannel::SetLocalContent_w");
RTC_DCHECK_RUN_ON(worker_thread());
- RTC_LOG(LS_INFO) << "Setting local voice description";
+ RTC_LOG(LS_INFO) << "Setting local voice description for " << ToString();
RTC_DCHECK(content);
if (!content) {
@@ -852,7 +873,7 @@
}
// Need to re-register the sink to update the handled payload.
if (!RegisterRtpDemuxerSink()) {
- RTC_LOG(LS_ERROR) << "Failed to set up audio demuxing.";
+ RTC_LOG(LS_ERROR) << "Failed to set up audio demuxing for " << ToString();
return false;
}
}
@@ -878,7 +899,7 @@
std::string* error_desc) {
TRACE_EVENT0("webrtc", "VoiceChannel::SetRemoteContent_w");
RTC_DCHECK_RUN_ON(worker_thread());
- RTC_LOG(LS_INFO) << "Setting remote voice description";
+ RTC_LOG(LS_INFO) << "Setting remote voice description for " << ToString();
RTC_DCHECK(content);
if (!content) {
@@ -907,10 +928,11 @@
if (!webrtc::RtpTransceiverDirectionHasSend(content->direction())) {
RTC_DLOG(LS_VERBOSE) << "SetRemoteContent_w: remote side will not send - "
- "disable payload type demuxing";
+ "disable payload type demuxing for "
+ << ToString();
ClearHandledPayloadTypes();
if (!RegisterRtpDemuxerSink()) {
- RTC_LOG(LS_ERROR) << "Failed to update audio demuxing.";
+ RTC_LOG(LS_ERROR) << "Failed to update audio demuxing for " << ToString();
return false;
}
}
@@ -958,11 +980,12 @@
// and we have had some form of connectivity.
bool send = IsReadyToSendMedia_w();
if (!media_channel()->SetSend(send)) {
- RTC_LOG(LS_ERROR) << "Failed to SetSend on video channel";
+ RTC_LOG(LS_ERROR) << "Failed to SetSend on video channel: " + ToString();
// TODO(gangji): Report error back to server.
}
- RTC_LOG(LS_INFO) << "Changing video state, send=" << send;
+ RTC_LOG(LS_INFO) << "Changing video state, send=" << send << " for "
+ << ToString();
}
void VideoChannel::FillBitrateInfo(BandwidthEstimationInfo* bwe_info) {
@@ -975,7 +998,7 @@
std::string* error_desc) {
TRACE_EVENT0("webrtc", "VideoChannel::SetLocalContent_w");
RTC_DCHECK_RUN_ON(worker_thread());
- RTC_LOG(LS_INFO) << "Setting local video description";
+ RTC_LOG(LS_INFO) << "Setting local video description for " << ToString();
RTC_DCHECK(content);
if (!content) {
@@ -1027,7 +1050,7 @@
}
// Need to re-register the sink to update the handled payload.
if (!RegisterRtpDemuxerSink()) {
- RTC_LOG(LS_ERROR) << "Failed to set up video demuxing.";
+ RTC_LOG(LS_ERROR) << "Failed to set up video demuxing for " << ToString();
return false;
}
}
@@ -1061,7 +1084,7 @@
std::string* error_desc) {
TRACE_EVENT0("webrtc", "VideoChannel::SetRemoteContent_w");
RTC_DCHECK_RUN_ON(worker_thread());
- RTC_LOG(LS_INFO) << "Setting remote video description";
+ RTC_LOG(LS_INFO) << "Setting remote video description for " << ToString();
RTC_DCHECK(content);
if (!content) {
@@ -1120,10 +1143,11 @@
if (!webrtc::RtpTransceiverDirectionHasSend(content->direction())) {
RTC_DLOG(LS_VERBOSE) << "SetRemoteContent_w: remote side will not send - "
- "disable payload type demuxing";
+ "disable payload type demuxing for "
+ << ToString();
ClearHandledPayloadTypes();
if (!RegisterRtpDemuxerSink()) {
- RTC_LOG(LS_ERROR) << "Failed to update video demuxing.";
+ RTC_LOG(LS_ERROR) << "Failed to update video demuxing for " << ToString();
return false;
}
}
@@ -1203,7 +1227,7 @@
std::string* error_desc) {
TRACE_EVENT0("webrtc", "RtpDataChannel::SetLocalContent_w");
RTC_DCHECK_RUN_ON(worker_thread());
- RTC_LOG(LS_INFO) << "Setting local data description";
+ RTC_LOG(LS_INFO) << "Setting local data description for " << ToString();
RTC_DCHECK(content);
if (!content) {
@@ -1233,7 +1257,7 @@
}
// Need to re-register the sink to update the handled payload.
if (!RegisterRtpDemuxerSink()) {
- RTC_LOG(LS_ERROR) << "Failed to set up data demuxing.";
+ RTC_LOG(LS_ERROR) << "Failed to set up data demuxing for " << ToString();
return false;
}
@@ -1258,7 +1282,7 @@
std::string* error_desc) {
TRACE_EVENT0("webrtc", "RtpDataChannel::SetRemoteContent_w");
RTC_DCHECK_RUN_ON(worker_thread());
- RTC_LOG(LS_INFO) << "Setting remote data description";
+ RTC_LOG(LS_INFO) << "Setting remote data description for " << ToString();
RTC_DCHECK(content);
if (!content) {
@@ -1280,7 +1304,7 @@
RtpHeaderExtensions rtp_header_extensions =
GetFilteredRtpHeaderExtensions(data->rtp_header_extensions());
- RTC_LOG(LS_INFO) << "Setting remote data description";
+ RTC_LOG(LS_INFO) << "Setting remote data description for " << ToString();
DataSendParameters send_params = last_send_params_;
RtpSendParametersFromMediaDescription<DataCodec>(
data, rtp_header_extensions,
@@ -1311,20 +1335,21 @@
// content. We receive data on the default channel and multiplexed streams.
bool recv = IsReadyToReceiveMedia_w();
if (!media_channel()->SetReceive(recv)) {
- RTC_LOG(LS_ERROR) << "Failed to SetReceive on data channel";
+ RTC_LOG(LS_ERROR) << "Failed to SetReceive on data channel: " << ToString();
}
// Send outgoing data if we're the active call, we have the remote content,
// and we have had some form of connectivity.
bool send = IsReadyToSendMedia_w();
if (!media_channel()->SetSend(send)) {
- RTC_LOG(LS_ERROR) << "Failed to SetSend on data channel";
+ RTC_LOG(LS_ERROR) << "Failed to SetSend on data channel: " << ToString();
}
// Trigger SignalReadyToSendData asynchronously.
OnDataChannelReadyToSend(send);
- RTC_LOG(LS_INFO) << "Changing data state, recv=" << recv << " send=" << send;
+ RTC_LOG(LS_INFO) << "Changing data state, recv=" << recv << " send=" << send
+ << " for " << ToString();
}
void RtpDataChannel::OnMessage(rtc::Message* pmsg) {
diff --git a/pc/channel.h b/pc/channel.h
index 238a8e2..9dc6522 100644
--- a/pc/channel.h
+++ b/pc/channel.h
@@ -275,6 +275,9 @@
bool RegisterRtpDemuxerSink();
+ // Return description of media channel to facilitate logging
+ std::string ToString() const;
+
bool has_received_packet_ = false;
private:
