From d7d762d08d690f741942528e62b4a759a520c390 Mon Sep 17 00:00:00 2001 From: Jonas Olsson Date: Wed, 28 Mar 2018 09:47:51 +0200 Subject: [PATCH] Remove LOG_J and LOG_JV, tweak p2p logs. Bug: webrtc:9077 Change-Id: I54ecf10592add33692fc6e694c2f10a646e81345 Reviewed-on: https://webrtc-review.googlesource.com/56142 Reviewed-by: Fredrik Solenberg Reviewed-by: Taylor Brandstetter Reviewed-by: Qingsi Wang Reviewed-by: Karl Wiberg Commit-Queue: Jonas Olsson Cr-Commit-Position: refs/heads/master@{#22667} --- p2p/BUILD.gn | 1 - p2p/base/common.h | 20 -- p2p/base/dtlstransport.cc | 129 +++++---- p2p/base/p2ptransportchannel.cc | 71 ++--- p2p/base/p2ptransportchannel_unittest.cc | 8 +- p2p/base/port.cc | 243 ++++++++-------- p2p/base/portallocator.cc | 3 +- p2p/base/pseudotcp_unittest.cc | 4 +- p2p/base/relayport.cc | 7 +- p2p/base/stun.cc | 2 +- p2p/base/stunport.cc | 24 +- p2p/base/tcpport.cc | 57 ++-- p2p/base/transportdescriptionfactory.cc | 2 +- p2p/base/turnport.cc | 336 +++++++++++++---------- p2p/base/turnserver.cc | 42 +-- p2p/client/basicportallocator.cc | 28 +- 16 files changed, 548 insertions(+), 429 deletions(-) delete mode 100644 p2p/base/common.h diff --git a/p2p/BUILD.gn b/p2p/BUILD.gn index c38f850cb1..769bd4b209 100644 --- a/p2p/BUILD.gn +++ b/p2p/BUILD.gn @@ -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", diff --git a/p2p/base/common.h b/p2p/base/common.h deleted file mode 100644 index aa5da42d8e..0000000000 --- a/p2p/base/common.h +++ /dev/null @@ -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_ diff --git a/p2p/base/dtlstransport.cc b/p2p/base/dtlstransport.cc index d1c3fec77c..e17d5c375d 100644 --- a/p2p/base/dtlstransport.cc +++ b/p2p/base/dtlstransport.cc @@ -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 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(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(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(), 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"; } } diff --git a/p2p/base/p2ptransportchannel.cc b/p2p/base/p2ptransportchannel.cc index 088c405538..804cab153c 100644 --- a/p2p/base/p2ptransportchannel.cc +++ b/p2p/base/p2ptransportchannel.cc @@ -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(state_) << " to " - << static_cast(state); + RTC_LOG(LS_INFO) << ToString() + << ": Transport channel state changed from " + << static_cast(state_) << " to " + << static_cast(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); diff --git a/p2p/base/p2ptransportchannel_unittest.cc b/p2p/base/p2ptransportchannel_unittest.cc index 45662ae8e7..2b0efacc2d 100644 --- a/p2p/base/p2ptransportchannel_unittest.cc +++ b/p2p/base/p2ptransportchannel_unittest.cc @@ -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. diff --git a/p2p/base/port.cc b/p2p/base/port.cc index cfecf7f4f2..7d3c719e47 100644 --- a/p2p/base/port.cc +++ b/p2p/base/port.cc @@ -16,7 +16,6 @@ #include #include -#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 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(std::hash{}(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 diff --git a/p2p/base/portallocator.cc b/p2p/base/portallocator.cc index 2b9b183f01..e766fa732c 100644 --- a/p2p/base/portallocator.cc +++ b/p2p/base/portallocator.cc @@ -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; diff --git a/p2p/base/pseudotcp_unittest.cc b/p2p/base/pseudotcp_unittest.cc index fb9a503455..f6b46ccc6a 100644 --- a/p2p/base/pseudotcp_unittest.cc +++ b/p2p/base/pseudotcp_unittest.cc @@ -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); diff --git a/p2p/base/relayport.cc b/p2p/base/relayport.cc index a789a1b16b..52416ca72c 100644 --- a/p2p/base/relayport.cc +++ b/p2p/base/relayport.cc @@ -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) diff --git a/p2p/base/stun.cc b/p2p/base/stun.cc index 50b6b44803..2bedde07a2 100644 --- a/p2p/base/stun.cc +++ b/p2p/base/stun.cc @@ -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; } diff --git a/p2p/base/stunport.cc b/p2p/base/stunport.cc index 8deea1c92d..1a6db168ff 100644 --- a/p2p/base/stunport.cc +++ b/p2p/base/stunport.cc @@ -13,7 +13,6 @@ #include #include -#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; } diff --git a/p2p/base/tcpport.cc b/p2p/base/tcpport.cc index a8bda95950..45acfc7ecc 100644 --- a/p2p/base/tcpport.cc +++ b/p2p/base/tcpport.cc @@ -68,7 +68,6 @@ #include -#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& 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(); } } diff --git a/p2p/base/transportdescriptionfactory.cc b/p2p/base/transportdescriptionfactory.cc index d5f8561b6b..5924a9379d 100644 --- a/p2p/base/transportdescriptionfactory.cc +++ b/p2p/base/transportdescriptionfactory.cc @@ -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; } diff --git a/p2p/base/turnport.cc b/p2p/base/turnport.cc index e718bb19de..fa3bc17c6e 100644 --- a/p2p/base/turnport.cc +++ b/p2p/base/turnport.cc @@ -16,7 +16,6 @@ #include #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; } diff --git a/p2p/base/turnserver.cc b/p2p/base/turnserver.cc index 902e889057..aa5b5ed648 100644 --- a/p2p/base/turnserver.cc +++ b/p2p/base/turnserver.cc @@ -14,7 +14,6 @@ #include #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(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; } } diff --git a/p2p/client/basicportallocator.cc b/p2p/client/basicportallocator.cc index 01acf42cdd..1b3947b6cf 100644 --- a/p2p/client/basicportallocator.cc +++ b/p2p/client/basicportallocator.cc @@ -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(ports_.size()) << " remaining)"; + RTC_LOG(LS_INFO) << port->ToString() + << ": Removed port from allocator (" + << static_cast(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; }