admin/webrtc_m130
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

Remove LOG_J and LOG_JV, tweak p2p logs.

Browse Source 
Bug: webrtc:9077
Change-Id: I54ecf10592add33692fc6e694c2f10a646e81345
Reviewed-on: https://webrtc-review.googlesource.com/56142
Reviewed-by: Fredrik Solenberg <solenberg@webrtc.org>
Reviewed-by: Taylor Brandstetter <deadbeef@webrtc.org>
Reviewed-by: Qingsi Wang <qingsi@webrtc.org>
Reviewed-by: Karl Wiberg <kwiberg@webrtc.org>
Commit-Queue: Jonas Olsson <jonasolsson@webrtc.org>
Cr-Commit-Position: refs/heads/master@{#22667}
This commit is contained in:
Jonas Olsson 2018-03-28 09:47:51 +02:00 committed by Commit Bot
parent c99dc31501
commit d7d762d08d
16 changed files with 548 additions and 429 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

1
p2p/BUILD.gn
View File

@ -23,7 +23,6 @@ rtc_static_library("rtc_p2p") {
"base/basicpacketsocketfactory.cc",
"base/basicpacketsocketfactory.h",
"base/candidatepairinterface.h",
"base/common.h",
"base/dtlstransport.cc",
"base/dtlstransport.h",
"base/dtlstransportinternal.cc",

20
p2p/base/common.h
View File

@ -1,20 +0,0 @@
/*
* Copyright 2004 The WebRTC Project Authors. All rights reserved.
*
* Use of this source code is governed by a BSD-style license
* that can be found in the LICENSE file in the root of the source
* tree. An additional intellectual property rights grant can be found
* in the file PATENTS. All contributing project authors may
* be found in the AUTHORS file in the root of the source tree.
*/
#ifndef P2P_BASE_COMMON_H_
#define P2P_BASE_COMMON_H_
#include "rtc_base/logging.h"
// Common log description format for jingle messages
#define LOG_J(sev, obj) RTC_LOG(sev) << "Jingle:" << obj->ToString() << ": "
#define LOG_JV(sev, obj) RTC_LOG_V(sev) << "Jingle:" << obj->ToString() << ": "
#endif // P2P_BASE_COMMON_H_

129
p2p/base/dtlstransport.cc
View File

@ -14,11 +14,11 @@
#include "p2p/base/dtlstransport.h"
#include "p2p/base/common.h"
#include "p2p/base/packettransportinternal.h"
#include "rtc_base/buffer.h"
#include "rtc_base/checks.h"
#include "rtc_base/dscp.h"
#include "rtc_base/logging.h"
#include "rtc_base/messagequeue.h"
#include "rtc_base/sslstreamadapter.h"
#include "rtc_base/stream.h"
@ -170,10 +170,12 @@ bool DtlsTransport::SetLocalCertificate(
if (dtls_active_) {
if (certificate == local_certificate_) {
// This may happen during renegotiation.
LOG_J(LS_INFO, this) << "Ignoring identical DTLS identity";
RTC_LOG(LS_INFO) << ToString()
<< ": Ignoring identical DTLS identity";
return true;
} else {
LOG_J(LS_ERROR, this) << "Can't change DTLS local identity in this state";
RTC_LOG(LS_ERROR) << ToString()
<< ": Can't change DTLS local identity in this state";
return false;
}
}
@ -182,7 +184,8 @@ bool DtlsTransport::SetLocalCertificate(
local_certificate_ = certificate;
dtls_active_ = true;
} else {
LOG_J(LS_INFO, this) << "NULL DTLS identity supplied. Not doing DTLS";
RTC_LOG(LS_INFO) << ToString()
<< ": NULL DTLS identity supplied. Not doing DTLS";
}
return true;
@ -196,7 +199,7 @@ rtc::scoped_refptr<rtc::RTCCertificate> DtlsTransport::GetLocalCertificate()
bool DtlsTransport::SetSslMaxProtocolVersion(rtc::SSLProtocolVersion version) {
if (dtls_active_) {
RTC_LOG(LS_ERROR) << "Not changing max. protocol version "
<< "while DTLS is negotiating";
"while DTLS is negotiating";
return false;
}
@ -245,7 +248,8 @@ bool DtlsTransport::SetRemoteFingerprint(const std::string& digest_alg,
if (dtls_active_ && remote_fingerprint_value_ == remote_fingerprint_value &&
!digest_alg.empty()) {
// This may happen during renegotiation.
LOG_J(LS_INFO, this) << "Ignoring identical remote DTLS fingerprint";
RTC_LOG(LS_INFO) << ToString()
<< ": Ignoring identical remote DTLS fingerprint";
return true;
}
@ -256,7 +260,8 @@ bool DtlsTransport::SetRemoteFingerprint(const std::string& digest_alg,
// SetRemoteFingerprint shouldn't even be called though.
if (digest_alg.empty()) {
RTC_DCHECK(!digest_len);
LOG_J(LS_INFO, this) << "Other side didn't support DTLS.";
RTC_LOG(LS_INFO) << ToString()
<< ": Other side didn't support DTLS.";
dtls_active_ = false;
return true;
}
@ -264,7 +269,8 @@ bool DtlsTransport::SetRemoteFingerprint(const std::string& digest_alg,
// Otherwise, we must have a local certificate before setting remote
// fingerprint.
if (!dtls_active_) {
LOG_J(LS_ERROR, this) << "Can't set DTLS remote settings in this state.";
RTC_LOG(LS_ERROR) << ToString()
<< ": Can't set DTLS remote settings in this state.";
return false;
}
@ -282,7 +288,8 @@ bool DtlsTransport::SetRemoteFingerprint(const std::string& digest_alg,
remote_fingerprint_algorithm_,
reinterpret_cast<unsigned char*>(remote_fingerprint_value_.data()),
remote_fingerprint_value_.size(), &err)) {
LOG_J(LS_ERROR, this) << "Couldn't set DTLS certificate digest.";
RTC_LOG(LS_ERROR) << ToString()
<< ": Couldn't set DTLS certificate digest.";
set_dtls_state(DTLS_TRANSPORT_FAILED);
// If the error is "verification failed", don't return false, because
// this means the fingerprint was formatted correctly but didn't match
@ -336,7 +343,8 @@ bool DtlsTransport::SetupDtls() {
dtls_.reset(rtc::SSLStreamAdapter::Create(downward));
if (!dtls_) {
LOG_J(LS_ERROR, this) << "Failed to create DTLS adapter.";
RTC_LOG(LS_ERROR) << ToString()
<< ": Failed to create DTLS adapter.";
delete downward;
return false;
}
@ -355,21 +363,24 @@ bool DtlsTransport::SetupDtls() {
remote_fingerprint_algorithm_,
reinterpret_cast<unsigned char*>(remote_fingerprint_value_.data()),
remote_fingerprint_value_.size())) {
LOG_J(LS_ERROR, this) << "Couldn't set DTLS certificate digest.";
RTC_LOG(LS_ERROR) << ToString()
<< ": Couldn't set DTLS certificate digest.";
return false;
}
// Set up DTLS-SRTP, if it's been enabled.
if (!srtp_ciphers_.empty()) {
if (!dtls_->SetDtlsSrtpCryptoSuites(srtp_ciphers_)) {
LOG_J(LS_ERROR, this) << "Couldn't set DTLS-SRTP ciphers.";
RTC_LOG(LS_ERROR) << ToString()
<< ": Couldn't set DTLS-SRTP ciphers.";
return false;
}
} else {
LOG_J(LS_INFO, this) << "Not using DTLS-SRTP.";
RTC_LOG(LS_INFO) << ToString()
<< ": Not using DTLS-SRTP.";
}
LOG_J(LS_INFO, this) << "DTLS setup complete.";
RTC_LOG(LS_INFO) << ToString() << ": DTLS setup complete.";
// If the underlying ice_transport is already writable at this point, we may
// be able to start DTLS right away.
@ -485,8 +496,9 @@ void DtlsTransport::ConnectToIceTransport() {
void DtlsTransport::OnWritableState(rtc::PacketTransportInternal* transport) {
RTC_DCHECK(rtc::Thread::Current() == network_thread_);
RTC_DCHECK(transport == ice_transport_);
LOG_J(LS_VERBOSE, this)
<< "DTLSTransportChannelWrapper: ice_transport writable state changed to "
RTC_LOG(LS_VERBOSE)
<< ToString()
<< ": ice_transport writable state changed to "
<< ice_transport_->writable();
if (!dtls_active_) {
@ -517,9 +529,10 @@ void DtlsTransport::OnWritableState(rtc::PacketTransportInternal* transport) {
void DtlsTransport::OnReceivingState(rtc::PacketTransportInternal* transport) {
RTC_DCHECK(rtc::Thread::Current() == network_thread_);
RTC_DCHECK(transport == ice_transport_);
LOG_J(LS_VERBOSE, this) << "DTLSTransportChannelWrapper: ice_transport "
"receiving state changed to "
<< ice_transport_->receiving();
RTC_LOG(LS_VERBOSE) << ToString()
<< ": ice_transport "
"receiving state changed to "
<< ice_transport_->receiving();
if (!dtls_active_ || dtls_state() == DTLS_TRANSPORT_CONNECTED) {
// Note: SignalReceivingState fired by set_receiving.
set_receiving(ice_transport_->receiving());
@ -544,15 +557,18 @@ void DtlsTransport::OnReadPacket(rtc::PacketTransportInternal* transport,
switch (dtls_state()) {
case DTLS_TRANSPORT_NEW:
if (dtls_) {
LOG_J(LS_INFO, this) << "Packet received before DTLS started.";
RTC_LOG(LS_INFO) << ToString()
<< ": Packet received before DTLS started.";
} else {
LOG_J(LS_WARNING, this) << "Packet received before we know if we are "
<< "doing DTLS or not.";
RTC_LOG(LS_WARNING) << ToString()
<< ": Packet received before we know if we are "
"doing DTLS or not.";
}
// Cache a client hello packet received before DTLS has actually started.
if (IsDtlsClientHelloPacket(data, size)) {
LOG_J(LS_INFO, this) << "Caching DTLS ClientHello packet until DTLS is "
<< "started.";
RTC_LOG(LS_INFO) << ToString()
<< ": Caching DTLS ClientHello packet until DTLS is "
"started.";
cached_client_hello_.SetData(data, size);
// If we haven't started setting up DTLS yet (because we don't have a
// remote fingerprint/role), we can use the client hello as a clue that
@ -563,7 +579,8 @@ void DtlsTransport::OnReadPacket(rtc::PacketTransportInternal* transport,
SetupDtls();
}
} else {
LOG_J(LS_INFO, this) << "Not a DTLS ClientHello packet; dropping.";
RTC_LOG(LS_INFO) << ToString()
<< ": Not a DTLS ClientHello packet; dropping.";
}
break;
@ -573,20 +590,23 @@ void DtlsTransport::OnReadPacket(rtc::PacketTransportInternal* transport,
// Is this potentially a DTLS packet?
if (IsDtlsPacket(data, size)) {
if (!HandleDtlsPacket(data, size)) {
LOG_J(LS_ERROR, this) << "Failed to handle DTLS packet.";
RTC_LOG(LS_ERROR) << ToString()
<< ": Failed to handle DTLS packet.";
return;
}
} else {
// Not a DTLS packet; our handshake should be complete by now.
if (dtls_state() != DTLS_TRANSPORT_CONNECTED) {
LOG_J(LS_ERROR, this) << "Received non-DTLS packet before DTLS "
<< "complete.";
RTC_LOG(LS_ERROR) << ToString()
<< ": Received non-DTLS packet before DTLS "
"complete.";
return;
}
// And it had better be a SRTP packet.
if (!IsRtpPacket(data, size)) {
LOG_J(LS_ERROR, this) << "Received unexpected non-DTLS packet.";
RTC_LOG(LS_ERROR) << ToString()
<< ": Received unexpected non-DTLS packet.";
return;
}
@ -622,7 +642,8 @@ void DtlsTransport::OnDtlsEvent(rtc::StreamInterface* dtls, int sig, int err) {
RTC_DCHECK(dtls == dtls_.get());
if (sig & rtc::SE_OPEN) {
// This is the first time.
LOG_J(LS_INFO, this) << "DTLS handshake complete.";
RTC_LOG(LS_INFO) << ToString()
<< ": DTLS handshake complete.";
if (dtls_->GetState() == rtc::SS_OPEN) {
// The check for OPEN shouldn't be necessary but let's make
// sure we don't accidentally frob the state if it's closed.
@ -643,12 +664,14 @@ void DtlsTransport::OnDtlsEvent(rtc::StreamInterface* dtls, int sig, int err) {
SignalReadPacket(this, buf, read, rtc::CreatePacketTime(0), 0);
} else if (ret == rtc::SR_EOS) {
// Remote peer shut down the association with no error.
LOG_J(LS_INFO, this) << "DTLS transport closed";
RTC_LOG(LS_INFO) << ToString()
<< ": DTLS transport closed";
set_writable(false);
set_dtls_state(DTLS_TRANSPORT_CLOSED);
} else if (ret == rtc::SR_ERROR) {
// Remote peer shut down the association with an error.
LOG_J(LS_INFO, this) << "DTLS transport error, code=" << read_error;
RTC_LOG(LS_INFO) << ToString()
<< ": DTLS transport error, code=" << read_error;
set_writable(false);
set_dtls_state(DTLS_TRANSPORT_FAILED);
}
@ -658,10 +681,12 @@ void DtlsTransport::OnDtlsEvent(rtc::StreamInterface* dtls, int sig, int err) {
RTC_DCHECK(sig == rtc::SE_CLOSE); // SE_CLOSE should be by itself.
set_writable(false);
if (!err) {
LOG_J(LS_INFO, this) << "DTLS transport closed";
RTC_LOG(LS_INFO) << ToString()
<< ": DTLS transport closed";
set_dtls_state(DTLS_TRANSPORT_CLOSED);
} else {
LOG_J(LS_INFO, this) << "DTLS transport error, code=" << err;
RTC_LOG(LS_INFO) << ToString()
<< ": DTLS transport error, code=" << err;
set_dtls_state(DTLS_TRANSPORT_FAILED);
}
}
@ -684,24 +709,29 @@ void DtlsTransport::MaybeStartDtls() {
// ignore write errors, thus any errors must be because of
// configuration and therefore are our fault.
RTC_NOTREACHED() << "StartSSL failed.";
LOG_J(LS_ERROR, this) << "Couldn't start DTLS handshake";
RTC_LOG(LS_ERROR) << ToString()
<< ": Couldn't start DTLS handshake";
set_dtls_state(DTLS_TRANSPORT_FAILED);
return;
}
LOG_J(LS_INFO, this) << "DtlsTransport: Started DTLS handshake";
RTC_LOG(LS_INFO) << ToString()
<< ": DtlsTransport: Started DTLS handshake";
set_dtls_state(DTLS_TRANSPORT_CONNECTING);
// Now that the handshake has started, we can process a cached ClientHello
// (if one exists).
if (cached_client_hello_.size()) {
if (*dtls_role_ == rtc::SSL_SERVER) {
LOG_J(LS_INFO, this) << "Handling cached DTLS ClientHello packet.";
RTC_LOG(LS_INFO) << ToString()
<< ": Handling cached DTLS ClientHello packet.";
if (!HandleDtlsPacket(cached_client_hello_.data<char>(),
cached_client_hello_.size())) {
LOG_J(LS_ERROR, this) << "Failed to handle DTLS packet.";
RTC_LOG(LS_ERROR) << ToString()
<< ": Failed to handle DTLS packet.";
}
} else {
LOG_J(LS_WARNING, this) << "Discarding cached DTLS ClientHello packet "
<< "because we don't have the server role.";
RTC_LOG(LS_WARNING) << ToString()
<< ": Discarding cached DTLS ClientHello packet "
"because we don't have the server role.";
}
cached_client_hello_.Clear();
}
@ -743,8 +773,8 @@ void DtlsTransport::set_writable(bool writable) {
if (writable_ == writable) {
return;
}
LOG_J(LS_VERBOSE, this) << "set_writable from:" << writable_ << " to "
<< writable;
RTC_LOG(LS_VERBOSE) << ToString()
<< ": set_writable to: " << writable;
writable_ = writable;
if (writable_) {
SignalReadyToSend(this);
@ -756,8 +786,9 @@ void DtlsTransport::set_dtls_state(DtlsTransportState state) {
if (dtls_state_ == state) {
return;
}
LOG_J(LS_VERBOSE, this) << "set_dtls_state from:" << dtls_state_ << " to "
<< state;
RTC_LOG(LS_VERBOSE) << ToString()
<< ": set_dtls_state from:" << dtls_state_ << " to "
<< state;
dtls_state_ = state;
SignalDtlsState(this, state);
}
@ -774,13 +805,15 @@ void DtlsTransport::ConfigureHandshakeTimeout() {
// extreme values.
int initial_timeout = std::max(kMinHandshakeTimeout,
std::min(kMaxHandshakeTimeout, 2 * (*rtt)));
LOG_J(LS_INFO, this) << "configuring DTLS handshake timeout "
<< initial_timeout << " based on ICE RTT " << *rtt;
RTC_LOG(LS_INFO) << ToString()
<< ": configuring DTLS handshake timeout "
<< initial_timeout << " based on ICE RTT " << *rtt;
dtls_->SetInitialRetransmissionTimeout(initial_timeout);
} else {
LOG_J(LS_INFO, this)
<< "no RTT estimate - using default DTLS handshake timeout";
RTC_LOG(LS_INFO)
<< ToString()
<< ": no RTT estimate - using default DTLS handshake timeout";
}
}

71
p2p/base/p2ptransportchannel.cc
View File

@ -19,7 +19,6 @@
#include "api/umametrics.h"
#include "logging/rtc_event_log/icelogger.h"
#include "p2p/base/candidatepairinterface.h"
#include "p2p/base/common.h"
#include "p2p/base/relayport.h" // For RELAY_PORT_TYPE.
#include "p2p/base/stunport.h" // For STUN_PORT_TYPE.
#include "rtc_base/checks.h"
@ -362,9 +361,10 @@ IceTransportState P2PTransportChannel::ComputeState() const {
if (networks.find(network) == networks.end()) {
networks.insert(network);
} else {
LOG_J(LS_VERBOSE, this) << "Ice not completed yet for this channel as "
<< network->ToString()
<< " has more than 1 connection.";
RTC_LOG(LS_VERBOSE) << ToString()
<< ": Ice not completed yet for this channel as "
<< network->ToString()
<< " has more than 1 connection.";
return IceTransportState::STATE_CONNECTING;
}
}
@ -426,7 +426,7 @@ void P2PTransportChannel::SetIceConfig(const IceConfig& config) {
if (config_.continual_gathering_policy != config.continual_gathering_policy) {
if (!allocator_sessions_.empty()) {
RTC_LOG(LS_ERROR) << "Trying to change continual gathering policy "
<< "when gathering has already started!";
"when gathering has already started!";
} else {
config_.continual_gathering_policy = config.continual_gathering_policy;
RTC_LOG(LS_INFO) << "Set continual_gathering_policy to "
@ -470,7 +470,7 @@ void P2PTransportChannel::SetIceConfig(const IceConfig& config) {
config.presume_writable_when_fully_relayed) {
if (!connections_.empty()) {
RTC_LOG(LS_ERROR) << "Trying to change 'presume writable' "
<< "while connections already exist!";
"while connections already exist!";
} else {
config_.presume_writable_when_fully_relayed =
config.presume_writable_when_fully_relayed;
@ -645,7 +645,7 @@ void P2PTransportChannel::MaybeStartGathering() {
if (ice_parameters_.ufrag.empty() || ice_parameters_.pwd.empty()) {
RTC_LOG(LS_ERROR)
<< "Cannot gather candidates because ICE parameters are empty"
<< " ufrag: " << ice_parameters_.ufrag
" ufrag: " << ice_parameters_.ufrag
<< " pwd: " << ice_parameters_.pwd;
return;
}
@ -711,9 +711,9 @@ void P2PTransportChannel::OnPortReady(PortAllocatorSession *session,
++it) {
int val = port->SetOption(it->first, it->second);
if (val < 0) {
LOG_J(LS_WARNING, port) << "SetOption(" << it->first
<< ", " << it->second
<< ") failed: " << port->GetError();
RTC_LOG(LS_WARNING) << port->ToString() << ": SetOption("
<< it->first << ", " << it->second
<< ") failed: " << port->GetError();
}
}
@ -761,7 +761,7 @@ void P2PTransportChannel::OnCandidatesAllocationDone(
RTC_LOG(LS_INFO) << "P2PTransportChannel: " << transport_name()
<< ", component " << component()
<< " gathering complete, but using continual "
<< "gathering so not changing gathering state.";
"gathering so not changing gathering state.";
return;
}
gathering_state_ = kIceGatheringComplete;
@ -815,8 +815,8 @@ void P2PTransportChannel::OnUnknownAddress(
stun_msg->GetUInt32(STUN_ATTR_PRIORITY);
if (!priority_attr) {
RTC_LOG(LS_WARNING) << "P2PTransportChannel::OnUnknownAddress - "
<< "No STUN_ATTR_PRIORITY found in the "
<< "stun request message";
"No STUN_ATTR_PRIORITY found in the "
"stun request message";
port->SendBindingErrorResponse(stun_msg, address, STUN_ERROR_BAD_REQUEST,
STUN_ERROR_REASON_BAD_REQUEST);
return;
@ -861,7 +861,7 @@ void P2PTransportChannel::OnUnknownAddress(
if (port->GetConnection(remote_candidate.address())) {
if (port_muxed) {
RTC_LOG(LS_INFO) << "Connection already exists for peer reflexive "
<< "candidate: " << remote_candidate.ToString();
"candidate: " << remote_candidate.ToString();
return;
} else {
RTC_NOTREACHED();
@ -1069,8 +1069,9 @@ bool P2PTransportChannel::CreateConnection(PortInterface* port,
return false;
}
AddConnection(connection);
LOG_J(LS_INFO, this) << "Created connection with origin=" << origin << ", ("
<< connections_.size() << " total)";
RTC_LOG(LS_INFO) << ToString()
<< ": Created connection with origin: " << origin
<< ", total: " << connections_.size();
return true;
}
@ -1079,7 +1080,7 @@ bool P2PTransportChannel::CreateConnection(PortInterface* port,
// connection; however, the other side can send a duplicate candidate.
if (!remote_candidate.IsEquivalent(connection->remote_candidate())) {
RTC_LOG(INFO) << "Attempt to change a remote candidate."
<< " Existing remote candidate: "
" Existing remote candidate: "
<< connection->remote_candidate().ToString()
<< "New remote candidate: " << remote_candidate.ToString();
}
@ -1275,8 +1276,9 @@ void P2PTransportChannel::MaybeStartPinging() {
if (std::any_of(
connections_.begin(), connections_.end(),
[this, now](const Connection* c) { return IsPingable(c, now); })) {
LOG_J(LS_INFO, this) << "Have a pingable connection for the first time; "
<< "starting to ping.";
RTC_LOG(LS_INFO) << ToString()
<< ": Have a pingable connection for the first time; "
"starting to ping.";
thread()->Post(RTC_FROM_HERE, this, MSG_CHECK_AND_PING);
thread()->PostDelayed(
RTC_FROM_HERE,
@ -1521,7 +1523,7 @@ void P2PTransportChannel::SortConnectionsAndUpdateState() {
});
RTC_LOG(LS_VERBOSE) << "Sorting " << connections_.size()
<< " available connections:";
<< " available connections";
for (size_t i = 0; i < connections_.size(); ++i) {
RTC_LOG(LS_VERBOSE) << connections_[i]->ToString();
}
@ -1648,11 +1650,13 @@ void P2PTransportChannel::SwitchSelectedConnection(Connection* conn) {
if (selected_connection_) {
++nomination_;
if (old_selected_connection) {
LOG_J(LS_INFO, this) << "Previous selected connection: "
<< old_selected_connection->ToString();
RTC_LOG(LS_INFO) << ToString()
<< ": Previous selected connection: "
<< old_selected_connection->ToString();
}
LOG_J(LS_INFO, this) << "New selected connection: "
<< selected_connection_->ToString();
RTC_LOG(LS_INFO) << ToString()
<< ": New selected connection: "
<< selected_connection_->ToString();
SignalRouteChange(this, selected_connection_->remote_candidate());
// This is a temporary, but safe fix to webrtc issue 5705.
// TODO(honghaiz): Make all ENOTCONN error routed through the transport
@ -1676,7 +1680,8 @@ void P2PTransportChannel::SwitchSelectedConnection(Connection* conn) {
selected_connection_->local_candidate().address().family()) +
GetProtocolOverhead(selected_connection_->local_candidate().protocol());
} else {
LOG_J(LS_INFO, this) << "No selected connection";
RTC_LOG(LS_INFO) << ToString()
<< ": No selected connection";
}
SignalNetworkRouteChanged(network_route_);
@ -1691,9 +1696,10 @@ void P2PTransportChannel::SwitchSelectedConnection(Connection* conn) {
void P2PTransportChannel::UpdateState() {
IceTransportState state = ComputeState();
if (state_ != state) {
LOG_J(LS_INFO, this) << "Transport channel state changed from "
<< static_cast<int>(state_) << " to "
<< static_cast<int>(state);
RTC_LOG(LS_INFO) << ToString()
<< ": Transport channel state changed from "
<< static_cast<int>(state_) << " to "
<< static_cast<int>(state);
// Check that the requested transition is allowed. Note that
// P2PTransportChannel does not (yet) implement a direct mapping of the ICE
// states from the standard; the difference is covered by
@ -2115,9 +2121,9 @@ void P2PTransportChannel::OnConnectionDestroyed(Connection* connection) {
unpinged_connections_.erase(*iter);
connections_.erase(iter);
LOG_J(LS_INFO, this) << "Removed connection " << std::hex << connection
<< std::dec << " (" << connections_.size()
<< " remaining)";
RTC_LOG(LS_INFO) << ToString() << ": Removed connection "
<< std::hex << connection << std::dec << " ("
<< connections_.size() << " remaining)";
// If this is currently the selected connection, then we need to pick a new
// one. The call to SortConnectionsAndUpdateState will pick a new one. It
@ -2340,7 +2346,8 @@ void P2PTransportChannel::set_writable(bool writable) {
if (writable_ == writable) {
return;
}
LOG_J(LS_VERBOSE, this) << "Changed writable_ to " << writable;
RTC_LOG(LS_VERBOSE) << ToString()
<< ": Changed writable_ to " << writable;
writable_ = writable;
if (writable_) {
SignalReadyToSend(this);

8
p2p/base/p2ptransportchannel_unittest.cc
View File

@ -560,8 +560,8 @@ class P2PTransportChannelTestBase : public testing::Test,
if (connect_time < expected.connect_wait) {
RTC_LOG(LS_INFO) << "Connect time: " << connect_time << " ms";
} else {
RTC_LOG(LS_INFO) << "Connect time: "
<< "TIMEOUT (" << expected.connect_wait << " ms)";
RTC_LOG(LS_INFO) << "Connect time: TIMEOUT ("
<< expected.connect_wait << " ms)";
}
// Allow a few turns of the crank for the selected connections to emerge.
@ -585,8 +585,8 @@ class P2PTransportChannelTestBase : public testing::Test,
if (converge_time < converge_wait) {
RTC_LOG(LS_INFO) << "Converge time: " << converge_time << " ms";
} else {
RTC_LOG(LS_INFO) << "Converge time: "
<< "TIMEOUT (" << converge_wait << " ms)";
RTC_LOG(LS_INFO) << "Converge time: TIMEOUT ("
<< converge_wait << " ms)";
}
}
// Try sending some data to other end.

243
p2p/base/port.cc
View File

@ -16,7 +16,6 @@
#include <utility>
#include <vector>
#include "p2p/base/common.h"
#include "p2p/base/portallocator.h"
#include "rtc_base/base64.h"
#include "rtc_base/checks.h"
@ -310,7 +309,8 @@ void Port::Construct() {
thread_->PostDelayed(RTC_FROM_HERE, timeout_delay_, this,
MSG_DESTROY_IF_DEAD);
LOG_J(LS_INFO, this) << "Port created with network cost " << network_cost_;
RTC_LOG(LS_INFO) << ToString()
<< ": Port created with network cost " << network_cost_;
}
Port::~Port() {
@ -435,9 +435,11 @@ void Port::AddOrReplaceConnection(Connection* conn) {
// If there is a different connection on the same remote address, replace
// it with the new one and destroy the old one.
if (ret.second == false && ret.first->second != conn) {
LOG_J(LS_WARNING, this)
<< "A new connection was created on an existing remote address. "
<< "New remote candidate: " << conn->remote_candidate().ToString();
RTC_LOG(LS_WARNING)
<< ToString()
<< ": A new connection was created on an existing remote address. "
"New remote candidate: "
<< conn->remote_candidate().ToString();
ret.first->second->SignalDestroyed.disconnect(this);
ret.first->second->Destroy();
ret.first->second = conn;
@ -460,13 +462,14 @@ void Port::OnReadPacket(
std::unique_ptr<IceMessage> msg;
std::string remote_username;
if (!GetStunMessage(data, size, addr, &msg, &remote_username)) {
LOG_J(LS_ERROR, this) << "Received non-STUN packet from unknown address ("
<< addr.ToSensitiveString() << ")";
RTC_LOG(LS_ERROR) << ToString()
<< ": Received non-STUN packet from unknown address: "
<< addr.ToSensitiveString();
} else if (!msg) {
// STUN message handled already
} else if (msg->type() == STUN_BINDING_REQUEST) {
RTC_LOG(LS_INFO) << "Received STUN ping "
<< " id=" << rtc::hex_encode(msg->transaction_id())
RTC_LOG(LS_INFO) << "Received STUN ping id="
<< rtc::hex_encode(msg->transaction_id())
<< " from unknown address " << addr.ToSensitiveString();
// We need to signal an unknown address before we handle any role conflict
// below. Otherwise there would be no candidate pair and TURN entry created
@ -483,9 +486,10 @@ void Port::OnReadPacket(
// because we then get back responses for them, which this code correctly
// does not handle.
if (msg->type() != STUN_BINDING_RESPONSE) {
LOG_J(LS_ERROR, this) << "Received unexpected STUN message type ("
<< msg->type() << ") from unknown address ("
<< addr.ToSensitiveString() << ")";
RTC_LOG(LS_ERROR) << ToString()
<< ": Received unexpected STUN message type: "
<< msg->type() << " from unknown address: "
<< addr.ToSensitiveString();
}
}
}
@ -533,8 +537,9 @@ bool Port::GetStunMessage(const char* data,
// If not present, fail with a 400 Bad Request.
if (!stun_msg->GetByteString(STUN_ATTR_USERNAME) ||
!stun_msg->GetByteString(STUN_ATTR_MESSAGE_INTEGRITY)) {
LOG_J(LS_ERROR, this) << "Received STUN request without username/M-I "
<< "from " << addr.ToSensitiveString();
RTC_LOG(LS_ERROR) << ToString()
<< ": Received STUN request without username/M-I from: "
<< addr.ToSensitiveString();
SendBindingErrorResponse(stun_msg.get(), addr, STUN_ERROR_BAD_REQUEST,
STUN_ERROR_REASON_BAD_REQUEST);
return true;
@ -545,9 +550,9 @@ bool Port::GetStunMessage(const char* data,
std::string remote_ufrag;
if (!ParseStunUsername(stun_msg.get(), &local_ufrag, &remote_ufrag) ||
local_ufrag != username_fragment()) {
LOG_J(LS_ERROR, this) << "Received STUN request with bad local username "
<< local_ufrag << " from "
<< addr.ToSensitiveString();
RTC_LOG(LS_ERROR) << ToString()
<< ": Received STUN request with bad local username "
<< local_ufrag << " from " << addr.ToSensitiveString();
SendBindingErrorResponse(stun_msg.get(), addr, STUN_ERROR_UNAUTHORIZED,
STUN_ERROR_REASON_UNAUTHORIZED);
return true;
@ -555,9 +560,10 @@ bool Port::GetStunMessage(const char* data,
// If ICE, and the MESSAGE-INTEGRITY is bad, fail with a 401 Unauthorized
if (!stun_msg->ValidateMessageIntegrity(data, size, password_)) {
LOG_J(LS_ERROR, this) << "Received STUN request with bad M-I "
<< "from " << addr.ToSensitiveString()
<< ", password_=" << password_;
RTC_LOG(LS_ERROR) << ToString()
<< ": Received STUN request with bad M-I from "
<< addr.ToSensitiveString()
<< ", password_=" << password_;
SendBindingErrorResponse(stun_msg.get(), addr, STUN_ERROR_UNAUTHORIZED,
STUN_ERROR_REASON_UNAUTHORIZED);
return true;
@ -567,30 +573,35 @@ bool Port::GetStunMessage(const char* data,
(stun_msg->type() == STUN_BINDING_ERROR_RESPONSE)) {
if (stun_msg->type() == STUN_BINDING_ERROR_RESPONSE) {
if (const StunErrorCodeAttribute* error_code = stun_msg->GetErrorCode()) {
LOG_J(LS_ERROR, this) << "Received STUN binding error:"
<< " class=" << error_code->eclass()
<< " number=" << error_code->number()
<< " reason='" << error_code->reason() << "'"
<< " from " << addr.ToSensitiveString();
RTC_LOG(LS_ERROR) << ToString()
<< ": Received STUN binding error: class="
<< error_code->eclass()
<< " number=" << error_code->number() << " reason='"
<< error_code->reason() << "' from "
<< addr.ToSensitiveString();
// Return message to allow error-specific processing
} else {
LOG_J(LS_ERROR, this) << "Received STUN binding error without a error "
<< "code from " << addr.ToSensitiveString();
RTC_LOG(LS_ERROR)
<< ToString()
<< ": Received STUN binding error without a error code from "
<< addr.ToSensitiveString();
return true;
}
}
// NOTE: Username should not be used in verifying response messages.
out_username->clear();
} else if (stun_msg->type() == STUN_BINDING_INDICATION) {
LOG_J(LS_VERBOSE, this) << "Received STUN binding indication:"
<< " from " << addr.ToSensitiveString();
RTC_LOG(LS_VERBOSE) << ToString()
<< ": Received STUN binding indication: from "
<< addr.ToSensitiveString();
out_username->clear();
// No stun attributes will be verified, if it's stun indication message.
// Returning from end of the this method.
} else {
LOG_J(LS_ERROR, this) << "Received STUN packet with invalid type ("
<< stun_msg->type() << ") from "
<< addr.ToSensitiveString();
RTC_LOG(LS_ERROR) << ToString()
<< ": Received STUN packet with invalid type ("
<< stun_msg->type() << ") from "
<< addr.ToSensitiveString();
return true;
}
@ -747,8 +758,9 @@ void Port::SendBindingResponse(StunMessage* request,
STUN_ATTR_RETRANSMIT_COUNT, retransmit_attr->value()));
if (retransmit_attr->value() > CONNECTION_WRITE_CONNECT_FAILURES) {
LOG_J(LS_INFO, this)
<< "Received a remote ping with high retransmit count: "
RTC_LOG(LS_INFO)
<< ToString()
<< ": Received a remote ping with high retransmit count: "
<< retransmit_attr->value();
}
}
@ -764,21 +776,20 @@ void Port::SendBindingResponse(StunMessage* request,
rtc::PacketOptions options(DefaultDscpValue());
auto err = SendTo(buf.Data(), buf.Length(), addr, options, false);
if (err < 0) {
LOG_J(LS_ERROR, this)
<< "Failed to send STUN ping response"
<< ", to=" << addr.ToSensitiveString()
<< ", err=" << err
<< ", id=" << rtc::hex_encode(response.transaction_id());
RTC_LOG(LS_ERROR) << ToString()
<< ": Failed to send STUN ping response, to="
<< addr.ToSensitiveString() << ", err=" << err
<< ", id=" << rtc::hex_encode(response.transaction_id());
} else {
// Log at LS_INFO if we send a stun ping response on an unwritable
// connection.
Connection* conn = GetConnection(addr);
rtc::LoggingSeverity sev = (conn && !conn->writable()) ?
rtc::LS_INFO : rtc::LS_VERBOSE;
LOG_JV(sev, this)
<< "Sent STUN ping response"
<< ", to=" << addr.ToSensitiveString()
<< ", id=" << rtc::hex_encode(response.transaction_id());
RTC_LOG_V(sev) << ToString()
<< ": Sent STUN ping response, to="
<< addr.ToSensitiveString()
<< ", id=" << rtc::hex_encode(response.transaction_id());
conn->stats_.sent_ping_responses++;
conn->LogCandidatePairEvent(
@ -815,8 +826,9 @@ void Port::SendBindingErrorResponse(StunMessage* request,
response.Write(&buf);
rtc::PacketOptions options(DefaultDscpValue());
SendTo(buf.Data(), buf.Length(), addr, options, false);
LOG_J(LS_INFO, this) << "Sending STUN binding error: reason=" << reason
<< " to " << addr.ToSensitiveString();
RTC_LOG(LS_INFO) << ToString()
<< ": Sending STUN binding error: reason=" << reason
<< " to " << addr.ToSensitiveString();
}
void Port::KeepAliveUntilPruned() {
@ -905,7 +917,7 @@ void Port::OnConnectionDestroyed(Connection* conn) {
void Port::Destroy() {
RTC_DCHECK(connections_.empty());
LOG_J(LS_INFO, this) << "Port deleted";
RTC_LOG(LS_INFO) << ToString() << ": Port deleted";
SignalDestroyed(this);
delete this;
}
@ -1046,7 +1058,7 @@ Connection::Connection(Port* port,
// Wire up to send stun packets
requests_.SignalSendPacket.connect(this, &Connection::OnSendStunPacket);
hash_ = static_cast<uint32_t>(std::hash<std::string>{}(ToString()));
LOG_J(LS_INFO, this) << "Connection created";
RTC_LOG(LS_INFO) << ToString() << ": Connection created";
}
Connection::~Connection() {
@ -1090,8 +1102,9 @@ void Connection::set_write_state(WriteState value) {
WriteState old_value = write_state_;
write_state_ = value;
if (value != old_value) {
LOG_J(LS_VERBOSE, this) << "set_write_state from: " << old_value << " to "
<< value;
RTC_LOG(LS_VERBOSE) << ToString()
<< ": set_write_state from: " << old_value << " to "
<< value;
SignalStateChange(this);
}
}
@ -1102,7 +1115,8 @@ void Connection::UpdateReceiving(int64_t now) {
if (receiving_ == receiving) {
return;
}
LOG_J(LS_VERBOSE, this) << "set_receiving to " << receiving;
RTC_LOG(LS_VERBOSE) << ToString() << ": set_receiving to "
<< receiving;
receiving_ = receiving;
receiving_unchanged_since_ = now;
SignalStateChange(this);
@ -1112,7 +1126,7 @@ void Connection::set_state(IceCandidatePairState state) {
IceCandidatePairState old_state = state_;
state_ = state;
if (state != old_state) {
LOG_J(LS_VERBOSE, this) << "set_state";
RTC_LOG(LS_VERBOSE) << ToString() << ": set_state";
}
}
@ -1120,7 +1134,8 @@ void Connection::set_connected(bool value) {
bool old_value = connected_;
connected_ = value;
if (value != old_value) {
LOG_J(LS_VERBOSE, this) << "Change connected_ to " << value;
RTC_LOG(LS_VERBOSE) << ToString()
<< ": Change connected_ to " << value;
SignalStateChange(this);
}
}
@ -1147,9 +1162,10 @@ void Connection::OnSendStunPacket(const void* data, size_t size,
auto err = port_->SendTo(
data, size, remote_candidate_.address(), options, false);
if (err < 0) {
LOG_J(LS_WARNING, this) << "Failed to send STUN ping "
<< " err=" << err
<< " id=" << rtc::hex_encode(req->id());
RTC_LOG(LS_WARNING) << ToString()
<< ": Failed to send STUN ping "
" err="
<< err << " id=" << rtc::hex_encode(req->id());
}
}
@ -1170,7 +1186,7 @@ void Connection::OnReadPacket(
if (!pruned_ && (write_state_ == STATE_WRITE_TIMEOUT)) {
RTC_LOG(LS_WARNING)
<< "Received a data packet on a timed-out Connection. "
<< "Resetting state to STATE_WRITE_INIT.";
"Resetting state to STATE_WRITE_INIT.";
set_write_state(STATE_WRITE_INIT);
}
} else if (!msg) {
@ -1184,17 +1200,19 @@ void Connection::OnReadPacket(
rtc::LoggingSeverity sev = (!writable() ? rtc::LS_INFO : rtc::LS_VERBOSE);
switch (msg->type()) {
case STUN_BINDING_REQUEST:
LOG_JV(sev, this) << "Received STUN ping"
<< ", id=" << rtc::hex_encode(msg->transaction_id());
RTC_LOG_V(sev) << ToString()
<< ": Received STUN ping, id="
<< rtc::hex_encode(msg->transaction_id());
if (remote_ufrag == remote_candidate_.username()) {
HandleBindingRequest(msg.get());
} else {
// The packet had the right local username, but the remote username
// was not the right one for the remote address.
LOG_J(LS_ERROR, this)
<< "Received STUN request with bad remote username "
<< remote_ufrag;
RTC_LOG(LS_ERROR)
<< ToString()
<< ": Received STUN request with bad remote username "
<< remote_ufrag;
port_->SendBindingErrorResponse(msg.get(), addr,
STUN_ERROR_UNAUTHORIZED,
STUN_ERROR_REASON_UNAUTHORIZED);
@ -1296,7 +1314,7 @@ void Connection::OnReadyToSend() {
void Connection::Prune() {
if (!pruned_ || active()) {
LOG_J(LS_INFO, this) << "Connection pruned";
RTC_LOG(LS_INFO) << ToString() << ": Connection pruned";
pruned_ = true;
requests_.Clear();
set_write_state(STATE_WRITE_TIMEOUT);
@ -1309,7 +1327,8 @@ void Connection::Destroy() {
// with the networking thread on which this message is posted). Also affects
// tests, with a workaround in
// AutoSocketServerThread::~AutoSocketServerThread.
LOG_J(LS_VERBOSE, this) << "Connection destroyed";
RTC_LOG(LS_VERBOSE) << ToString()
<< ": Connection destroyed";
port_->thread()->Post(RTC_FROM_HERE, this, MSG_DELETE);
LogCandidatePairEvent(webrtc::IceCandidatePairEventType::kDestroyed);
}
@ -1347,13 +1366,13 @@ void Connection::UpdateState(int64_t now) {
if (RTC_LOG_CHECK_LEVEL(LS_VERBOSE)) {
std::string pings;
PrintPingsSinceLastResponse(&pings, 5);
LOG_J(LS_VERBOSE, this) << "UpdateState()"
<< ", ms since last received response="
<< now - last_ping_response_received_
<< ", ms since last received data="
<< now - last_data_received_
<< ", rtt=" << rtt
<< ", pings_since_last_response=" << pings;
RTC_LOG(LS_VERBOSE) << ToString()
<< ": UpdateState()"
", ms since last received response="
<< now - last_ping_response_received_
<< ", ms since last received data="
<< now - last_data_received_ << ", rtt=" << rtt
<< ", pings_since_last_response=" << pings;
}
// Check the writable state. (The order of these checks is important.)
@ -1371,15 +1390,14 @@ void Connection::UpdateState(int64_t now) {
TooLongWithoutResponse(pings_since_last_response_, unwritable_timeout(),
now)) {
uint32_t max_pings = unwritable_min_checks();
LOG_J(LS_INFO, this) << "Unwritable after " << max_pings
<< " ping failures and "
<< now - pings_since_last_response_[0].sent_time
<< " ms without a response,"
<< " ms since last received ping="
<< now - last_ping_received_
<< " ms since last received data="
<< now - last_data_received_
<< " rtt=" << rtt;
RTC_LOG(LS_INFO) << ToString() << ": Unwritable after "
<< max_pings << " ping failures and "
<< now - pings_since_last_response_[0].sent_time
<< " ms without a response,"
" ms since last received ping="
<< now - last_ping_received_
<< " ms since last received data="
<< now - last_data_received_ << " rtt=" << rtt;
set_write_state(STATE_WRITE_UNRELIABLE);
}
if ((write_state_ == STATE_WRITE_UNRELIABLE ||
@ -1387,10 +1405,9 @@ void Connection::UpdateState(int64_t now) {
TooLongWithoutResponse(pings_since_last_response_,
CONNECTION_WRITE_TIMEOUT,
now)) {
LOG_J(LS_INFO, this) << "Timed out after "
<< now - pings_since_last_response_[0].sent_time
<< " ms without a response"
<< ", rtt=" << rtt;
RTC_LOG(LS_INFO) << ToString() << ": Timed out after "
<< now - pings_since_last_response_[0].sent_time
<< " ms without a response, rtt=" << rtt;
set_write_state(STATE_WRITE_TIMEOUT);
}
@ -1413,9 +1430,10 @@ void Connection::Ping(int64_t now) {
}
pings_since_last_response_.push_back(SentPing(req->id(), now, nomination));
packet_loss_estimator_.ExpectResponse(req->id(), now);
LOG_J(LS_VERBOSE, this) << "Sending STUN ping "
<< ", id=" << rtc::hex_encode(req->id())
<< ", nomination=" << nomination_;
RTC_LOG(LS_VERBOSE) << ToString()
<< ": Sending STUN ping, id="
<< rtc::hex_encode(req->id())
<< ", nomination=" << nomination_;
requests_.Send(req);
state_ = IceCandidatePairState::IN_PROGRESS;
num_pings_sent_++;
@ -1589,11 +1607,12 @@ void Connection::OnConnectionRequestResponse(ConnectionRequest* request,
if (RTC_LOG_CHECK_LEVEL_V(sev)) {
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;
RTC_LOG_V(sev) << ToString()
<< ": Received STUN ping response, id="
<< rtc::hex_encode(request->id())
<< ", code=0" // Makes logging easier to parse.
", rtt="
<< rtt << ", pings_since_last_response=" << pings;
}
ReceivedPingResponse(rtt, request->id());
@ -1610,10 +1629,11 @@ void Connection::OnConnectionRequestResponse(ConnectionRequest* request,
void Connection::OnConnectionRequestErrorResponse(ConnectionRequest* request,
StunMessage* response) {
int error_code = response->GetErrorCodeValue();
LOG_J(LS_WARNING, this) << "Received STUN error response"
<< " id=" << rtc::hex_encode(request->id())
<< " code=" << error_code
<< " rtt=" << request->Elapsed();
RTC_LOG(LS_WARNING) << ToString()
<< ": Received STUN error response id="
<< rtc::hex_encode(request->id())
<< " code=" << error_code
<< " rtt=" << request->Elapsed();
if (error_code == STUN_ERROR_UNKNOWN_ATTRIBUTE ||
error_code == STUN_ERROR_SERVER_ERROR ||
@ -1625,8 +1645,9 @@ void Connection::OnConnectionRequestErrorResponse(ConnectionRequest* request,
HandleRoleConflictFromPeer();
} else {
// This is not a valid connection.
LOG_J(LS_ERROR, this) << "Received STUN error response, code="
<< error_code << "; killing connection";
RTC_LOG(LS_ERROR) << ToString()
<< ": Received STUN error response, code=" << error_code
<< "; killing connection";
FailAndDestroy();
}
}
@ -1634,18 +1655,18 @@ void Connection::OnConnectionRequestErrorResponse(ConnectionRequest* request,
void Connection::OnConnectionRequestTimeout(ConnectionRequest* request) {
// Log at LS_INFO if we miss a ping on a writable connection.
rtc::LoggingSeverity sev = writable() ? rtc::LS_INFO : rtc::LS_VERBOSE;
LOG_JV(sev, this) << "Timing-out STUN ping "
<< rtc::hex_encode(request->id())
<< " after " << request->Elapsed() << " ms";
RTC_LOG_V(sev) << ToString() << ": Timing-out STUN ping "
<< rtc::hex_encode(request->id()) << " after "
<< request->Elapsed() << " ms";
}
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;
LOG_JV(sev, this) << "Sent STUN ping"
<< ", id=" << rtc::hex_encode(request->id())
<< ", use_candidate=" << use_candidate_attr()
<< ", nomination=" << nomination();
RTC_LOG_V(sev) << ToString()
<< ": Sent STUN ping, id=" << rtc::hex_encode(request->id())
<< ", use_candidate=" << use_candidate_attr()
<< ", nomination=" << nomination();
stats_.sent_ping_requests_total++;
LogCandidatePairEvent(webrtc::IceCandidatePairEventType::kCheckSent);
if (stats_.recv_ping_responses == 0) {
@ -1733,15 +1754,16 @@ void Connection::MaybeUpdateLocalCandidate(ConnectionRequest* request,
if (!addr) {
RTC_LOG(LS_WARNING)
<< "Connection::OnConnectionRequestResponse - "
<< "No MAPPED-ADDRESS or XOR-MAPPED-ADDRESS found in the "
<< "stun response message";
"No MAPPED-ADDRESS or XOR-MAPPED-ADDRESS found in the "
"stun response message";
return;
}
for (size_t i = 0; i < port_->Candidates().size(); ++i) {
if (port_->Candidates()[i].address() == addr->GetAddress()) {
if (local_candidate_index_ != i) {
LOG_J(LS_INFO, this) << "Updating local candidate type to srflx.";
RTC_LOG(LS_INFO) << ToString()
<< ": Updating local candidate type to srflx.";
local_candidate_index_ = i;
// SignalStateChange to force a re-sort in P2PTransportChannel as this
// Connection's local candidate has changed.
@ -1758,8 +1780,8 @@ void Connection::MaybeUpdateLocalCandidate(ConnectionRequest* request,
request->msg()->GetUInt32(STUN_ATTR_PRIORITY);
if (!priority_attr) {
RTC_LOG(LS_WARNING) << "Connection::OnConnectionRequestResponse - "
<< "No STUN_ATTR_PRIORITY found in the "
<< "stun response message";
"No STUN_ATTR_PRIORITY found in the "
"stun response message";
return;
}
const uint32_t priority = priority_attr->value();
@ -1785,7 +1807,8 @@ void Connection::MaybeUpdateLocalCandidate(ConnectionRequest* request,
new_local_candidate.set_network_cost(local_candidate().network_cost());
// Change the local candidate of this Connection to the new prflx candidate.
LOG_J(LS_INFO, this) << "Updating local candidate type to prflx.";
RTC_LOG(LS_INFO) << ToString()
<< ": Updating local candidate type to prflx.";
local_candidate_index_ = port_->AddPrflxCandidate(new_local_candidate);
// SignalStateChange to force a re-sort in P2PTransportChannel as this

3
p2p/base/portallocator.cc
View File

@ -127,8 +127,7 @@ bool PortAllocator::SetConfiguration(
if (candidate_pool_frozen_) {
if (candidate_pool_size != candidate_pool_size_) {
RTC_LOG(LS_ERROR)
<< "Trying to change candidate pool size after pool was "
<< "frozen.";
<< "Trying to change candidate pool size after pool was frozen.";
return false;
}
return true;

4
p2p/base/pseudotcp_unittest.cc
View File

@ -554,8 +554,8 @@ class PseudoTcpTestReceiveWindow : public PseudoTcpTestBase {
} else {
if (!remote_.isReceiveBufferFull()) {
RTC_LOG(LS_ERROR) << "This shouldn't happen - the send buffer is full, "
<< "the receive buffer is not, and there are no "
<< "remaining messages to process.";
"the receive buffer is not, and there are no "
"remaining messages to process.";
}
send_stream_.GetPosition(&position);
send_position_.push_back(position);

7
p2p/base/relayport.cc
View File

@ -508,7 +508,7 @@ void RelayEntry::Connect() {
rtc::SocketAddress(port_->Network()->GetBestIP(), 0), ra->address,
port_->proxy(), port_->user_agent(), opts);
} else {
RTC_LOG(LS_WARNING) << "Unknown protocol (" << ra->proto << ")";
RTC_LOG(LS_WARNING) << "Unknown protocol: " << ra->proto;
}
// If we failed to get a socket, move on to the next protocol.
@ -832,9 +832,8 @@ void AllocateRequest::OnErrorResponse(StunMessage* response) {
if (!attr) {
RTC_LOG(LS_ERROR) << "Missing allocate response error code.";
} else {
RTC_LOG(INFO) << "Allocate error response:"
<< " code=" << attr->code() << " reason='" << attr->reason()
<< "'";
RTC_LOG(INFO) << "Allocate error response: code=" << attr->code()
<< " reason=" << attr->reason();
}
if (rtc::TimeMillis() - start_time_ <= kRetryTimeout)

2
p2p/base/stun.cc
View File

@ -268,7 +268,7 @@ bool StunMessage::AddMessageIntegrity(const char* key,
RTC_DCHECK(ret == sizeof(hmac));
if (ret != sizeof(hmac)) {
RTC_LOG(LS_ERROR) << "HMAC computation failed. Message-Integrity "
<< "has dummy value.";
"has dummy value.";
return false;
}

24
p2p/base/stunport.cc
View File

@ -13,7 +13,6 @@
#include <utility>
#include <vector>
#include "p2p/base/common.h"
#include "p2p/base/p2pconstants.h"
#include "p2p/base/portallocator.h"
#include "p2p/base/stun.h"
@ -69,9 +68,9 @@ class StunBindingRequest : public StunRequest {
RTC_LOG(LS_ERROR) << "Missing binding response error code.";
} else {
RTC_LOG(LS_ERROR) << "Binding error response:"
<< " class=" << attr->eclass()
<< " number=" << attr->number() << " reason='"
<< attr->reason() << "'";
" class=" << attr->eclass()
<< " number=" << attr->number() << " reason="
<< attr->reason();
}
port_->OnStunBindingOrResolveRequestFailed(server_addr_);
@ -209,7 +208,8 @@ bool UDPPort::Init() {
socket_ = socket_factory()->CreateUdpSocket(
rtc::SocketAddress(Network()->GetBestIP(), 0), min_port(), max_port());
if (!socket_) {
LOG_J(LS_WARNING, this) << "UDP socket creation failed";
RTC_LOG(LS_WARNING) << ToString()
<< ": UDP socket creation failed";
return false;
}
socket_->SignalReadPacket.connect(this, &UDPPort::OnReadPacket);
@ -271,8 +271,8 @@ int UDPPort::SendTo(const void* data, size_t size,
int sent = socket_->SendTo(data, size, addr, options);
if (sent < 0) {
error_ = socket_->GetError();
LOG_J(LS_ERROR, this) << "UDP send of " << size
<< " bytes failed with error " << error_;
RTC_LOG(LS_ERROR) << ToString() << ": UDP send of "
<< size << " bytes failed with error " << error_;
}
return sent;
}
@ -387,8 +387,9 @@ void UDPPort::ResolveStunAddress(const rtc::SocketAddress& stun_addr) {
resolver_->SignalDone.connect(this, &UDPPort::OnResolveResult);
}
LOG_J(LS_INFO, this) << "Starting STUN host lookup for "
<< stun_addr.ToSensitiveString();
RTC_LOG(LS_INFO) << ToString()
<< ": Starting STUN host lookup for "
<< stun_addr.ToSensitiveString();
resolver_->Resolve(stun_addr);
}
@ -399,8 +400,9 @@ void UDPPort::OnResolveResult(const rtc::SocketAddress& input,
rtc::SocketAddress resolved;
if (error != 0 || !resolver_->GetResolvedAddress(
input, Network()->GetBestIP().family(), &resolved)) {
LOG_J(LS_WARNING, this) << "StunPort: stun host lookup received error "
<< error;
RTC_LOG(LS_WARNING) << ToString()
<< ": StunPort: stun host lookup received error "
<< error;
OnStunBindingOrResolveRequestFailed(input);
return;
}

57
p2p/base/tcpport.cc
View File

@ -68,7 +68,6 @@
#include <vector>
#include "p2p/base/common.h"
#include "rtc_base/checks.h"
#include "rtc_base/logging.h"
@ -175,7 +174,8 @@ void TCPPort::PrepareAddress() {
TCPTYPE_PASSIVE_STR, LOCAL_PORT_TYPE,
ICE_TYPE_PREFERENCE_HOST_TCP, 0, "", true);
} else {
LOG_J(LS_INFO, this) << "Not listening due to firewall restrictions.";
RTC_LOG(LS_INFO) << ToString()
<< ": Not listening due to firewall restrictions.";
// Note: We still add the address, since otherwise the remote side won't
// recognize our incoming TCP connections. According to
// https://tools.ietf.org/html/rfc6544#section-4.5, for active candidate,
@ -211,8 +211,9 @@ int TCPPort::SendTo(const void* data, size_t size,
socket = GetIncoming(addr);
}
if (!socket) {
LOG_J(LS_ERROR, this) << "Attempted to send to an unknown destination, "
<< addr.ToSensitiveString();
RTC_LOG(LS_ERROR) << ToString()
<< ": Attempted to send to an unknown destination: "
<< addr.ToSensitiveString();
return SOCKET_ERROR; // TODO(tbd): Set error_
}
@ -222,8 +223,8 @@ int TCPPort::SendTo(const void* data, size_t size,
// Error from this code path for a Connection (instead of from a bare
// socket) will not trigger reconnecting. In theory, this shouldn't matter
// as OnClose should always be called and set connected to false.
LOG_J(LS_ERROR, this) << "TCP send of " << size
<< " bytes failed with error " << error_;
RTC_LOG(LS_ERROR) << ToString() << ": TCP send of "
<< size << " bytes failed with error " << error_;
}
return sent;
}
@ -267,8 +268,9 @@ void TCPPort::OnNewConnection(rtc::AsyncPacketSocket* socket,
incoming.socket->SignalReadyToSend.connect(this, &TCPPort::OnReadyToSend);
incoming.socket->SignalSentPacket.connect(this, &TCPPort::OnSentPacket);
LOG_J(LS_VERBOSE, this) << "Accepted connection from "
<< incoming.addr.ToSensitiveString();
RTC_LOG(LS_VERBOSE) << ToString()
<< ": Accepted connection from "
<< incoming.addr.ToSensitiveString();
incoming_.push_back(incoming);
}
@ -277,8 +279,9 @@ void TCPPort::TryCreateServerSocket() {
rtc::SocketAddress(Network()->GetBestIP(), 0), min_port(), max_port(),
false /* ssl */);
if (!socket_) {
LOG_J(LS_WARNING, this)
<< "TCP server socket creation failed; continuing anyway.";
RTC_LOG(LS_WARNING)
<< ToString()
<< ": TCP server socket creation failed; continuing anyway.";
return;
}
socket_->SignalNewConnection.connect(this, &TCPPort::OnNewConnection);
@ -342,9 +345,9 @@ TCPConnection::TCPConnection(TCPPort* port,
} else {
// Incoming connections should match one of the network addresses. Same as
// what's being checked in OnConnect, but just DCHECKing here.
LOG_J(LS_VERBOSE, this)
<< "socket ipaddr: " << socket_->GetLocalAddress().ToString()
<< ", port() Network:" << port->Network()->ToString();
RTC_LOG(LS_VERBOSE) << ToString() << ": socket ipaddr: "
<< socket_->GetLocalAddress().ToString()
<< ", port() Network:" << port->Network()->ToString();
const std::vector<rtc::InterfaceAddress>& desired_addresses =
port_->Network()->GetIPs();
RTC_DCHECK(std::find_if(desired_addresses.begin(), desired_addresses.end(),
@ -435,8 +438,9 @@ void TCPConnection::OnConnect(rtc::AsyncPacketSocket* socket) {
[socket_address](const rtc::InterfaceAddress& addr) {
return socket_address.ipaddr() == addr;
}) != desired_addresses.end()) {
LOG_J(LS_VERBOSE, this) << "Connection established to "
<< socket->GetRemoteAddress().ToSensitiveString();
RTC_LOG(LS_VERBOSE) << ToString()
<< ": Connection established to "
<< socket->GetRemoteAddress().ToSensitiveString();
} else {
if (socket->GetLocalAddress().IsLoopbackIP()) {
RTC_LOG(LS_WARNING) << "Socket is bound to the address:"
@ -451,7 +455,7 @@ void TCPConnection::OnConnect(rtc::AsyncPacketSocket* socket) {
<< ", rather than an address associated with network:"
<< port_->Network()->ToString()
<< ". Still allowing it since it's the 'any' address"
<< ", possibly caused by multiple_routes being disabled.";
", possibly caused by multiple_routes being disabled.";
} else {
RTC_LOG(LS_WARNING) << "Dropping connection as TCP socket bound to IP "
<< socket_address.ipaddr().ToString()
@ -469,7 +473,8 @@ void TCPConnection::OnConnect(rtc::AsyncPacketSocket* socket) {
void TCPConnection::OnClose(rtc::AsyncPacketSocket* socket, int error) {
RTC_DCHECK(socket == socket_.get());
LOG_J(LS_INFO, this) << "Connection closed with error " << error;
RTC_LOG(LS_INFO) << ToString()
<< ": Connection closed with error " << error;
// Guard against the condition where IPC socket will call OnClose for every
// packet it can't send.
@ -516,8 +521,9 @@ void TCPConnection::MaybeReconnect() {
return;
}
LOG_J(LS_INFO, this) << "TCP Connection with remote is closed, "
<< "trying to reconnect";
RTC_LOG(LS_INFO) << ToString()
<< ": TCP Connection with remote is closed, "
"trying to reconnect";
CreateOutgoingTcpSocket();
error_ = EPIPE;
@ -547,15 +553,18 @@ void TCPConnection::CreateOutgoingTcpSocket() {
remote_candidate().address(), port()->proxy(), port()->user_agent(),
opts));
if (socket_) {
LOG_J(LS_VERBOSE, this)
<< "Connecting from " << socket_->GetLocalAddress().ToSensitiveString()
<< " to " << remote_candidate().address().ToSensitiveString();
RTC_LOG(LS_VERBOSE) << ToString()
<< ": Connecting from "
<< socket_->GetLocalAddress().ToSensitiveString()
<< " to "
<< remote_candidate().address().ToSensitiveString();
set_connected(false);
connection_pending_ = true;
ConnectSocketSignals(socket_.get());
} else {
LOG_J(LS_WARNING, this) << "Failed to create connection to "
<< remote_candidate().address().ToSensitiveString();
RTC_LOG(LS_WARNING) << ToString()
<< ": Failed to create connection to "
<< remote_candidate().address().ToSensitiveString();
}
}

2
p2p/base/transportdescriptionfactory.cc
View File

@ -64,7 +64,7 @@ TransportDescription* TransportDescriptionFactory::CreateAnswer(
// TODO(juberti): Figure out why we get NULL offers, and fix this upstream.
if (!offer) {
RTC_LOG(LS_WARNING) << "Failed to create TransportDescription answer "
<< "because offer is NULL";
"because offer is NULL";
return NULL;
}

336
p2p/base/turnport.cc
View File

@ -16,7 +16,6 @@
#include <vector>
#include "api/optional.h"
#include "p2p/base/common.h"
#include "p2p/base/stun.h"
#include "rtc_base/asyncpacketsocket.h"
#include "rtc_base/byteorder.h"
@ -308,7 +307,7 @@ void TurnPort::PrepareAddress() {
if (credentials_.username.empty() ||
credentials_.password.empty()) {
RTC_LOG(LS_ERROR) << "Allocation can't be started without setting the"
<< " TURN server credentials for the user.";
" TURN server credentials for the user.";
OnAllocateError();
return;
}
@ -323,8 +322,8 @@ void TurnPort::PrepareAddress() {
} else {
// If protocol family of server address doesn't match with local, return.
if (!IsCompatibleAddress(server_address_.address)) {
RTC_LOG(LS_ERROR) << "IP address family does not match: "
<< "server: " << server_address_.address.family()
RTC_LOG(LS_ERROR) << "IP address family does not match. server: "
<< server_address_.address.family()
<< " local: " << Network()->GetBestIP().family();
OnAllocateError();
return;
@ -333,9 +332,10 @@ void TurnPort::PrepareAddress() {
// Insert the current address to prevent redirection pingpong.
attempted_server_addresses_.insert(server_address_.address);
LOG_J(LS_INFO, this) << "Trying to connect to TURN server via "
<< ProtoToString(server_address_.proto) << " @ "
<< server_address_.address.ToSensitiveString();
RTC_LOG(LS_INFO) << ToString()
<< ": Trying to connect to TURN server via "
<< ProtoToString(server_address_.proto) << " @ "
<< server_address_.address.ToSensitiveString();
if (!CreateTurnClientSocket()) {
RTC_LOG(LS_ERROR) << "Failed to create TURN client socket";
OnAllocateError();
@ -451,7 +451,7 @@ void TurnPort::OnSocketConnect(rtc::AsyncPacketSocket* socket) {
<< ", rather than an address associated with network:"
<< Network()->ToString()
<< ". Still allowing it since it's the 'any' address"
<< ", possibly caused by multiple_routes being disabled.";
", possibly caused by multiple_routes being disabled.";
} else {
RTC_LOG(LS_WARNING) << "Socket is bound to the address:"
<< socket_address.ipaddr().ToString()
@ -473,23 +473,27 @@ void TurnPort::OnSocketConnect(rtc::AsyncPacketSocket* socket) {
}
void TurnPort::OnSocketClose(rtc::AsyncPacketSocket* socket, int error) {
LOG_J(LS_WARNING, this) << "Connection with server failed, error=" << error;
RTC_LOG(LS_WARNING) << ToString()
<< ": Connection with server failed with error: "
<< error;
RTC_DCHECK(socket == socket_);
Close();
}
void TurnPort::OnAllocateMismatch() {
if (allocate_mismatch_retries_ >= MAX_ALLOCATE_MISMATCH_RETRIES) {
LOG_J(LS_WARNING, this) << "Giving up on the port after "
<< allocate_mismatch_retries_
<< " retries for STUN_ERROR_ALLOCATION_MISMATCH";
RTC_LOG(LS_WARNING) << ToString()
<< ": Giving up on the port after "
<< allocate_mismatch_retries_
<< " retries for STUN_ERROR_ALLOCATION_MISMATCH";
OnAllocateError();
return;
}
LOG_J(LS_INFO, this) << "Allocating a new socket after "
<< "STUN_ERROR_ALLOCATION_MISMATCH, retry = "
<< allocate_mismatch_retries_ + 1;
RTC_LOG(LS_INFO) << ToString()
<< ": Allocating a new socket after "
"STUN_ERROR_ALLOCATION_MISMATCH, retry: "
<< allocate_mismatch_retries_ + 1;
if (SharedSocket()) {
ResetSharedSocket();
} else {
@ -580,7 +584,7 @@ int TurnPort::SendTo(const void* data, size_t size,
// Try to find an entry for this specific address; we should have one.
TurnEntry* entry = FindEntry(addr);
if (!entry) {
RTC_LOG(LS_ERROR) << "Did not find the TurnEntry for address " << addr;
RTC_LOG(LS_ERROR) << "Did not find the TurnEntry for address: " << addr;
return 0;
}
@ -619,22 +623,24 @@ bool TurnPort::HandleIncomingPacket(rtc::AsyncPacketSocket* socket,
// alternative server redirection. TODO(guoweis): add a unit test for this
// race condition.
if (remote_addr != server_address_.address) {
LOG_J(LS_WARNING, this) << "Discarding TURN message from unknown address:"
<< remote_addr.ToString()
<< ", server_address_:"
<< server_address_.address.ToString();
RTC_LOG(LS_WARNING) << ToString()
<< ": Discarding TURN message from unknown address: "
<< remote_addr.ToString() << " server_address_: "
<< server_address_.address.ToString();
return false;
}
// The message must be at least the size of a channel header.
if (size < TURN_CHANNEL_HEADER_SIZE) {
LOG_J(LS_WARNING, this) << "Received TURN message that was too short";
RTC_LOG(LS_WARNING) << ToString()
<< ": Received TURN message that was too short";
return false;
}
if (state_ == STATE_DISCONNECTED) {
LOG_J(LS_WARNING, this)
<< "Received TURN message while the TURN port is disconnected";
RTC_LOG(LS_WARNING)
<< ToString()
<< ": Received TURN message while the TURN port is disconnected";
return false;
}
@ -654,8 +660,9 @@ bool TurnPort::HandleIncomingPacket(rtc::AsyncPacketSocket* socket,
if (SharedSocket() && (msg_type == STUN_BINDING_RESPONSE ||
msg_type == STUN_BINDING_ERROR_RESPONSE)) {
LOG_J(LS_VERBOSE, this) <<
"Ignoring STUN binding response message on shared socket.";
RTC_LOG(LS_VERBOSE)
<< ToString()
<< ": Ignoring STUN binding response message on shared socket.";
return false;
}
@ -663,8 +670,10 @@ bool TurnPort::HandleIncomingPacket(rtc::AsyncPacketSocket* socket,
// Check success responses, but not errors, for MESSAGE-INTEGRITY.
if (IsStunSuccessResponseType(msg_type) &&
!StunMessage::ValidateMessageIntegrity(data, size, hash())) {
LOG_J(LS_WARNING, this) << "Received TURN message with invalid "
<< "message integrity, msg_type=" << msg_type;
RTC_LOG(LS_WARNING) << ToString()
<< ": Received TURN message with invalid "
"message integrity, msg_type: "
<< msg_type;
return true;
}
request_manager_.CheckResponse(data, size);
@ -701,32 +710,32 @@ bool TurnPort::SetAlternateServer(const rtc::SocketAddress& address) {
// Check if we have seen this address before and reject if we did.
AttemptedServerSet::iterator iter = attempted_server_addresses_.find(address);
if (iter != attempted_server_addresses_.end()) {
LOG_J(LS_WARNING, this) << "Redirection to ["
<< address.ToSensitiveString()
<< "] ignored, allocation failed.";
RTC_LOG(LS_WARNING) << ToString() << ": Redirection to ["
<< address.ToSensitiveString()
<< "] ignored, allocation failed.";
return false;
}
// If protocol family of server address doesn't match with local, return.
if (!IsCompatibleAddress(address)) {
RTC_LOG(LS_WARNING) << "Server IP address family does not match with "
<< "local host address family type";
"local host address family type";
return false;
}
// Block redirects to a loopback address.
// See: https://bugs.chromium.org/p/chromium/issues/detail?id=649118
if (address.IsLoopbackIP()) {
LOG_J(LS_WARNING, this)
<< "Blocking attempted redirect to loopback address.";
RTC_LOG(LS_WARNING) << ToString()
<< ": Blocking attempted redirect to loopback address.";
return false;
}
LOG_J(LS_INFO, this) << "Redirecting from TURN server ["
<< server_address_.address.ToSensitiveString()
<< "] to TURN server ["
<< address.ToSensitiveString()
<< "]";
RTC_LOG(LS_INFO) << ToString()
<< ": Redirecting from TURN server ["
<< server_address_.address.ToSensitiveString()
<< "] to TURN server [" << address.ToSensitiveString()
<< "]";
server_address_ = ProtocolAddress(address, server_address_.proto);
// Insert the current address to prevent redirection pingpong.
@ -738,8 +747,9 @@ void TurnPort::ResolveTurnAddress(const rtc::SocketAddress& address) {
if (resolver_)
return;
LOG_J(LS_INFO, this) << "Starting TURN host lookup for "
<< address.ToSensitiveString();
RTC_LOG(LS_INFO) << ToString()
<< ": Starting TURN host lookup for "
<< address.ToSensitiveString();
resolver_ = socket_factory()->CreateAsyncResolver();
resolver_->SignalDone.connect(this, &TurnPort::OnResolveResult);
resolver_->Start(address);
@ -765,8 +775,9 @@ void TurnPort::OnResolveResult(rtc::AsyncResolverInterface* resolver) {
if (resolver_->GetError() != 0 ||
!resolver_->GetResolvedAddress(Network()->GetBestIP().family(),
&resolved_address)) {
LOG_J(LS_WARNING, this) << "TURN host lookup received error "
<< resolver_->GetError();
RTC_LOG(LS_WARNING) << ToString()
<< ": TURN host lookup received error "
<< resolver_->GetError();
error_ = resolver_->GetError();
OnAllocateError();
return;
@ -784,8 +795,9 @@ void TurnPort::OnSendStunPacket(const void* data, size_t size,
RTC_DCHECK(connected());
rtc::PacketOptions options(DefaultDscpValue());
if (Send(data, size, options) < 0) {
LOG_J(LS_ERROR, this) << "Failed to send TURN message, err="
<< socket_->GetError();
RTC_LOG(LS_ERROR) << ToString()
<< ": Failed to send TURN message, error: "
<< socket_->GetError();
}
}
@ -912,7 +924,8 @@ void TurnPort::HandleDataIndication(const char* data, size_t size,
rtc::ByteBufferReader buf(data, size);
TurnMessage msg;
if (!msg.Read(&buf)) {
LOG_J(LS_WARNING, this) << "Received invalid TURN data indication";
RTC_LOG(LS_WARNING) << ToString()
<< ": Received invalid TURN data indication";
return;
}
@ -920,16 +933,18 @@ void TurnPort::HandleDataIndication(const char* data, size_t size,
const StunAddressAttribute* addr_attr =
msg.GetAddress(STUN_ATTR_XOR_PEER_ADDRESS);
if (!addr_attr) {
LOG_J(LS_WARNING, this) << "Missing STUN_ATTR_XOR_PEER_ADDRESS attribute "
<< "in data indication.";
RTC_LOG(LS_WARNING) << ToString()
<< ": Missing STUN_ATTR_XOR_PEER_ADDRESS attribute "
"in data indication.";
return;
}
const StunByteStringAttribute* data_attr =
msg.GetByteString(STUN_ATTR_DATA);
if (!data_attr) {
LOG_J(LS_WARNING, this) << "Missing STUN_ATTR_DATA attribute in "
<< "data indication.";
RTC_LOG(LS_WARNING) << ToString()
<< ": Missing STUN_ATTR_DATA attribute in "
"data indication.";
return;
}
@ -937,9 +952,10 @@ void TurnPort::HandleDataIndication(const char* data, size_t size,
// a permission for.
rtc::SocketAddress ext_addr(addr_attr->GetAddress());
if (!HasPermission(ext_addr.ipaddr())) {
LOG_J(LS_WARNING, this)
<< "Received TURN data indication with unknown "
<< "peer address, addr=" << ext_addr.ToSensitiveString();
RTC_LOG(LS_WARNING) << ToString()
<< ": Received TURN data indication with unknown "
"peer address, addr: "
<< ext_addr.ToSensitiveString();
}
DispatchPacket(data_attr->bytes(), data_attr->length(), ext_addr,
@ -966,16 +982,20 @@ void TurnPort::HandleChannelData(int channel_id, const char* data,
// Extract header fields from the message.
uint16_t len = rtc::GetBE16(data + 2);
if (len > size - TURN_CHANNEL_HEADER_SIZE) {
LOG_J(LS_WARNING, this) << "Received TURN channel data message with "
<< "incorrect length, len=" << len;
RTC_LOG(LS_WARNING) << ToString()
<< ": Received TURN channel data message with "
"incorrect length, len: "
<< len;
return;
}
// Allowing messages larger than |len|, as ChannelData can be padded.
TurnEntry* entry = FindEntry(channel_id);
if (!entry) {
LOG_J(LS_WARNING, this) << "Received TURN channel data message for invalid "
<< "channel, channel_id=" << channel_id;
RTC_LOG(LS_WARNING) << ToString()
<< ": Received TURN channel data message for invalid "
"channel, channel_id: "
<< channel_id;
return;
}
@ -1004,14 +1024,16 @@ bool TurnPort::ScheduleRefresh(uint32_t lifetime) {
// The RFC does not mention a lower limit on lifetime.
// So if server sends a value less than 2 minutes, we schedule a refresh
// for half lifetime.
LOG_J(LS_WARNING, this) << "Received response with short lifetime="
<< lifetime << " seconds.";
RTC_LOG(LS_WARNING) << ToString()
<< ": Received response with short lifetime: "
<< lifetime << " seconds.";
delay = (lifetime * 1000) / 2;
} else if (lifetime > max_lifetime) {
// Make 1 hour largest delay, and then sce
// we schedule a refresh for one minute less than max lifetime.
LOG_J(LS_WARNING, this) << "Received response with long lifetime="
<< lifetime << " seconds.";
RTC_LOG(LS_WARNING) << ToString()
<< ": Received response with long lifetime: "
<< lifetime << " seconds.";
delay = (max_lifetime - 60) * 1000;
} else {
// Normal case,
@ -1020,7 +1042,8 @@ bool TurnPort::ScheduleRefresh(uint32_t lifetime) {
}
SendRequest(new TurnRefreshRequest(this), delay);
LOG_J(LS_INFO, this) << "Scheduled refresh in " << delay << "ms.";
RTC_LOG(LS_INFO) << ToString() << ": Scheduled refresh in "
<< delay << "ms.";
return true;
}
@ -1060,7 +1083,7 @@ bool TurnPort::UpdateNonce(StunMessage* response) {
response->GetByteString(STUN_ATTR_REALM);
if (!realm_attr) {
RTC_LOG(LS_ERROR) << "Missing STUN_ATTR_REALM attribute in "
<< "stale nonce error response.";
"stale nonce error response.";
return false;
}
set_realm(realm_attr->GetString());
@ -1069,7 +1092,7 @@ bool TurnPort::UpdateNonce(StunMessage* response) {
response->GetByteString(STUN_ATTR_NONCE);
if (!nonce_attr) {
RTC_LOG(LS_ERROR) << "Missing STUN_ATTR_NONCE attribute in "
<< "stale nonce error response.";
"stale nonce error response.";
return false;
}
set_nonce(nonce_attr->GetString());
@ -1251,23 +1274,27 @@ void TurnAllocateRequest::Prepare(StunMessage* request) {
}
void TurnAllocateRequest::OnSent() {
LOG_J(LS_INFO, port_) << "TURN allocate request sent"
<< ", id=" << rtc::hex_encode(id());
RTC_LOG(LS_INFO) << port_->ToString()
<< ": TURN allocate request sent, id="
<< rtc::hex_encode(id());
StunRequest::OnSent();
}
void TurnAllocateRequest::OnResponse(StunMessage* response) {
LOG_J(LS_INFO, port_) << "TURN allocate requested successfully"
<< ", id=" << rtc::hex_encode(id())
<< ", code=0" // Makes logging easier to parse.
<< ", rtt=" << Elapsed();
RTC_LOG(LS_INFO) << port_->ToString()
<< ": TURN allocate requested successfully, id="
<< rtc::hex_encode(id())
<< ", code=0" // Makes logging easier to parse.
", rtt="
<< Elapsed();
// Check mandatory attributes as indicated in RFC5766, Section 6.3.
const StunAddressAttribute* mapped_attr =
response->GetAddress(STUN_ATTR_XOR_MAPPED_ADDRESS);
if (!mapped_attr) {
LOG_J(LS_WARNING, port_) << "Missing STUN_ATTR_XOR_MAPPED_ADDRESS "
<< "attribute in allocate success response";
RTC_LOG(LS_WARNING) << port_->ToString()
<< ": Missing STUN_ATTR_XOR_MAPPED_ADDRESS "
"attribute in allocate success response";
return;
}
// Using XOR-Mapped-Address for stun.
@ -1276,16 +1303,18 @@ void TurnAllocateRequest::OnResponse(StunMessage* response) {
const StunAddressAttribute* relayed_attr =
response->GetAddress(STUN_ATTR_XOR_RELAYED_ADDRESS);
if (!relayed_attr) {
LOG_J(LS_WARNING, port_) << "Missing STUN_ATTR_XOR_RELAYED_ADDRESS "
<< "attribute in allocate success response";
RTC_LOG(LS_WARNING) << port_->ToString()
<< ": Missing STUN_ATTR_XOR_RELAYED_ADDRESS "
"attribute in allocate success response";
return;
}
const StunUInt32Attribute* lifetime_attr =
response->GetUInt32(STUN_ATTR_TURN_LIFETIME);
if (!lifetime_attr) {
LOG_J(LS_WARNING, port_) << "Missing STUN_ATTR_TURN_LIFETIME attribute in "
<< "allocate success response";
RTC_LOG(LS_WARNING) << port_->ToString()
<< ": Missing STUN_ATTR_TURN_LIFETIME attribute in "
"allocate success response";
return;
}
// Notify the port the allocate succeeded, and schedule a refresh request.
@ -1298,9 +1327,10 @@ void TurnAllocateRequest::OnErrorResponse(StunMessage* response) {
// Process error response according to RFC5766, Section 6.4.
int error_code = response->GetErrorCodeValue();
LOG_J(LS_INFO, port_) << "Received TURN allocate error response"
<< ", id=" << rtc::hex_encode(id())
<< ", code=" << error_code << ", rtt=" << Elapsed();
RTC_LOG(LS_INFO) << port_->ToString()
<< ": Received TURN allocate error response, id="
<< rtc::hex_encode(id()) << ", code=" << error_code
<< ", rtt=" << Elapsed();
switch (error_code) {
case STUN_ERROR_UNAUTHORIZED: // Unauthrorized.
@ -1316,25 +1346,27 @@ void TurnAllocateRequest::OnErrorResponse(StunMessage* response) {
TurnPort::MSG_ALLOCATE_MISMATCH);
break;
default:
LOG_J(LS_WARNING, port_)
<< "Received TURN allocate error response"
<< ", id=" << rtc::hex_encode(id()) << ", code=" << error_code
<< ", rtt=" << Elapsed();
RTC_LOG(LS_WARNING) << port_->ToString()
<< ": Received TURN allocate error response, id="
<< rtc::hex_encode(id()) << ", code=" << error_code
<< ", rtt=" << Elapsed();
port_->OnAllocateError();
}
}
void TurnAllocateRequest::OnTimeout() {
LOG_J(LS_WARNING, port_) << "TURN allocate request "
<< rtc::hex_encode(id()) << " timeout";
RTC_LOG(LS_WARNING) << port_->ToString()
<< ": TURN allocate request " << rtc::hex_encode(id())
<< " timeout";
port_->OnAllocateRequestTimeout();
}
void TurnAllocateRequest::OnAuthChallenge(StunMessage* response, int code) {
// If we failed to authenticate even after we sent our credentials, fail hard.
if (code == STUN_ERROR_UNAUTHORIZED && !port_->hash().empty()) {
LOG_J(LS_WARNING, port_) << "Failed to authenticate with the server "
<< "after challenge.";
RTC_LOG(LS_WARNING) << port_->ToString()
<< ": Failed to authenticate with the server "
"after challenge.";
port_->OnAllocateError();
return;
}
@ -1343,8 +1375,9 @@ void TurnAllocateRequest::OnAuthChallenge(StunMessage* response, int code) {
const StunByteStringAttribute* realm_attr =
response->GetByteString(STUN_ATTR_REALM);
if (!realm_attr) {
LOG_J(LS_WARNING, port_) << "Missing STUN_ATTR_REALM attribute in "
<< "allocate unauthorized response.";
RTC_LOG(LS_WARNING) << port_->ToString()
<< ": Missing STUN_ATTR_REALM attribute in "
"allocate unauthorized response.";
return;
}
port_->set_realm(realm_attr->GetString());
@ -1352,8 +1385,9 @@ void TurnAllocateRequest::OnAuthChallenge(StunMessage* response, int code) {
const StunByteStringAttribute* nonce_attr =
response->GetByteString(STUN_ATTR_NONCE);
if (!nonce_attr) {
LOG_J(LS_WARNING, port_) << "Missing STUN_ATTR_NONCE attribute in "
<< "allocate unauthorized response.";
RTC_LOG(LS_WARNING) << port_->ToString()
<< ": Missing STUN_ATTR_NONCE attribute in "
"allocate unauthorized response.";
return;
}
port_->set_nonce(nonce_attr->GetString());
@ -1371,8 +1405,9 @@ void TurnAllocateRequest::OnTryAlternate(StunMessage* response, int code) {
const StunAddressAttribute* alternate_server_attr =
response->GetAddress(STUN_ATTR_ALTERNATE_SERVER);
if (!alternate_server_attr) {
LOG_J(LS_WARNING, port_) << "Missing STUN_ATTR_ALTERNATE_SERVER "
<< "attribute in try alternate error response";
RTC_LOG(LS_WARNING) << port_->ToString()
<< ": Missing STUN_ATTR_ALTERNATE_SERVER "
"attribute in try alternate error response";
port_->OnAllocateError();
return;
}
@ -1385,16 +1420,18 @@ void TurnAllocateRequest::OnTryAlternate(StunMessage* response, int code) {
const StunByteStringAttribute* realm_attr =
response->GetByteString(STUN_ATTR_REALM);
if (realm_attr) {
LOG_J(LS_INFO, port_) << "Applying STUN_ATTR_REALM attribute in "
<< "try alternate error response.";
RTC_LOG(LS_INFO) << port_->ToString()
<< ": Applying STUN_ATTR_REALM attribute in "
"try alternate error response.";
port_->set_realm(realm_attr->GetString());
}
const StunByteStringAttribute* nonce_attr =
response->GetByteString(STUN_ATTR_NONCE);
if (nonce_attr) {
LOG_J(LS_INFO, port_) << "Applying STUN_ATTR_NONCE attribute in "
<< "try alternate error response.";
RTC_LOG(LS_INFO) << port_->ToString()
<< ": Applying STUN_ATTR_NONCE attribute in "
"try alternate error response.";
port_->set_nonce(nonce_attr->GetString());
}
@ -1425,23 +1462,27 @@ void TurnRefreshRequest::Prepare(StunMessage* request) {
}
void TurnRefreshRequest::OnSent() {
LOG_J(LS_INFO, port_) << "TURN refresh request sent"
<< ", id=" << rtc::hex_encode(id());
RTC_LOG(LS_INFO) << port_->ToString()
<< ": TURN refresh request sent, id="
<< rtc::hex_encode(id());
StunRequest::OnSent();
}
void TurnRefreshRequest::OnResponse(StunMessage* response) {
LOG_J(LS_INFO, port_) << "TURN refresh requested successfully"
<< ", id=" << rtc::hex_encode(id())
<< ", code=0" // Makes logging easier to parse.
<< ", rtt=" << Elapsed();
RTC_LOG(LS_INFO) << port_->ToString()
<< ": TURN refresh requested successfully, id="
<< rtc::hex_encode(id())
<< ", code=0" // Makes logging easier to parse.
", rtt="
<< Elapsed();
// Check mandatory attributes as indicated in RFC5766, Section 7.3.
const StunUInt32Attribute* lifetime_attr =
response->GetUInt32(STUN_ATTR_TURN_LIFETIME);
if (!lifetime_attr) {
LOG_J(LS_WARNING, port_) << "Missing STUN_ATTR_TURN_LIFETIME attribute in "
<< "refresh success response.";
RTC_LOG(LS_WARNING) << port_->ToString()
<< ": Missing STUN_ATTR_TURN_LIFETIME attribute in "
"refresh success response.";
return;
}
@ -1467,17 +1508,18 @@ void TurnRefreshRequest::OnErrorResponse(StunMessage* response) {
port_->SendRequest(new TurnRefreshRequest(port_), 0);
}
} else {
LOG_J(LS_WARNING, port_)
<< "Received TURN refresh error response"
<< ", id=" << rtc::hex_encode(id()) << ", code=" << error_code
<< ", rtt=" << Elapsed();
RTC_LOG(LS_WARNING) << port_->ToString()
<< ": Received TURN refresh error response, id="
<< rtc::hex_encode(id()) << ", code=" << error_code
<< ", rtt=" << Elapsed();
port_->OnRefreshError();
port_->SignalTurnRefreshResult(port_, error_code);
}
}
void TurnRefreshRequest::OnTimeout() {
LOG_J(LS_WARNING, port_) << "TURN refresh timeout " << rtc::hex_encode(id());
RTC_LOG(LS_WARNING) << port_->ToString()
<< ": TURN refresh timeout " << rtc::hex_encode(id());
port_->OnRefreshError();
}
@ -1502,16 +1544,19 @@ void TurnCreatePermissionRequest::Prepare(StunMessage* request) {
}
void TurnCreatePermissionRequest::OnSent() {
LOG_J(LS_INFO, port_) << "TURN create permission request sent"
<< ", id=" << rtc::hex_encode(id());
RTC_LOG(LS_INFO) << port_->ToString()
<< ": TURN create permission request sent, id="
<< rtc::hex_encode(id());
StunRequest::OnSent();
}
void TurnCreatePermissionRequest::OnResponse(StunMessage* response) {
LOG_J(LS_INFO, port_) << "TURN permission requested successfully"
<< ", id=" << rtc::hex_encode(id())
<< ", code=0" // Makes logging easier to parse.
<< ", rtt=" << Elapsed();
RTC_LOG(LS_INFO) << port_->ToString()
<< ": TURN permission requested successfully, id="
<< rtc::hex_encode(id())
<< ", code=0" // Makes logging easier to parse.
", rtt="
<< Elapsed();
if (entry_) {
entry_->OnCreatePermissionSuccess();
@ -1520,17 +1565,19 @@ void TurnCreatePermissionRequest::OnResponse(StunMessage* response) {
void TurnCreatePermissionRequest::OnErrorResponse(StunMessage* response) {
int error_code = response->GetErrorCodeValue();
LOG_J(LS_WARNING, port_) << "Received TURN create permission error response"
<< ", id=" << rtc::hex_encode(id())
<< ", code=" << error_code << ", rtt=" << Elapsed();
RTC_LOG(LS_WARNING) << port_->ToString()
<< ": Received TURN create permission error response, id="
<< rtc::hex_encode(id()) << ", code=" << error_code
<< ", rtt=" << Elapsed();
if (entry_) {
entry_->OnCreatePermissionError(response, error_code);
}
}
void TurnCreatePermissionRequest::OnTimeout() {
LOG_J(LS_WARNING, port_) << "TURN create permission timeout "
<< rtc::hex_encode(id());
RTC_LOG(LS_WARNING) << port_->ToString()
<< ": TURN create permission timeout "
<< rtc::hex_encode(id());
if (entry_) {
entry_->OnCreatePermissionTimeout();
}
@ -1565,16 +1612,19 @@ void TurnChannelBindRequest::Prepare(StunMessage* request) {
}
void TurnChannelBindRequest::OnSent() {
LOG_J(LS_INFO, port_) << "TURN channel bind request sent"
<< ", id=" << rtc::hex_encode(id());
RTC_LOG(LS_INFO) << port_->ToString()
<< ": TURN channel bind request sent, id="
<< rtc::hex_encode(id());
StunRequest::OnSent();
}
void TurnChannelBindRequest::OnResponse(StunMessage* response) {
LOG_J(LS_INFO, port_) << "TURN channel bind requested successfully"
<< ", id=" << rtc::hex_encode(id())
<< ", code=0" // Makes logging easier to parse.
<< ", rtt=" << Elapsed();
RTC_LOG(LS_INFO) << port_->ToString()
<< ": TURN channel bind requested successfully, id="
<< rtc::hex_encode(id())
<< ", code=0" // Makes logging easier to parse.
", rtt="
<< Elapsed();
if (entry_) {
entry_->OnChannelBindSuccess();
@ -1584,23 +1634,26 @@ void TurnChannelBindRequest::OnResponse(StunMessage* response) {
// permission from expiring.
int delay = TURN_PERMISSION_TIMEOUT - 60000;
entry_->SendChannelBindRequest(delay);
LOG_J(LS_INFO, port_) << "Scheduled channel bind in " << delay << "ms.";
RTC_LOG(LS_INFO) << port_->ToString()
<< ": Scheduled channel bind in " << delay << "ms.";
}
}
void TurnChannelBindRequest::OnErrorResponse(StunMessage* response) {
int error_code = response->GetErrorCodeValue();
LOG_J(LS_WARNING, port_) << "Received TURN channel bind error response"
<< ", id=" << rtc::hex_encode(id())
<< ", code=" << error_code << ", rtt=" << Elapsed();
RTC_LOG(LS_WARNING) << port_->ToString()
<< ": Received TURN channel bind error response, id="
<< rtc::hex_encode(id()) << ", code=" << error_code
<< ", rtt=" << Elapsed();
if (entry_) {
entry_->OnChannelBindError(response, error_code);
}
}
void TurnChannelBindRequest::OnTimeout() {
LOG_J(LS_WARNING, port_) << "TURN channel bind timeout "
<< rtc::hex_encode(id());
RTC_LOG(LS_WARNING) << port_->ToString()
<< ": TURN channel bind timeout "
<< rtc::hex_encode(id());
if (entry_) {
entry_->OnChannelBindTimeout();
}
@ -1667,9 +1720,9 @@ int TurnEntry::Send(const void* data, size_t size, bool payload,
}
void TurnEntry::OnCreatePermissionSuccess() {
LOG_J(LS_INFO, port_) << "Create permission for "
<< ext_addr_.ToSensitiveString()
<< " succeeded";
RTC_LOG(LS_INFO) << port_->ToString()
<< ": Create permission for "
<< ext_addr_.ToSensitiveString() << " succeeded";
port_->SignalCreatePermissionResult(port_, ext_addr_,
TURN_SUCCESS_RESULT_CODE);
@ -1680,8 +1733,9 @@ void TurnEntry::OnCreatePermissionSuccess() {
// times out.
int delay = TURN_PERMISSION_TIMEOUT - 60000;
SendCreatePermissionRequest(delay);
LOG_J(LS_INFO, port_) << "Scheduled create-permission-request in "
<< delay << "ms.";
RTC_LOG(LS_INFO) << port_->ToString()
<< ": Scheduled create-permission-request in " << delay
<< "ms.";
}
}
@ -1694,7 +1748,8 @@ void TurnEntry::OnCreatePermissionError(StunMessage* response, int code) {
bool found = port_->FailAndPruneConnection(ext_addr_);
if (found) {
RTC_LOG(LS_ERROR) << "Received TURN CreatePermission error response, "
<< "code=" << code << "; pruned connection.";
"code="
<< code << "; pruned connection.";
}
// Send signal with error code.
port_->SignalCreatePermissionResult(port_, ext_addr_, code);
@ -1706,8 +1761,9 @@ void TurnEntry::OnCreatePermissionTimeout() {
}
void TurnEntry::OnChannelBindSuccess() {
LOG_J(LS_INFO, port_) << "Channel bind for " << ext_addr_.ToSensitiveString()
<< " succeeded";
RTC_LOG(LS_INFO) << port_->ToString()
<< ": Successful channel bind for "
<< ext_addr_.ToSensitiveString();
RTC_DCHECK(state_ == STATE_BINDING || state_ == STATE_BOUND);
state_ = STATE_BOUND;
}

42
p2p/base/turnserver.cc
View File

@ -14,7 +14,6 @@
#include <utility>
#include "p2p/base/asyncstuntcpsocket.h"
#include "p2p/base/common.h"
#include "p2p/base/packetsocketfactory.h"
#include "p2p/base/stun.h"
#include "rtc_base/bind.h"
@ -601,7 +600,7 @@ TurnServerAllocation::~TurnServerAllocation() {
delete *it;
}
thread_->Clear(this, MSG_ALLOCATION_TIMEOUT);
LOG_J(LS_INFO, this) << "Allocation destroyed";
RTC_LOG(LS_INFO) << ToString() << ": Allocation destroyed";
}
std::string TurnServerAllocation::ToString() const {
@ -630,8 +629,9 @@ void TurnServerAllocation::HandleTurnMessage(const TurnMessage* msg) {
break;
default:
// Not sure what to do with this, just eat it.
LOG_J(LS_WARNING, this) << "Invalid TURN message type received: "
<< msg->type();
RTC_LOG(LS_WARNING) << ToString()
<< ": Invalid TURN message type received: "
<< msg->type();
}
}
@ -653,7 +653,8 @@ void TurnServerAllocation::HandleAllocateRequest(const TurnMessage* msg) {
thread_->PostDelayed(RTC_FROM_HERE, lifetime_secs * 1000, this,
MSG_ALLOCATION_TIMEOUT);
LOG_J(LS_INFO, this) << "Created allocation, lifetime=" << lifetime_secs;
RTC_LOG(LS_INFO) << ToString()
<< ": Created allocation with lifetime=" << lifetime_secs;
// We've already validated all the important bits; just send a response here.
TurnMessage response;
@ -681,7 +682,8 @@ void TurnServerAllocation::HandleRefreshRequest(const TurnMessage* msg) {
thread_->PostDelayed(RTC_FROM_HERE, lifetime_secs * 1000, this,
MSG_ALLOCATION_TIMEOUT);
LOG_J(LS_INFO, this) << "Refreshed allocation, lifetime=" << lifetime_secs;
RTC_LOG(LS_INFO) << ToString()
<< ": Refreshed allocation, lifetime=" << lifetime_secs;
// Send a success response with a LIFETIME attribute.
TurnMessage response;
@ -700,7 +702,8 @@ void TurnServerAllocation::HandleSendIndication(const TurnMessage* msg) {
const StunAddressAttribute* peer_attr =
msg->GetAddress(STUN_ATTR_XOR_PEER_ADDRESS);
if (!data_attr || !peer_attr) {
LOG_J(LS_WARNING, this) << "Received invalid send indication";
RTC_LOG(LS_WARNING) << ToString()
<< ": Received invalid send indication";
return;
}
@ -709,8 +712,10 @@ void TurnServerAllocation::HandleSendIndication(const TurnMessage* msg) {
SendExternal(data_attr->bytes(), data_attr->length(),
peer_attr->GetAddress());
} else {
LOG_J(LS_WARNING, this) << "Received send indication without permission"
<< "peer=" << peer_attr->GetAddress();
RTC_LOG(LS_WARNING) << ToString()
<< ": Received send indication without permission"
" peer="
<< peer_attr->GetAddress();
}
}
@ -733,8 +738,8 @@ void TurnServerAllocation::HandleCreatePermissionRequest(
// Add this permission.
AddPermission(peer_attr->GetAddress().ipaddr());
LOG_J(LS_INFO, this) << "Created permission, peer="
<< peer_attr->GetAddress();
RTC_LOG(LS_INFO) << ToString()
<< ": Created permission, peer=" << peer_attr->GetAddress();
// Send a success response.
TurnMessage response;
@ -782,8 +787,9 @@ void TurnServerAllocation::HandleChannelBindRequest(const TurnMessage* msg) {
// Channel binds also refresh permissions.
AddPermission(peer_attr->GetAddress().ipaddr());
LOG_J(LS_INFO, this) << "Bound channel, id=" << channel_id
<< ", peer=" << peer_attr->GetAddress();
RTC_LOG(LS_INFO) << ToString()
<< ": Bound channel, id=" << channel_id
<< ", peer=" << peer_attr->GetAddress();
// Send a success response.
TurnMessage response;
@ -800,8 +806,9 @@ void TurnServerAllocation::HandleChannelData(const char* data, size_t size) {
SendExternal(data + TURN_CHANNEL_HEADER_SIZE,
size - TURN_CHANNEL_HEADER_SIZE, channel->peer());
} else {
LOG_J(LS_WARNING, this) << "Received channel data for invalid channel, id="
<< channel_id;
RTC_LOG(LS_WARNING) << ToString()
<< ": Received channel data for invalid channel, id="
<< channel_id;
}
}
@ -832,8 +839,9 @@ void TurnServerAllocation::OnExternalPacket(
rtc::MakeUnique<StunByteStringAttribute>(STUN_ATTR_DATA, data, size));
server_->SendStun(&conn_, &msg);
} else {
LOG_J(LS_WARNING, this) << "Received external packet without permission, "
<< "peer=" << addr;
RTC_LOG(LS_WARNING)
<< ToString()
<< ": Received external packet without permission, peer=" << addr;
}
}

28
p2p/client/basicportallocator.cc
View File

@ -17,7 +17,6 @@
#include "api/umametrics.h"
#include "p2p/base/basicpacketsocketfactory.h"
#include "p2p/base/common.h"
#include "p2p/base/port.h"
#include "p2p/base/relayport.h"
#include "p2p/base/stunport.h"
@ -843,7 +842,8 @@ void BasicPortAllocatorSession::AddAllocatedPort(Port* port,
&BasicPortAllocatorSession::OnPortDestroyed);
port->SignalPortError.connect(
this, &BasicPortAllocatorSession::OnPortError);
LOG_J(LS_INFO, port) << "Added port to allocator";
RTC_LOG(LS_INFO) << port->ToString()
<< ": Added port to allocator";
if (prepare_address)
port->PrepareAddress();
@ -860,7 +860,8 @@ void BasicPortAllocatorSession::OnCandidateReady(
RTC_DCHECK(rtc::Thread::Current() == network_thread_);
PortData* data = FindPort(port);
RTC_DCHECK(data != NULL);
LOG_J(LS_INFO, port) << "Gathered candidate: " << c.ToSensitiveString();
RTC_LOG(LS_INFO) << port->ToString()
<< ": Gathered candidate: " << c.ToSensitiveString();
// Discarding any candidate signal if port allocation status is
// already done with gathering.
if (!data->inprogress()) {
@ -887,7 +888,7 @@ void BasicPortAllocatorSession::OnCandidateReady(
}
// If the current port is not pruned yet, SignalPortReady.
if (!data->pruned()) {
LOG_J(LS_INFO, port) << "Port ready.";
RTC_LOG(LS_INFO) << port->ToString() << ": Port ready.";
SignalPortReady(this, port);
port->KeepAliveUntilPruned();
}
@ -961,7 +962,8 @@ void BasicPortAllocatorSession::PruneAllPorts() {
void BasicPortAllocatorSession::OnPortComplete(Port* port) {
RTC_DCHECK(rtc::Thread::Current() == network_thread_);
LOG_J(LS_INFO, port) << "Port completed gathering candidates.";
RTC_LOG(LS_INFO) << port->ToString()
<< ": Port completed gathering candidates.";
PortData* data = FindPort(port);
RTC_DCHECK(data != NULL);
@ -978,7 +980,8 @@ void BasicPortAllocatorSession::OnPortComplete(Port* port) {
void BasicPortAllocatorSession::OnPortError(Port* port) {
RTC_DCHECK(rtc::Thread::Current() == network_thread_);
LOG_J(LS_INFO, port) << "Port encountered error while gathering candidates.";
RTC_LOG(LS_INFO) << port->ToString()
<< ": Port encountered error while gathering candidates.";
PortData* data = FindPort(port);
RTC_DCHECK(data != NULL);
// We might have already given up on this port and stopped it.
@ -1069,8 +1072,9 @@ void BasicPortAllocatorSession::OnPortDestroyed(
iter != ports_.end(); ++iter) {
if (port == iter->port()) {
ports_.erase(iter);
LOG_J(LS_INFO, port) << "Removed port from allocator ("
<< static_cast<int>(ports_.size()) << " remaining)";
RTC_LOG(LS_INFO) << port->ToString()
<< ": Removed port from allocator ("
<< static_cast<int>(ports_.size()) << " remaining)";
return;
}
}
@ -1251,8 +1255,8 @@ void AllocationSequence::OnMessage(rtc::Message* msg) {
const char* const PHASE_NAMES[kNumPhases] = {"Udp", "Relay", "Tcp"};
// Perform all of the phases in the current step.
LOG_J(LS_INFO, network_) << "Allocation Phase="
<< PHASE_NAMES[phase_];
RTC_LOG(LS_INFO) << network_->ToString()
<< ": Allocation Phase=" << PHASE_NAMES[phase_];
switch (phase_) {
case PHASE_UDP:
@ -1324,7 +1328,7 @@ void AllocationSequence::CreateUDPPorts() {
if (config_ && !config_->StunServers().empty()) {
RTC_LOG(LS_INFO)
<< "AllocationSequence: UDPPort will be handling the "
<< "STUN candidate generation.";
"STUN candidate generation.";
port->set_server_addresses(config_->StunServers());
}
}
@ -1455,7 +1459,7 @@ void AllocationSequence::CreateTurnPort(const RelayServerConfig& config) {
if (server_ip_family != AF_UNSPEC && server_ip_family != local_ip_family) {
RTC_LOG(LS_INFO)
<< "Server and local address families are not compatible. "
<< "Server address: " << relay_port->address.ipaddr().ToString()
"Server address: " << relay_port->address.ipaddr().ToString()
<< " Local address: " << network_->GetBestIP().ToString();
continue;
}