From d9489878a07199cce2971ad4ad82ef2828d11515 Mon Sep 17 00:00:00 2001 From: Alden Torres Date: Fri, 16 Sep 2016 08:21:07 -0400 Subject: [PATCH] rpc_manager log optimization and minor refactor (#1095) more on log optimization --- include/libtorrent/kademlia/msg.hpp | 1 + include/libtorrent/udp_socket.hpp | 7 +++ src/kademlia/rpc_manager.cpp | 72 ++++++++++++++++++----------- src/session_impl.cpp | 43 ++++++++--------- 4 files changed, 71 insertions(+), 52 deletions(-) diff --git a/include/libtorrent/kademlia/msg.hpp b/include/libtorrent/kademlia/msg.hpp index c2ba86b57..fc63ee329 100644 --- a/include/libtorrent/kademlia/msg.hpp +++ b/include/libtorrent/kademlia/msg.hpp @@ -51,6 +51,7 @@ typedef std::vector peers_t; struct msg { msg(bdecode_node const& m, udp::endpoint const& ep): message(m), addr(ep) {} + // the message bdecode_node const& message; diff --git a/include/libtorrent/udp_socket.hpp b/include/libtorrent/udp_socket.hpp index d3913535d..697b02023 100644 --- a/include/libtorrent/udp_socket.hpp +++ b/include/libtorrent/udp_socket.hpp @@ -100,6 +100,13 @@ namespace libtorrent bool is_closed() const { return m_abort; } udp::endpoint local_endpoint(error_code& ec) const { return m_socket.local_endpoint(ec); } + // best effort, if you want to know the error, use + // ``local_endpoint(error_code& ec)`` + udp::endpoint local_endpoint() const + { + error_code ec; + return local_endpoint(ec); + } typedef udp::socket::receive_buffer_size receive_buffer_size; typedef udp::socket::send_buffer_size send_buffer_size; diff --git a/src/kademlia/rpc_manager.cpp b/src/kademlia/rpc_manager.cpp index 445354cdf..e4bdf7f64 100644 --- a/src/kademlia/rpc_manager.cpp +++ b/src/kademlia/rpc_manager.cpp @@ -209,8 +209,11 @@ void rpc_manager::check_invariant() const void rpc_manager::unreachable(udp::endpoint const& ep) { #ifndef TORRENT_DISABLE_LOGGING - m_log->log(dht_logger::rpc_manager, "PORT_UNREACHABLE [ ip: %s ]" - , print_endpoint(ep).c_str()); + if (m_log->should_log(dht_logger::rpc_manager)) + { + m_log->log(dht_logger::rpc_manager, "PORT_UNREACHABLE [ ip: %s ]" + , print_endpoint(ep).c_str()); + } #endif for (auto i = m_transactions.begin(); i != m_transactions.end();) @@ -261,7 +264,7 @@ bool rpc_manager::incoming(msg const& m, node_id* id) if (!o) { #ifndef TORRENT_DISABLE_LOGGING - if (m_table.native_endpoint(m.addr)) + if (m_table.native_endpoint(m.addr) && m_log->should_log(dht_logger::rpc_manager)) { m_log->log(dht_logger::rpc_manager, "reply with unknown transaction id size: %d from %s" , int(transaction_id.size()), print_endpoint(m.addr).c_str()); @@ -281,28 +284,34 @@ bool rpc_manager::incoming(msg const& m, node_id* id) time_point now = clock_type::now(); #ifndef TORRENT_DISABLE_LOGGING - m_log->log(dht_logger::rpc_manager, "round trip time(ms): %" PRId64 " from %s" - , total_milliseconds(now - o->sent()), print_endpoint(m.addr).c_str()); + if (m_log->should_log(dht_logger::rpc_manager)) + { + m_log->log(dht_logger::rpc_manager, "round trip time(ms): %" PRId64 " from %s" + , total_milliseconds(now - o->sent()), print_endpoint(m.addr).c_str()); + } #endif if (m.message.dict_find_string_value("y") == "e") { // It's an error. #ifndef TORRENT_DISABLE_LOGGING - bdecode_node err = m.message.dict_find_list("e"); - if (err && err.list_size() >= 2 - && err.list_at(0).type() == bdecode_node::int_t - && err.list_at(1).type() == bdecode_node::string_t) + if (m_log->should_log(dht_logger::rpc_manager)) { - m_log->log(dht_logger::rpc_manager, "reply with error from %s: (%" PRId64 ") %s" - , print_endpoint(m.addr).c_str() - , err.list_int_value_at(0) - , err.list_string_value_at(1).to_string().c_str()); - } - else - { - m_log->log(dht_logger::rpc_manager, "reply with (malformed) error from %s" - , print_endpoint(m.addr).c_str()); + bdecode_node err = m.message.dict_find_list("e"); + if (err && err.list_size() >= 2 + && err.list_at(0).type() == bdecode_node::int_t + && err.list_at(1).type() == bdecode_node::string_t) + { + m_log->log(dht_logger::rpc_manager, "reply with error from %s: (%" PRId64 ") %s" + , print_endpoint(m.addr).c_str() + , err.list_int_value_at(0) + , err.list_string_value_at(1).to_string().c_str()); + } + else + { + m_log->log(dht_logger::rpc_manager, "reply with (malformed) error from %s" + , print_endpoint(m.addr).c_str()); + } } #endif // Logically, we should call o->reply(m) since we get a reply. @@ -340,9 +349,12 @@ bool rpc_manager::incoming(msg const& m, node_id* id) } #ifndef TORRENT_DISABLE_LOGGING - m_log->log(dht_logger::rpc_manager, "[%p] reply with transaction id: %d from %s" - , static_cast(o->algorithm()), int(transaction_id.size()) - , print_endpoint(m.addr).c_str()); + if (m_log->should_log(dht_logger::rpc_manager)) + { + m_log->log(dht_logger::rpc_manager, "[%p] reply with transaction id: %d from %s" + , static_cast(o->algorithm()), int(transaction_id.size()) + , print_endpoint(m.addr).c_str()); + } #endif o->reply(m); *id = nid; @@ -379,9 +391,12 @@ time_duration rpc_manager::tick() if (diff >= seconds(timeout)) { #ifndef TORRENT_DISABLE_LOGGING - m_log->log(dht_logger::rpc_manager, "[%p] timing out transaction id: %d from: %s" - , static_cast(o->algorithm()), o->transaction_id() - , print_endpoint(o->target_ep()).c_str()); + if (m_log->should_log(dht_logger::rpc_manager)) + { + m_log->log(dht_logger::rpc_manager, "[%p] timing out transaction id: %d from: %s" + , static_cast(o->algorithm()), o->transaction_id() + , print_endpoint(o->target_ep()).c_str()); + } #endif m_transactions.erase(i++); timeouts.push_back(o); @@ -393,9 +408,12 @@ time_duration rpc_manager::tick() if (diff >= seconds(short_timeout) && !o->has_short_timeout()) { #ifndef TORRENT_DISABLE_LOGGING - m_log->log(dht_logger::rpc_manager, "[%p] short-timing out transaction id: %d from: %s" - , static_cast(o->algorithm()), o->transaction_id() - , print_endpoint(o->target_ep()).c_str()); + if (m_log->should_log(dht_logger::rpc_manager)) + { + m_log->log(dht_logger::rpc_manager, "[%p] short-timing out transaction id: %d from: %s" + , static_cast(o->algorithm()), o->transaction_id() + , print_endpoint(o->target_ep()).c_str()); + } #endif ++i; diff --git a/src/session_impl.cpp b/src/session_impl.cpp index c4671c282..678ff5393 100644 --- a/src/session_impl.cpp +++ b/src/session_impl.cpp @@ -1983,9 +1983,8 @@ namespace aux { void session_impl::remap_ports(remap_port_mask_t const mask , listen_socket_t& s) { - error_code ec; - tcp::endpoint const tcp_ep = s.sock ? s.sock->local_endpoint(ec) : tcp::endpoint(); - udp::endpoint const udp_ep = s.udp_sock ? s.udp_sock->local_endpoint(ec) : udp::endpoint(); + tcp::endpoint const tcp_ep = s.sock ? s.sock->local_endpoint() : tcp::endpoint(); + udp::endpoint const udp_ep = s.udp_sock ? s.udp_sock->local_endpoint() : udp::endpoint(); if ((mask & remap_natpmp) && m_natpmp) { @@ -2277,8 +2276,7 @@ namespace aux { { std::shared_ptr s = socket.lock(); udp::endpoint ep; - error_code best_effort; - if (s) ep = s->local_endpoint(best_effort); + if (s) ep = s->local_endpoint(); // don't bubble up operation aborted errors to the user if (ec != boost::asio::error::operation_aborted @@ -2364,8 +2362,7 @@ namespace aux { if (err) { - error_code best_effort; - udp::endpoint ep = s->local_endpoint(best_effort); + udp::endpoint const ep = s->local_endpoint(); if (err != boost::asio::error::operation_aborted && m_alerts.should_post()) @@ -6009,31 +6006,28 @@ namespace aux { void session_impl::update_peer_tos() { int const tos = m_settings.get_int(settings_pack::peer_tos); - for (std::list::iterator i = m_listen_sockets.begin() - , end(m_listen_sockets.end()); i != end; ++i) + for (auto const& l : m_listen_sockets) { error_code ec; - set_tos(*i->sock, tos, ec); + set_tos(*l.sock, tos, ec); #ifndef TORRENT_DISABLE_LOGGING if (should_log()) { - error_code err; session_log(">>> SET_TOS [ tcp (%s %d) tos: %x e: %s ]" - , i->sock->local_endpoint(err).address().to_string().c_str() - , i->sock->local_endpoint(err).port(), tos, ec.message().c_str()); + , l.sock->local_endpoint().address().to_string().c_str() + , l.sock->local_endpoint().port(), tos, ec.message().c_str()); } #endif ec.clear(); - set_tos(*i->udp_sock, tos, ec); + set_tos(*l.udp_sock, tos, ec); #ifndef TORRENT_DISABLE_LOGGING if (should_log()) { - error_code err; session_log(">>> SET_TOS [ udp (%s %d) tos: %x e: %s ]" - , i->udp_sock->local_endpoint(err).address().to_string().c_str() - , i->udp_sock->local_port() + , l.udp_sock->local_endpoint().address().to_string().c_str() + , l.udp_sock->local_port() , tos, ec.message().c_str()); } #endif @@ -6179,29 +6173,28 @@ namespace aux { void session_impl::update_socket_buffer_size() { - for (std::list::iterator i = m_listen_sockets.begin() - , end(m_listen_sockets.end()); i != end; ++i) + for (auto const& l : m_listen_sockets) { error_code ec; - set_socket_buffer_size(*i->udp_sock, m_settings, ec); + set_socket_buffer_size(*l.udp_sock, m_settings, ec); #ifndef TORRENT_DISABLE_LOGGING if (ec && should_log()) { error_code err; session_log("socket buffer size [ udp %s %d]: (%d) %s" - , i->udp_sock->local_endpoint(err).address().to_string(err).c_str() - , i->udp_sock->local_port(), ec.value(), ec.message().c_str()); + , l.udp_sock->local_endpoint().address().to_string(err).c_str() + , l.udp_sock->local_port(), ec.value(), ec.message().c_str()); } #endif ec.clear(); - set_socket_buffer_size(*i->sock, m_settings, ec); + set_socket_buffer_size(*l.sock, m_settings, ec); #ifndef TORRENT_DISABLE_LOGGING if (ec && should_log()) { error_code err; session_log("socket buffer size [ udp %s %d]: (%d) %s" - , i->sock->local_endpoint(err).address().to_string(err).c_str() - , i->sock->local_endpoint(err).port(), ec.value(), ec.message().c_str()); + , l.sock->local_endpoint().address().to_string(err).c_str() + , l.sock->local_endpoint().port(), ec.value(), ec.message().c_str()); } #endif }