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

Improve text logs in the network stack.

Browse Source 
1) Network info is appended with its network ID assigned by the network
manager so that we can cross-reference networks by IDs in the log.
2) The local network info is added to the candidate pair string
representation so that we do not need the cross reference to the
logs of candidate gathering to find out the network where the local
candidate is from.
3) A flag is added to the candidate pair string representation to
indicate if this pair is the selected one.
4) Sorting of candidate pairs is logged with the reason of sorting
request.
5) Network filtering that takes place in the port allocator is
explicitly logged.

Bug: None
Change-Id: Iaa337394cad803515e26e254814aa04ed2213eab
Reviewed-on: https://webrtc-review.googlesource.com/72522
Commit-Queue: Qingsi Wang <qingsi@google.com>
Reviewed-by: Taylor Brandstetter <deadbeef@webrtc.org>
Cr-Commit-Position: refs/heads/master@{#23266}
This commit is contained in:
Qingsi Wang 2018-05-16 13:37:03 -07:00 committed by Commit Bot
parent 90e3fbdd37
commit 10a0e516bf
7 changed files with 121 additions and 49 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

61
p2p/base/p2ptransportchannel.cc
View File

@ -42,6 +42,12 @@ enum {
// The minimum improvement in RTT that justifies a switch.
const int kMinImprovement = 10;
struct SortCandidatePairRequest : public rtc::MessageData {
explicit SortCandidatePairRequest(const std::string& reason_to_sort)
: reason_to_sort(reason_to_sort) {}
const std::string reason_to_sort;
};
bool IsRelayRelay(const cricket::Connection* conn) {
return conn->local_candidate().type() == cricket::RELAY_PORT_TYPE &&
conn->remote_candidate().type() == cricket::RELAY_PORT_TYPE;
@ -258,7 +264,7 @@ bool P2PTransportChannel::MaybeSwitchSelectedConnection(
bool missed_receiving_unchanged_threshold = false;
if (ShouldSwitchSelectedConnection(new_connection,
&missed_receiving_unchanged_threshold)) {
RTC_LOG(LS_INFO) << "Switching selected connection due to " << reason;
RTC_LOG(LS_INFO) << "Switching selected connection due to: " << reason;
SwitchSelectedConnection(new_connection);
return true;
}
@ -268,9 +274,12 @@ bool P2PTransportChannel::MaybeSwitchSelectedConnection(
// threshold, the new connection is in a better receiving state than the
// currently selected connection. So we need to re-check whether it needs
// to be switched at a later time.
std::unique_ptr<SortCandidatePairRequest> request_message(
new SortCandidatePairRequest(reason +
" (after switching dampening interval)"));
thread()->PostDelayed(RTC_FROM_HERE,
config_.receiving_switching_delay_or_default(), this,
MSG_SORT_AND_UPDATE_STATE);
MSG_SORT_AND_UPDATE_STATE, request_message.release());
}
return false;
}
@ -410,7 +419,7 @@ void P2PTransportChannel::SetRemoteIceParameters(
ice_params, static_cast<int>(remote_ice_parameters_.size() - 1));
}
// Updating the remote ICE candidate generation could change the sort order.
RequestSortAndStateUpdate();
RequestSortAndStateUpdate("remote candidate generation maybe changed");
}
void P2PTransportChannel::SetRemoteIceMode(IceMode mode) {
@ -502,7 +511,7 @@ void P2PTransportChannel::SetIceConfig(const IceConfig& config) {
if (config_.receiving_switching_delay != config.receiving_switching_delay) {
config_.receiving_switching_delay = config.receiving_switching_delay;
RTC_LOG(LS_INFO) << "Set receiving_switching_delay to"
RTC_LOG(LS_INFO) << "Set receiving_switching_delay to "
<< config_.receiving_switching_delay_or_default();
}
@ -556,7 +565,7 @@ void P2PTransportChannel::SetIceConfig(const IceConfig& config) {
if (config_.network_preference != config.network_preference) {
config_.network_preference = config.network_preference;
RequestSortAndStateUpdate();
RequestSortAndStateUpdate("network preference changed");
RTC_LOG(LS_INFO) << "Set network preference to "
<< (config_.network_preference.has_value()
? config_.network_preference.value()
@ -742,7 +751,8 @@ void P2PTransportChannel::OnPortReady(PortAllocatorSession *session,
CreateConnection(port, *iter, iter->origin_port());
}
SortConnectionsAndUpdateState();
SortConnectionsAndUpdateState(
"new candidate pairs created from a new local candidate");
}
// A new candidate is available, let listeners know
@ -893,7 +903,8 @@ void P2PTransportChannel::OnUnknownAddress(
// Update the list of connections since we just added another. We do this
// after sending the response since it could (in principle) delete the
// connection in question.
SortConnectionsAndUpdateState();
SortConnectionsAndUpdateState(
"a new candidate pair created from an unknown remote address");
}
void P2PTransportChannel::OnRoleConflict(PortInterface* port) {
@ -924,11 +935,13 @@ void P2PTransportChannel::OnNominated(Connection* conn) {
return;
}
// TODO(qingsi): RequestSortAndStateUpdate will eventually call
// MaybeSwitchSelectedConnection again. Rewrite this logic.
if (MaybeSwitchSelectedConnection(conn,
"nomination on the controlled side")) {
// Now that we have selected a connection, it is time to prune other
// connections and update the read/write state of the channel.
RequestSortAndStateUpdate();
RequestSortAndStateUpdate("nomination on the controlled side");
} else {
RTC_LOG(LS_INFO)
<< "Not switching the selected connection on controlled side yet: "
@ -981,7 +994,8 @@ void P2PTransportChannel::AddRemoteCandidate(const Candidate& candidate) {
CreateConnections(new_remote_candidate, NULL);
// Resort the connections list, which may have new elements.
SortConnectionsAndUpdateState();
SortConnectionsAndUpdateState(
"new candidate pairs created from a new remote candidate");
}
void P2PTransportChannel::RemoveRemoteCandidate(
@ -1264,9 +1278,13 @@ void P2PTransportChannel::UpdateConnectionStates() {
}
// Prepare for best candidate sorting.
void P2PTransportChannel::RequestSortAndStateUpdate() {
void P2PTransportChannel::RequestSortAndStateUpdate(
const std::string& reason_to_sort) {
if (!sort_dirty_) {
network_thread_->Post(RTC_FROM_HERE, this, MSG_SORT_AND_UPDATE_STATE);
std::unique_ptr<SortCandidatePairRequest> request_message(
new SortCandidatePairRequest(reason_to_sort));
network_thread_->Post(RTC_FROM_HERE, this, MSG_SORT_AND_UPDATE_STATE,
request_message.release());
sort_dirty_ = true;
}
}
@ -1501,7 +1519,8 @@ bool P2PTransportChannel::PresumedWritable(const Connection* conn) const {
// Sort the available connections to find the best one. We also monitor
// the number of available connections and the current state.
void P2PTransportChannel::SortConnectionsAndUpdateState() {
void P2PTransportChannel::SortConnectionsAndUpdateState(
const std::string& reason_to_sort) {
RTC_DCHECK(network_thread_ == rtc::Thread::Current());
// Make sure the connection states are up-to-date since this affects how they
@ -1538,7 +1557,7 @@ void P2PTransportChannel::SortConnectionsAndUpdateState() {
// If necessary, switch to the new choice. Note that |top_connection| doesn't
// have to be writable to become the selected connection although it will
// have higher priority if it is writable.
MaybeSwitchSelectedConnection(top_connection, "sorting");
MaybeSwitchSelectedConnection(top_connection, reason_to_sort);
// The controlled side can prune only if the selected connection has been
// nominated because otherwise it may prune the connection that will be
@ -1651,8 +1670,12 @@ void P2PTransportChannel::SwitchSelectedConnection(Connection* conn) {
selected_connection_ = conn;
LogCandidatePairEvent(conn, webrtc::IceCandidatePairEventType::kSelected);
network_route_.reset();
if (old_selected_connection) {
old_selected_connection->set_selected(false);
}
if (selected_connection_) {
++nomination_;
selected_connection_->set_selected(true);
if (old_selected_connection) {
RTC_LOG(LS_INFO) << ToString()
<< ": Previous selected connection: "
@ -1801,9 +1824,13 @@ bool P2PTransportChannel::ReadyToSend(Connection* connection) const {
// Handle any queued up requests
void P2PTransportChannel::OnMessage(rtc::Message *pmsg) {
switch (pmsg->message_id) {
case MSG_SORT_AND_UPDATE_STATE:
SortConnectionsAndUpdateState();
case MSG_SORT_AND_UPDATE_STATE: {
RTC_DCHECK(pmsg->pdata);
std::unique_ptr<SortCandidatePairRequest> request_message(
static_cast<SortCandidatePairRequest*>(pmsg->pdata));
SortConnectionsAndUpdateState(request_message->reason_to_sort);
break;
}
case MSG_CHECK_AND_PING:
OnCheckAndPing();
break;
@ -2106,7 +2133,7 @@ void P2PTransportChannel::OnConnectionStateChange(Connection* connection) {
// We have to unroll the stack before doing this because we may be changing
// the state of connections while sorting.
RequestSortAndStateUpdate();
RequestSortAndStateUpdate("candidate pair state changed");
}
// When a connection is removed, edit it out, and then update our best
@ -2138,7 +2165,7 @@ void P2PTransportChannel::OnConnectionDestroyed(Connection* connection) {
if (selected_connection_ == connection) {
RTC_LOG(LS_INFO) << "Selected connection destroyed. Will choose a new one.";
SwitchSelectedConnection(nullptr);
RequestSortAndStateUpdate();
RequestSortAndStateUpdate("selected candidate pair destroyed");
} else {
// If a non-selected connection was destroyed, we don't need to re-sort but
// we do need to update state, because we could be switching to "failed" or

4
p2p/base/p2ptransportchannel.h
View File

@ -190,7 +190,7 @@ class P2PTransportChannel : public IceTransportInternal,
// Returns true if it's possible to send packets on |connection|.
bool ReadyToSend(Connection* connection) const;
void UpdateConnectionStates();
void RequestSortAndStateUpdate();
void RequestSortAndStateUpdate(const std::string& reason_to_sort);
// Start pinging if we haven't already started, and we now have a connection
// that's pingable.
void MaybeStartPinging();
@ -226,7 +226,7 @@ class P2PTransportChannel : public IceTransportInternal,
bool PresumedWritable(const cricket::Connection* conn) const;
void SortConnectionsAndUpdateState();
void SortConnectionsAndUpdateState(const std::string& reason_to_sort);
void SwitchSelectedConnection(Connection* conn);
void UpdateState();
void HandleAllTimedOut();

23
p2p/base/port.cc
View File

@ -1580,19 +1580,24 @@ std::string Connection::ToString() const {
"S", // STATE_SUCCEEDED
"F" // STATE_FAILED
};
const std::string SELECTED_STATE_ABBREV[2] = {
"-", // candidate pair not selected (false)
"S", // selected (true)
};
const Candidate& local = local_candidate();
const Candidate& remote = remote_candidate();
std::stringstream ss;
ss << "Conn[" << ToDebugId() << ":" << port_->content_name() << ":"
<< local.id() << ":" << local.component() << ":" << local.generation()
<< ":" << local.type() << ":" << local.protocol() << ":"
<< local.address().ToSensitiveString() << "->" << remote.id() << ":"
<< remote.component() << ":" << remote.priority() << ":" << remote.type()
<< ":" << remote.protocol() << ":" << remote.address().ToSensitiveString()
<< "|" << CONNECT_STATE_ABBREV[connected()]
<< RECEIVE_STATE_ABBREV[receiving()] << WRITE_STATE_ABBREV[write_state()]
<< ICESTATE[static_cast<int>(state())] << "|" << remote_nomination() << "|"
<< nomination() << "|" << priority() << "|";
<< port_->Network()->ToString() << ":" << local.id() << ":"
<< local.component() << ":" << local.generation() << ":" << local.type()
<< ":" << local.protocol() << ":" << local.address().ToSensitiveString()
<< "->" << remote.id() << ":" << remote.component() << ":"
<< remote.priority() << ":" << remote.type() << ":" << remote.protocol()
<< ":" << remote.address().ToSensitiveString() << "|"
<< CONNECT_STATE_ABBREV[connected()] << RECEIVE_STATE_ABBREV[receiving()]
<< WRITE_STATE_ABBREV[write_state()] << ICESTATE[static_cast<int>(state())]
<< "|" << SELECTED_STATE_ABBREV[selected()] << "|" << remote_nomination()
<< "|" << nomination() << "|" << priority() << "|";
if (rtt_ < DEFAULT_RTT) {
ss << rtt_ << "]";
} else {

6
p2p/base/port.h
View File

@ -679,6 +679,11 @@ class Connection : public CandidatePairInterface,
bool reported() const { return reported_; }
void set_reported(bool reported) { reported_ = reported;}
// The following two methods are only used for logging in ToString above, and
// this flag is set true by P2PTransportChannel for its selected candidate
// pair.
bool selected() const { return selected_; }
void set_selected(bool selected) { selected_ = selected; }
// This signal will be fired if this connection is nominated by the
// controlling side.
@ -769,6 +774,7 @@ class Connection : public CandidatePairInterface,
bool receiving_;
bool connected_;
bool pruned_;
bool selected_ = false;
// By default |use_candidate_attr_| flag will be true,
// as we will be using aggressive nomination.
// But when peer is ice-lite, this flag "must" be initialized to false and

56
p2p/client/basicportallocator.cc
View File

@ -11,6 +11,7 @@
#include "p2p/client/basicportallocator.h"
#include <algorithm>
#include <functional>
#include <set>
#include <string>
#include <vector>
@ -88,6 +89,28 @@ int ComparePort(const cricket::Port* a, const cricket::Port* b) {
return a_family - b_family;
}
struct NetworkFilter {
using Predicate = std::function<bool(rtc::Network*)>;
NetworkFilter(Predicate pred, const std::string& description)
: pred(pred), description(description) {}
Predicate pred;
const std::string description;
};
using NetworkList = rtc::NetworkManager::NetworkList;
void FilterNetworks(NetworkList* networks, NetworkFilter filter) {
auto start_to_remove =
std::remove_if(networks->begin(), networks->end(), filter.pred);
if (start_to_remove == networks->end()) {
return;
}
RTC_LOG(INFO) << "Filtered out " << filter.description << " networks:";
for (auto it = start_to_remove; it != networks->end(); ++it) {
RTC_LOG(INFO) << (*it)->ToString();
}
networks->erase(start_to_remove, networks->end());
}
} // namespace
namespace cricket {
@ -653,20 +676,19 @@ std::vector<rtc::Network*> BasicPortAllocatorSession::GetNetworks() {
}
// Filter out link-local networks if needed.
if (flags() & PORTALLOCATOR_DISABLE_LINK_LOCAL_NETWORKS) {
networks.erase(std::remove_if(networks.begin(), networks.end(),
[](rtc::Network* network) {
return IPIsLinkLocal(network->prefix());
}),
networks.end());
NetworkFilter link_local_filter(
[](rtc::Network* network) { return IPIsLinkLocal(network->prefix()); },
"link-local");
FilterNetworks(&networks, link_local_filter);
}
// Do some more filtering, depending on the network ignore mask and "disable
// costly networks" flag.
networks.erase(std::remove_if(networks.begin(), networks.end(),
[this](rtc::Network* network) {
return allocator_->network_ignore_mask() &
network->type();
}),
networks.end());
NetworkFilter ignored_filter(
[this](rtc::Network* network) {
return allocator_->network_ignore_mask() & network->type();
},
"ignored");
FilterNetworks(&networks, ignored_filter);
if (flags() & PORTALLOCATOR_DISABLE_COSTLY_NETWORKS) {
uint16_t lowest_cost = rtc::kNetworkCostMax;
for (rtc::Network* network : networks) {
@ -679,12 +701,12 @@ std::vector<rtc::Network*> BasicPortAllocatorSession::GetNetworks() {
}
lowest_cost = std::min<uint16_t>(lowest_cost, network->GetCost());
}
networks.erase(std::remove_if(networks.begin(), networks.end(),
[lowest_cost](rtc::Network* network) {
return network->GetCost() >
lowest_cost + rtc::kNetworkCostLow;
}),
networks.end());
NetworkFilter costly_filter(
[lowest_cost](rtc::Network* network) {
return network->GetCost() > lowest_cost + rtc::kNetworkCostLow;
},
"costly");
FilterNetworks(&networks, costly_filter);
}
// Lastly, if we have a limit for the number of IPv6 network interfaces (by
// default, it's 5), remove networks to ensure that limit is satisfied.

2
rtc_base/network.cc
View File

@ -1041,7 +1041,7 @@ std::string Network::ToString() const {
if (IsVpn()) {
ss << "/" << AdapterTypeToString(underlying_type_for_vpn_);
}
ss << "]";
ss << ":id=" << id_ << "]";
return ss.str();
}

18
rtc_base/network_unittest.cc
View File

@ -61,6 +61,18 @@ class FakeNetworkMonitorFactory : public NetworkMonitorFactory {
}
};
bool SameNameAndPrefix(const rtc::Network& a, const rtc::Network& b) {
if (a.name() != b.name()) {
RTC_LOG(INFO) << "Different interface names.";
return false;
}
if (a.prefix_length() != b.prefix_length() || a.prefix() != b.prefix()) {
RTC_LOG(INFO) << "Different IP prefixes.";
return false;
}
return true;
}
} // namespace
class NetworkTest : public testing::Test, public sigslot::has_slots<> {
@ -320,7 +332,7 @@ TEST_F(NetworkTest, TestBasicMergeNetworkList) {
manager.GetNetworks(&list);
EXPECT_EQ(1U, list.size());
EXPECT_EQ(ipv4_network1.ToString(), list[0]->ToString());
EXPECT_TRUE(SameNameAndPrefix(ipv4_network1, *list[0]));
Network* net1 = list[0];
uint16_t net_id1 = net1->id();
EXPECT_EQ(1, net_id1);
@ -336,7 +348,7 @@ TEST_F(NetworkTest, TestBasicMergeNetworkList) {
manager.GetNetworks(&list);
EXPECT_EQ(1U, list.size());
EXPECT_EQ(ipv4_network2.ToString(), list[0]->ToString());
EXPECT_TRUE(SameNameAndPrefix(ipv4_network2, *list[0]));
Network* net2 = list[0];
uint16_t net_id2 = net2->id();
// Network id will increase.
@ -544,7 +556,7 @@ TEST_F(NetworkTest, TestMultipleIPMergeNetworkList) {
int matchcount = 0;
for (NetworkManager::NetworkList::iterator it = list.begin();
it != list.end(); ++it) {
if ((*it)->ToString() == original_list[2]->ToString()) {
if (SameNameAndPrefix(**it, *original_list[2])) {
++matchcount;
EXPECT_EQ(1, matchcount);
// This should be the same network object as before.