From 0afea4bb3e7d5032c3ffc15709fb6e05035b0047 Mon Sep 17 00:00:00 2001 From: Arvid Norberg Date: Sun, 18 Jan 2015 01:06:36 +0000 Subject: [PATCH] move some DHT verbose stats logging over to performance counters --- include/libtorrent/kademlia/dht_tracker.hpp | 14 -- include/libtorrent/performance_counters.hpp | 5 + src/kademlia/dht_tracker.cpp | 151 -------------------- src/kademlia/node.cpp | 36 +++-- src/session_stats.cpp | 6 + 5 files changed, 28 insertions(+), 184 deletions(-) diff --git a/include/libtorrent/kademlia/dht_tracker.hpp b/include/libtorrent/kademlia/dht_tracker.hpp index 6d01723b8..568e24eac 100644 --- a/include/libtorrent/kademlia/dht_tracker.hpp +++ b/include/libtorrent/kademlia/dht_tracker.hpp @@ -157,20 +157,6 @@ namespace libtorrent { namespace dht // used to resolve hostnames for nodes udp::resolver m_host_resolver; - -#ifdef TORRENT_DHT_VERBOSE_LOGGING - int m_replies_sent[5]; - int m_queries_received[5]; - int m_replies_bytes_sent[5]; - int m_queries_bytes_received[5]; - int m_counter; - - int m_total_message_input; - int m_total_in_bytes; - int m_total_out_bytes; - - int m_queries_out_bytes; -#endif }; }} diff --git a/include/libtorrent/performance_counters.hpp b/include/libtorrent/performance_counters.hpp index 8a5e1335a..712aa1e51 100644 --- a/include/libtorrent/performance_counters.hpp +++ b/include/libtorrent/performance_counters.hpp @@ -228,6 +228,11 @@ namespace libtorrent dht_put_in, dht_put_out, + dht_invalid_announce, + dht_invalid_get_peers, + dht_invalid_put, + dht_invalid_get, + // uTP counters. utp_packet_loss, utp_timeout, diff --git a/src/kademlia/dht_tracker.cpp b/src/kademlia/dht_tracker.cpp index b18b898dd..07a739730 100644 --- a/src/kademlia/dht_tracker.cpp +++ b/src/kademlia/dht_tracker.cpp @@ -30,10 +30,6 @@ POSSIBILITY OF SUCH DAMAGE. */ -#ifdef TORRENT_DHT_VERBOSE_LOGGING -#include -#endif - #include #include #include @@ -73,22 +69,8 @@ namespace namespace libtorrent { namespace dht { - void incoming_error(entry& e, char const* msg); -#ifdef TORRENT_DHT_VERBOSE_LOGGING - int g_az_message_input = 0; - int g_ut_message_input = 0; - int g_lt_message_input = 0; - int g_mp_message_input = 0; - int g_gr_message_input = 0; - int g_mo_message_input = 0; - int g_unknown_message_input = 0; - - int g_announces = 0; - int g_failed_announces = 0; -#endif - #ifdef TORRENT_DHT_VERBOSE_LOGGING std::string parse_dht_client(lazy_entry const& e) { @@ -97,42 +79,34 @@ namespace libtorrent { namespace dht std::string const& client = ver->string_value(); if (client.size() < 2) { - ++g_unknown_message_input; return client; } else if (std::equal(client.begin(), client.begin() + 2, "Az")) { - ++g_az_message_input; return "Azureus"; } else if (std::equal(client.begin(), client.begin() + 2, "UT")) { - ++g_ut_message_input; return "uTorrent"; } else if (std::equal(client.begin(), client.begin() + 2, "LT")) { - ++g_lt_message_input; return "libtorrent"; } else if (std::equal(client.begin(), client.begin() + 2, "MP")) { - ++g_mp_message_input; return "MooPolice"; } else if (std::equal(client.begin(), client.begin() + 2, "GR")) { - ++g_gr_message_input; return "GetRight"; } else if (std::equal(client.begin(), client.begin() + 2, "MO")) { - ++g_mo_message_input; return "Mono Torrent"; } else { - ++g_unknown_message_input; return client; } } @@ -177,18 +151,6 @@ namespace libtorrent { namespace dht , m_host_resolver(sock.get_io_service()) { #ifdef TORRENT_DHT_VERBOSE_LOGGING - m_counter = 0; - std::fill_n(m_replies_bytes_sent, 5, 0); - std::fill_n(m_queries_bytes_received, 5, 0); - std::fill_n(m_replies_sent, 5, 0); - std::fill_n(m_queries_received, 5, 0); - g_announces = 0; - g_failed_announces = 0; - m_total_message_input = 0; - m_total_in_bytes = 0; - m_total_out_bytes = 0; - m_queries_out_bytes = 0; - // turns on and off individual components' logging // rpc_log().enable(false); @@ -297,92 +259,6 @@ namespace libtorrent { namespace dht TORRENT_LOG(dht_tracker) << " *** new write key"; #endif } - -#ifdef TORRENT_DHT_VERBOSE_LOGGING - // TODO: 3 move all this out of libtorrent. It can be done in libtorrent-webui - // just like session_stats - static bool first = true; - - std::ofstream st("dht_routing_table_state.txt", std::ios_base::trunc); - m_dht.print_state(st); - - // count torrents - int torrents = m_dht.num_torrents(); - - // count peers - int peers = m_dht.num_peers(); - - std::ofstream pc("dht_stats.log", first ? std::ios_base::trunc : std::ios_base::app); - if (first) - { - first = false; - pc << "\n\n ***** starting log at " << time_now_string() << " *****\n\n" - << "minute:active nodes:passive nodes:confirmed nodes" - ":ping replies sent:ping queries recvd" - ":ping replies bytes sent:ping queries bytes recvd" - ":find_node replies sent:find_node queries recv" - ":find_node replies bytes sent:find_node queries bytes recv" - ":get_peers replies sent:get_peers queries recvd" - ":get_peers replies bytes sent:get_peers queries bytes recv" - ":announce_peer replies sent:announce_peer queries recvd" - ":announce_peer replies bytes sent:announce_peer queries bytes recv" - ":error replies sent:error queries recvd" - ":error replies bytes sent:error queries bytes recv" - ":num torrents:num peers:announces per min" - ":failed announces per min:total msgs per min" - ":az msgs per min:ut msgs per min:lt msgs per min:mp msgs per min" - ":gr msgs per min:mo msgs per min:bytes in per sec:bytes out per sec" - ":queries out bytes per sec\n\n"; - } - - int active; - int passive; - int confirmed; - boost::tie(active, passive, confirmed) = m_dht.size(); - pc << (m_counter * tick_period) - << "\t" << active - << "\t" << passive - << "\t" << confirmed; - for (int i = 0; i < 5; ++i) - pc << "\t" << (m_replies_sent[i] / float(tick_period)) - << "\t" << (m_queries_received[i] / float(tick_period)) - << "\t" << (m_replies_bytes_sent[i] / float(tick_period*60)) - << "\t" << (m_queries_bytes_received[i] / float(tick_period*60)); - - pc << "\t" << torrents - << "\t" << peers - << "\t" << g_announces / float(tick_period) - << "\t" << g_failed_announces / float(tick_period) - << "\t" << (m_total_message_input / float(tick_period)) - << "\t" << (g_az_message_input / float(tick_period)) - << "\t" << (g_ut_message_input / float(tick_period)) - << "\t" << (g_lt_message_input / float(tick_period)) - << "\t" << (g_mp_message_input / float(tick_period)) - << "\t" << (g_gr_message_input / float(tick_period)) - << "\t" << (g_mo_message_input / float(tick_period)) - << "\t" << (m_total_in_bytes / float(tick_period*60)) - << "\t" << (m_total_out_bytes / float(tick_period*60)) - << "\t" << (m_queries_out_bytes / float(tick_period*60)) - << std::endl; - ++m_counter; - std::fill_n(m_replies_bytes_sent, 5, 0); - std::fill_n(m_queries_bytes_received, 5, 0); - std::fill_n(m_replies_sent, 5, 0); - std::fill_n(m_queries_received, 5, 0); - g_announces = 0; - g_failed_announces = 0; - m_total_message_input = 0; - g_az_message_input = 0; - g_ut_message_input = 0; - g_lt_message_input = 0; - g_mp_message_input = 0; - g_gr_message_input = 0; - g_mo_message_input = 0; - g_unknown_message_input = 0; - m_total_in_bytes = 0; - m_total_out_bytes = 0; - m_queries_out_bytes = 0; -#endif } void dht_tracker::announce(sha1_hash const& ih, int listen_port, int flags @@ -510,11 +386,6 @@ namespace libtorrent { namespace dht if (!m_blocker.incoming(ep.address(), time_now())) return true; -#ifdef TORRENT_DHT_VERBOSE_LOGGING - ++m_total_message_input; - m_total_in_bytes += size; -#endif - using libtorrent::entry; using libtorrent::bdecode; @@ -549,26 +420,6 @@ namespace libtorrent { namespace dht return false; } -#ifdef TORRENT_DHT_VERBOSE_LOGGING - parse_dht_client(e); - TORRENT_LOG(dht_tracker) << "<== " << ep << " " << print_entry(e, true); - - if (e.dict_find_string_value("y") == "q") - { - std::string cmd = e.dict_find_string_value("q"); - int cmd_idx = -1; - if (cmd == "ping") cmd_idx = 0; - else if (cmd == "find_node") cmd_idx = 1; - else if (cmd == "get_peers") cmd_idx = 2; - else if (cmd == "announce_peeer") cmd_idx = 3; - if (cmd_idx >= 0) - { - ++m_queries_received[cmd_idx]; - m_queries_bytes_received[cmd_idx] += size; - } - } -#endif - m_dht.incoming(m); return true; } @@ -675,8 +526,6 @@ namespace libtorrent { namespace dht , addr.address().is_v6() ? 48 : 28); m_counters.inc_stats_counter(counters::dht_messages_out); #ifdef TORRENT_DHT_VERBOSE_LOGGING - m_total_out_bytes += m_send_buf.size(); - if (e["y"].string() == "r") { /* diff --git a/src/kademlia/node.cpp b/src/kademlia/node.cpp index 7390fcc99..9036fe8fb 100644 --- a/src/kademlia/node.cpp +++ b/src/kademlia/node.cpp @@ -69,10 +69,6 @@ enum { announce_interval = 30 }; #ifdef TORRENT_DHT_VERBOSE_LOGGING TORRENT_DEFINE_LOG(node) - -extern int g_failed_announces; -extern int g_announces; - #endif // remove peers that have timed out @@ -338,7 +334,7 @@ namespace a["token"] = i->second; a["seed"] = (flags & node_impl::flag_seed) ? 1 : 0; if (flags & node_impl::flag_implied_port) a["implied_port"] = 1; - node.stats_counters().inc_stats_counter(counters::dht_announce_peer_in); + node.stats_counters().inc_stats_counter(counters::dht_announce_peer_out); node.m_rpc.invoke(e, i->first.ep(), o); } } @@ -864,8 +860,10 @@ void node_impl::incoming_request(msg const& m, entry& e) }; lazy_entry const* msg_keys[3]; - if (!verify_message(arg_ent, msg_desc, msg_keys, 3, error_string, sizeof(error_string))) + if (!verify_message(arg_ent, msg_desc, msg_keys, 3, error_string + , sizeof(error_string))) { + m_counters.inc_stats_counter(counters::dht_invalid_get_peers); incoming_error(e, error_string); return; } @@ -927,9 +925,7 @@ void node_impl::incoming_request(msg const& m, entry& e) lazy_entry const* msg_keys[6]; if (!verify_message(arg_ent, msg_desc, msg_keys, 6, error_string, sizeof(error_string))) { -#ifdef TORRENT_DHT_VERBOSE_LOGGING - ++g_failed_announces; -#endif + m_counters.inc_stats_counter(counters::dht_invalid_announce); incoming_error(e, error_string); return; } @@ -943,9 +939,7 @@ void node_impl::incoming_request(msg const& m, entry& e) if (port < 0 || port >= 65536) { -#ifdef TORRENT_DHT_VERBOSE_LOGGING - ++g_failed_announces; -#endif + m_counters.inc_stats_counter(counters::dht_invalid_announce); incoming_error(e, "invalid port"); return; } @@ -960,9 +954,7 @@ void node_impl::incoming_request(msg const& m, entry& e) if (!verify_token(msg_keys[2]->string_value(), msg_keys[0]->string_ptr(), m.addr)) { -#ifdef TORRENT_DHT_VERBOSE_LOGGING - ++g_failed_announces; -#endif + m_counters.inc_stats_counter(counters::dht_invalid_announce); incoming_error(e, "invalid token"); return; } @@ -1021,9 +1013,6 @@ void node_impl::incoming_request(msg const& m, entry& e) std::set::iterator i = v->peers.find(peer); if (i != v->peers.end()) v->peers.erase(i++); v->peers.insert(i, peer); -#ifdef TORRENT_DHT_VERBOSE_LOGGING - ++g_announces; -#endif } else if (strcmp(query, "put") == 0) { @@ -1044,6 +1033,7 @@ void node_impl::incoming_request(msg const& m, entry& e) lazy_entry const* msg_keys[7]; if (!verify_message(arg_ent, msg_desc, msg_keys, 7, error_string, sizeof(error_string))) { + m_counters.inc_stats_counter(counters::dht_invalid_put); incoming_error(e, error_string); return; } @@ -1065,6 +1055,7 @@ void node_impl::incoming_request(msg const& m, entry& e) std::pair buf = msg_keys[1]->data_section(); if (buf.second > 1000 || buf.second <= 0) { + m_counters.inc_stats_counter(counters::dht_invalid_put); incoming_error(e, "message too big", 205); return; } @@ -1075,6 +1066,7 @@ void node_impl::incoming_request(msg const& m, entry& e) msg_keys[6]->string_ptr(), msg_keys[6]->string_length()); if (salt.second > 64) { + m_counters.inc_stats_counter(counters::dht_invalid_put); incoming_error(e, "salt too big", 207); return; } @@ -1095,6 +1087,7 @@ void node_impl::incoming_request(msg const& m, entry& e) // specific target hashes. it must match the one we got a "get" for if (!verify_token(msg_keys[0]->string_value(), (char const*)&target[0], m.addr)) { + m_counters.inc_stats_counter(counters::dht_invalid_put); incoming_error(e, "invalid token"); return; } @@ -1147,6 +1140,7 @@ void node_impl::incoming_request(msg const& m, entry& e) if (!verify_mutable_item(buf, salt , msg_keys[2]->int_value(), pk, sig)) { + m_counters.inc_stats_counter(counters::dht_invalid_put); incoming_error(e, "invalid signature", 206); return; } @@ -1205,12 +1199,14 @@ void node_impl::incoming_request(msg const& m, entry& e) // writers are accessing the same slot if (msg_keys[5] && item->seq != msg_keys[5]->int_value()) { + m_counters.inc_stats_counter(counters::dht_invalid_put); incoming_error(e, "CAS mismatch", 301); return; } if (item->seq > boost::uint64_t(msg_keys[2]->int_value())) { + m_counters.inc_stats_counter(counters::dht_invalid_put); incoming_error(e, "old sequence number", 302); return; } @@ -1257,8 +1253,10 @@ void node_impl::incoming_request(msg const& m, entry& e) // attempt to parse the message lazy_entry const* msg_keys[2]; - if (!verify_message(arg_ent, msg_desc, msg_keys, 2, error_string, sizeof(error_string))) + if (!verify_message(arg_ent, msg_desc, msg_keys, 2, error_string + , sizeof(error_string))) { + m_counters.inc_stats_counter(counters::dht_invalid_get); incoming_error(e, error_string); return; } diff --git a/src/session_stats.cpp b/src/session_stats.cpp index b73130e79..56f38f022 100644 --- a/src/session_stats.cpp +++ b/src/session_stats.cpp @@ -439,6 +439,12 @@ namespace libtorrent METRIC(dht, dht_put_in) METRIC(dht, dht_put_out) + // the number of failed incoming DHT requests by kind of request + METRIC(dht, dht_invalid_announce) + METRIC(dht, dht_invalid_get_peers) + METRIC(dht, dht_invalid_put) + METRIC(dht, dht_invalid_get) + // uTP counters. Each counter represents the number of time each event // has occurred. METRIC(utp, utp_packet_loss)