remove dht-verbose logging build configuration. tie it to the main logging configuration (which now is on by default) and make it less costly when dht logging alerts are disabled

This commit is contained in:
Arvid Norberg 2015-05-16 19:29:49 +00:00
parent 12c9d3de26
commit 99de70604a
21 changed files with 172 additions and 114 deletions

View File

@ -454,9 +454,8 @@ feature.compose <simulate-slow-read>on : <define>TORRENT_SIMULATE_SLOW_READ ;
feature logging : on off : composite propagated link-incompatible ;
feature.compose <logging>off : <define>TORRENT_DISABLE_LOGGING ;
feature dht : on off logging : composite propagated link-incompatible ;
feature dht : on off : composite propagated link-incompatible ;
feature.compose <dht>off : <define>TORRENT_DISABLE_DHT ;
feature.compose <dht>logging : <define>TORRENT_DHT_VERBOSE_LOGGING ;
feature encryption : on off : composite propagated link-incompatible ;
feature.compose <encryption>off : <define>TORRENT_DISABLE_ENCRYPTION ;
@ -509,7 +508,7 @@ variant test_release
;
variant test_debug : debug
: <crypto>openssl <logging>on <disk-stats>on
<dht>logging <allocator>debug <debug-iterators>on
<allocator>debug <debug-iterators>on
<invariant-checks>full <boost-link>shared
<export-extra>on <debug-iterators>on <boost>source <threading>multi
;
@ -772,10 +771,7 @@ lib torrent
<link>shared:<define>BOOST_SYSTEM_SOURCE
<dht>on:<source>src/kademlia/$(KADEMLIA_SOURCES).cpp
<dht>logging:<source>src/kademlia/$(KADEMLIA_SOURCES).cpp
<dht>on:<source>ed25519/src/$(ED25519_SOURCES).cpp
<dht>logging:<source>ed25519/src/$(ED25519_SOURCES).cpp
<conditional>@building
<conditional>@warnings

View File

@ -568,8 +568,10 @@ namespace libtorrent
virtual void announce(sha1_hash const& ih, address const& addr, int port) TORRENT_OVERRIDE;
virtual void outgoing_get_peers(sha1_hash const& target
, sha1_hash const& sent_target, udp::endpoint const& ep) TORRENT_OVERRIDE;
virtual void log(libtorrent::dht::dht_logger::dht_module_t m, char const* fmt, ...)
virtual void log(libtorrent::dht::dht_logger::module_t m, char const* fmt, ...)
TORRENT_OVERRIDE TORRENT_FORMAT(3,4);
virtual void log_message(message_direction_t dir, char const* pkt, int len
, char const* fmt, ...) TORRENT_OVERRIDE TORRENT_FORMAT(5, 6);
void set_external_address(address const& ip
, int source_type, address const& source);

View File

@ -41,7 +41,7 @@ namespace libtorrent { namespace dht
{
struct dht_logger
{
enum dht_module_t
enum module_t
{
tracker,
node,
@ -50,7 +50,17 @@ namespace libtorrent { namespace dht
traversal
};
virtual void log(dht_module_t m, char const* fmt, ...) TORRENT_FORMAT(3,4) = 0;
enum message_direction_t
{
incoming_message,
outgoing_message,
incoming_message_error,
outgoing_message_error
};
virtual void log(module_t m, char const* fmt, ...) TORRENT_FORMAT(3,4) = 0;
virtual void log_message(message_direction_t dir, char const* pkt, int len
, char const* fmt, ...) TORRENT_FORMAT(5, 6) = 0;
protected:
~dht_logger() {}

View File

@ -232,7 +232,7 @@ public:
int data_size() const { return int(m_map.size()); }
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
void print_state(std::ostream& os) const
{ m_table.print_state(os); }
#endif

View File

@ -60,7 +60,7 @@ struct TORRENT_EXTRA_EXPORT node_entry
address addr() const { return address_v4(a); }
int port() const { return p; }
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
time_point first_seen;
#endif

View File

@ -129,8 +129,8 @@ struct observer : boost::noncopyable
flag_done = 128
};
#ifndef TORRENT_DHT_VERBOSE_LOGGING
// TODO: 2 make this private and unconditional
#ifdef TORRENT_DISABLE_LOGGING
// TODO: 3 make this private and unconditional
protected:
#endif

View File

@ -175,7 +175,7 @@ public:
void replacement_cache(bucket_t& nodes) const;
#if defined TORRENT_DHT_VERBOSE_LOGGING || defined TORRENT_DEBUG
#if defined TORRENT_DEBUG
// used for debug and monitoring purposes. This will print out
// the state of the routing table to the given stream
void print_state(std::ostream& os) const;

View File

@ -79,7 +79,7 @@ namespace libtorrent { namespace dht
{
void incoming_error(entry& e, char const* msg);
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
std::string parse_dht_client(bdecode_node const& e)
{
bdecode_node ver = e.dict_find_string("v");
@ -161,7 +161,7 @@ namespace libtorrent { namespace dht
, m_abort(false)
, m_host_resolver(sock.get_io_service())
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
m_log->log(dht_logger::tracker, "starting DHT tracker with node id: %s"
, to_hex(m_dht.nid().to_string()).c_str());
#endif
@ -260,12 +260,12 @@ namespace libtorrent { namespace dht
{
m_last_new_key = now;
m_dht.new_write_key();
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
m_log->log(dht_logger::tracker, "*** new write key***");
#endif
}
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#if defined TORRENT_DEBUG && TORRENT_USE_IOSTREAM
std::ofstream st("dht_routing_table_state.txt", std::ios_base::trunc);
m_dht.print_state(st);
#endif
@ -410,18 +410,21 @@ namespace libtorrent { namespace dht
int ret = bdecode(buf, buf + size, m_msg, err, &pos, 10, 500);
if (ret != 0)
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
m_log->log(dht_logger::tracker, "<== %s ERROR: %s pos: %d"
, print_endpoint(ep).c_str(), err.message().c_str(), int(pos));
#ifndef TORRENT_DISABLE_LOGGING
m_log->log_message(dht_logger::incoming_message_error, buf
, size, "%s ERROR: %s pos: %d"
, print_endpoint(ep).c_str(), err.message().c_str()
, int(pos));
#endif
return false;
}
if (m_msg.type() != bdecode_node::dict_t)
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
m_log->log(dht_logger::tracker, "<== %s ERROR: not a dictionary %s"
, print_endpoint(ep).c_str(), print_entry(m_msg, true).c_str());
#ifndef TORRENT_DISABLE_LOGGING
m_log->log_message(dht_logger::incoming_message_error, buf
, size, "%s ERROR: not a dictionary"
, print_endpoint(ep).c_str());
#endif
// it's not a good idea to send invalid messages
// especially not in response to an invalid message
@ -431,6 +434,11 @@ namespace libtorrent { namespace dht
return false;
}
#ifndef TORRENT_DISABLE_LOGGING
m_log->log_message(dht_logger::incoming_message, buf
, size, "%s", print_endpoint(ep).c_str());
#endif
libtorrent::dht::msg m(m_msg, ep);
m_dht.incoming(m);
return true;
@ -517,25 +525,15 @@ namespace libtorrent { namespace dht
bencode(std::back_inserter(m_send_buf), e);
error_code ec;
#ifdef TORRENT_DHT_VERBOSE_LOGGING
// TODO: 3 it would be nice to not have to decode this if logging
// is not enabled. Maybe there could be a separate log function for
// incoming and outgoing packets.
bdecode_node print;
int ret = bdecode(&m_send_buf[0], &m_send_buf[0] + m_send_buf.size(), print, ec);
TORRENT_ASSERT(ret == 0);
std::string outgoing_message = print_entry(print, true);
#endif
if (m_sock.send(addr, &m_send_buf[0], (int)m_send_buf.size(), ec, send_flags))
{
if (ec)
{
m_counters.inc_stats_counter(counters::dht_messages_out_dropped);
#ifdef TORRENT_DHT_VERBOSE_LOGGING
m_log->log(dht_logger::tracker, "==> %s DROPPED (%s) %s"
, print_endpoint(addr).c_str(), ec.message().c_str()
, outgoing_message.c_str());
#ifndef TORRENT_DISABLE_LOGGING
m_log->log_message(dht_logger::outgoing_message, &m_send_buf[0]
, m_send_buf.size(), "%s DROPPED (%s)"
, print_endpoint(addr).c_str(), ec.message().c_str());
#endif
return false;
}
@ -545,10 +543,10 @@ namespace libtorrent { namespace dht
m_counters.inc_stats_counter(counters::sent_ip_overhead_bytes
, addr.address().is_v6() ? 48 : 28);
m_counters.inc_stats_counter(counters::dht_messages_out);
#ifdef TORRENT_DHT_VERBOSE_LOGGING
m_log->log(dht_logger::tracker, "==> %s %s"
, print_endpoint(addr).c_str()
, outgoing_message.c_str());
#ifndef TORRENT_DISABLE_LOGGING
m_log->log_message(dht_logger::outgoing_message, &m_send_buf[0]
, m_send_buf.size(), "%s"
, print_endpoint(addr).c_str());
#endif
return true;
}
@ -556,10 +554,10 @@ namespace libtorrent { namespace dht
{
m_counters.inc_stats_counter(counters::dht_messages_out_dropped);
#ifdef TORRENT_DHT_VERBOSE_LOGGING
m_log->log(dht_logger::tracker, "==> %s DROPPED %s"
, print_endpoint(addr).c_str()
, outgoing_message.c_str());
#ifndef TORRENT_DISABLE_LOGGING
m_log->log_message(dht_logger::outgoing_message, &m_send_buf[0]
, m_send_buf.size(), "%s"
, print_endpoint(addr).c_str());
#endif
return false;
}

View File

@ -32,7 +32,7 @@ POSSIBILITY OF SUCH DAMAGE.
#include "libtorrent/kademlia/dos_blocker.hpp"
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
#include "libtorrent/socket_io.hpp" // for print_address
#include "libtorrent/kademlia/dht_observer.hpp" // for dht_logger
#endif
@ -76,7 +76,7 @@ namespace libtorrent { namespace dht
{
if (match->count == m_message_rate_limit * 10)
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
logger->log(dht_logger::tracker, "BANNING PEER [ ip: %s time: %f count: %d ]"
, print_address(addr).c_str()
, total_milliseconds((now - match->limit) + seconds(10)) / 1000.f

View File

@ -52,7 +52,7 @@ void find_data_observer::reply(msg const& m)
bdecode_node r = m.message.dict_find_dict("r");
if (!r)
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
m_algorithm->get_node().observer()->log(dht_logger::traversal, "[%p] missing response dict"
, m_algorithm.get());
#endif
@ -62,7 +62,7 @@ void find_data_observer::reply(msg const& m)
bdecode_node id = r.dict_find_string("id");
if (!id || id.string_length() != 20)
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
m_algorithm->get_node().observer()->log(dht_logger::traversal, "[%p] invalid id in response"
, m_algorithm.get());
#endif
@ -111,7 +111,7 @@ void find_data::start()
void find_data::got_write_token(node_id const& n, std::string const& write_token)
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
get_node().observer()->log(dht_logger::traversal, "[%p] adding write token '%s' under id '%s'"
, this, to_hex(write_token).c_str(), to_hex(n.to_string()).c_str());
#endif
@ -136,7 +136,7 @@ void find_data::done()
m_done = true;
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
get_node().observer()->log(dht_logger::traversal, "[%p] %s DONE"
, this, name());
#endif
@ -149,7 +149,7 @@ void find_data::done()
observer_ptr const& o = *i;
if ((o->flags & observer::flag_alive) == 0)
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
get_node().observer()->log(dht_logger::traversal, "[%p] not alive: %s"
, this, print_endpoint(o->target_ep()).c_str());
#endif
@ -158,14 +158,14 @@ void find_data::done()
std::map<node_id, std::string>::iterator j = m_write_tokens.find(o->id());
if (j == m_write_tokens.end())
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
get_node().observer()->log(dht_logger::traversal, "[%p] no write token: %s"
, this, print_endpoint(o->target_ep()).c_str());
#endif
continue;
}
results.push_back(std::make_pair(node_entry(o->id(), o->target_ep()), j->second));
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
get_node().observer()->log(dht_logger::traversal, "[%p] %s"
, this, print_endpoint(o->target_ep()).c_str());
#endif

View File

@ -198,7 +198,7 @@ void get_item::done()
// as the v argument
void get_item::put(std::vector<std::pair<node_entry, std::string> > const& v)
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
// TODO: 3 it would be nice to not have to spend so much time rendering
// the bencoded dict if logging is disabled
get_node().observer()->log(dht_logger::traversal, "[%p] sending put [ v: \"%s\" seq: %" PRId64 " nodes: %d ]"
@ -215,7 +215,7 @@ void get_item::put(std::vector<std::pair<node_entry, std::string> > const& v)
for (std::vector<std::pair<node_entry, std::string> >::const_iterator i = v.begin()
, end(v.end()); i != end; ++i)
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
get_node().observer()->log(dht_logger::traversal, "[%p] put-distance: %d"
, this, 160 - distance_exp(m_target, i->first.id));
#endif
@ -257,7 +257,7 @@ void get_item_observer::reply(msg const& m)
bdecode_node r = m.message.dict_find_dict("r");
if (!r)
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
m_algorithm->get_node().observer()->log(dht_logger::traversal, "[%p] missing response dict"
, m_algorithm.get());
#endif

View File

@ -50,7 +50,7 @@ void get_peers_observer::reply(msg const& m)
bdecode_node r = m.message.dict_find_dict("r");
if (!r)
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
m_algorithm->get_node().observer()->log(dht_logger::traversal, "[%p] missing response dict"
, m_algorithm.get());
#endif
@ -68,7 +68,7 @@ void get_peers_observer::reply(msg const& m)
char const* peers = n.list_at(0).string_ptr();
char const* end = peers + n.list_at(0).string_length();
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
bdecode_node id = r.dict_find_string("id");
if (id && id.string_length() == 20)
{
@ -90,7 +90,7 @@ void get_peers_observer::reply(msg const& m)
{
// assume it's uTorrent/libtorrent format
read_endpoint_list<tcp::endpoint>(n, peer_list);
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
bdecode_node id = r.dict_find_string("id");
if (id && id.string_length() == 20)
{
@ -276,7 +276,7 @@ void obfuscated_get_peers::done()
m_data_callback.clear();
m_nodes_callback.clear();
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
get_node().observer()->log(dht_logger::traversal, "[%p] obfuscated get_peers "
"phase 1 done, spawning get_peers [ %p ]"
, this, ta.get());
@ -307,7 +307,7 @@ void obfuscated_get_peers_observer::reply(msg const& m)
bdecode_node r = m.message.dict_find_dict("r");
if (!r)
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
m_algorithm->get_node().observer()->log(dht_logger::traversal, "[%p] missing response dict"
, m_algorithm.get());
#endif
@ -317,7 +317,7 @@ void obfuscated_get_peers_observer::reply(msg const& m)
bdecode_node id = r.dict_find_string("id");
if (!id || id.string_length() != 20)
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
m_algorithm->get_node().observer()->log(dht_logger::traversal, "[%p] invalid id in response"
, m_algorithm.get());
#endif

View File

@ -124,7 +124,7 @@ bool node::verify_token(std::string const& token, char const* info_hash
{
if (token.length() != 4)
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
m_observer->log(dht_logger::node, "token of incorrect length: %d"
, token.length());
#endif
@ -180,14 +180,14 @@ void node::bootstrap(std::vector<udp::endpoint> const& nodes
boost::intrusive_ptr<dht::bootstrap> r(new dht::bootstrap(*this, target, f));
m_last_self_refresh = aux::time_now();
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
int count = 0;
#endif
for (std::vector<udp::endpoint>::const_iterator i = nodes.begin()
, end(nodes.end()); i != end; ++i)
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
++count;
#endif
r->add_entry(node_id(0), *i, observer::flag_initial);
@ -196,7 +196,7 @@ void node::bootstrap(std::vector<udp::endpoint> const& nodes
// make us start as far away from our node ID as possible
r->trim_seed_nodes();
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
m_observer->log(dht_logger::node, "bootstrapping with %d nodes", count);
#endif
r->start();
@ -282,7 +282,7 @@ void node::incoming(msg const& m)
}
case 'e':
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
bdecode_node err = m.message.dict_find_list("e");
if (err && err.list_size() >= 2)
{
@ -302,7 +302,7 @@ namespace
void announce_fun(std::vector<std::pair<node_entry, std::string> > const& v
, node& node, int listen_port, sha1_hash const& ih, int flags)
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
char hex_ih[41];
to_hex(reinterpret_cast<char const*>(&ih[0]), 20, hex_ih);
node.observer()->log(dht_logger::node, "sending announce_peer [ ih: %s "
@ -317,7 +317,7 @@ namespace
for (std::vector<std::pair<node_entry, std::string> >::const_iterator i = v.begin()
, end(v.end()); i != end; ++i)
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
node.observer()->log(dht_logger::node, "announce-distance: %d"
, (160 - distance_exp(ih, i->first.id)));
#endif
@ -345,7 +345,7 @@ namespace
void node::add_router_node(udp::endpoint router)
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
m_observer->log(dht_logger::node, "adding router node: %s"
, print_endpoint(router).c_str());
#endif
@ -362,7 +362,7 @@ void node::add_node(udp::endpoint node)
void node::announce(sha1_hash const& info_hash, int listen_port, int flags
, boost::function<void(std::vector<tcp::endpoint> const&)> f)
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
char hex_ih[41];
to_hex(reinterpret_cast<char const*>(&info_hash[0]), 20, hex_ih);
m_observer->log(dht_logger::node, "announcing [ ih: %s p: %d ]"
@ -391,7 +391,7 @@ void node::announce(sha1_hash const& info_hash, int listen_port, int flags
void node::get_item(sha1_hash const& target
, boost::function<bool(item&)> f)
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
char hex_target[41];
to_hex(reinterpret_cast<char const*>(&target[0]), 20, hex_target);
m_observer->log(dht_logger::node, "starting get for [ hash: %s ]"
@ -406,7 +406,7 @@ void node::get_item(sha1_hash const& target
void node::get_item(char const* pk, std::string const& salt
, boost::function<bool(item&)> f)
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
char hex_key[65];
to_hex(pk, 32, hex_key);
m_observer->log(dht_logger::node, "starting get for [ key: %s ]", hex_key);
@ -433,7 +433,7 @@ struct ping_observer : observer
bdecode_node r = m.message.dict_find_dict("r");
if (!r)
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
m_algorithm->get_node().observer()->log(dht_logger::node
, "[%p] missing response dict"
, m_algorithm.get());
@ -899,7 +899,7 @@ void node::incoming_request(msg const& m, entry& e)
if (msg_keys[1] && msg_keys[1].int_value() != 0) noseed = true;
if (msg_keys[2] && msg_keys[2].int_value() != 0) scrape = true;
lookup_peers(info_hash, reply, noseed, scrape);
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
if (reply.find_key("values"))
{
m_observer->log(dht_logger::node, "values: %d"

View File

@ -46,7 +46,7 @@ namespace libtorrent { namespace dht
, rtt(roundtriptime & 0xffff)
, timeout_count(pinged ? 0 : 0xff)
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
first_seen = aux::time_now();
#endif
}
@ -59,7 +59,7 @@ namespace libtorrent { namespace dht
, rtt(0xffff)
, timeout_count(0xff)
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
first_seen = aux::time_now();
#endif
}
@ -71,7 +71,7 @@ namespace libtorrent { namespace dht
, rtt(0xffff)
, timeout_count(0xff)
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
first_seen = aux::time_now();
#endif
}

View File

@ -87,7 +87,7 @@ void bootstrap::trim_seed_nodes()
void bootstrap::done()
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
get_node().observer()->log(dht_logger::traversal, "[%p] bootstrap done, pinging remaining nodes"
, this);
#endif

View File

@ -197,7 +197,7 @@ int routing_table::depth() const
return m_depth;
}
#if (defined TORRENT_DHT_VERBOSE_LOGGING || defined TORRENT_DEBUG) && TORRENT_USE_IOSTREAM
#if defined TORRENT_DEBUG && TORRENT_USE_IOSTREAM
void routing_table::print_state(std::ostream& os) const
{
@ -585,7 +585,7 @@ routing_table::add_node_status_t routing_table::add_node_impl(node_entry e)
// routing table
if (m_settings.restrict_routing_ips)
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
char hex_id[41];
to_hex(reinterpret_cast<char const*>(&e.id[0]), 20, hex_id);
m_log->log(dht_logger::routing_table, "ignoring node (duplicate IP): %s %s"
@ -668,7 +668,7 @@ routing_table::add_node_status_t routing_table::add_node_impl(node_entry e)
// we already have a node in this bucket with an IP very
// close to this one. We know that it's not the same, because
// it claims a different node-ID. Ignore this to avoid attacks
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
char hex_id1[41];
to_hex(reinterpret_cast<char const*>(&e.id[0]), 20, hex_id1);
char hex_id2[41];
@ -684,7 +684,7 @@ routing_table::add_node_status_t routing_table::add_node_impl(node_entry e)
if (j != rb.end())
{
// same thing but for the replacement bucket
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
char hex_id1[41];
to_hex(reinterpret_cast<char const*>(&e.id[0]), 20, hex_id1);
char hex_id2[41];
@ -864,7 +864,7 @@ routing_table::add_node_status_t routing_table::add_node_impl(node_entry e)
erase_one(m_ips, j->addr().to_v4().to_bytes());
*j = e;
m_ips.insert(e.addr().to_v4().to_bytes());
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
char hex_id[41];
to_hex(reinterpret_cast<char const*>(&e.id[0]), sha1_hash::size, hex_id);
m_log->log(dht_logger::routing_table, "replaving node with higher RTT: %s %s"
@ -1037,7 +1037,7 @@ void routing_table::node_failed(node_id const& nid, udp::endpoint const& ep)
j->timed_out();
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
char hex_id[41];
to_hex(reinterpret_cast<char const*>(&nid[0]), 20, hex_id);
m_log->log(dht_logger::routing_table, "NODE FAILED id: %s ip: %s fails: %d pinged: %d up-time: %d"
@ -1058,7 +1058,7 @@ void routing_table::node_failed(node_id const& nid, udp::endpoint const& ep)
{
j->timed_out();
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
char hex_id[41];
to_hex(reinterpret_cast<char const*>(&nid[0]), 20, hex_id);
m_log->log(dht_logger::routing_table, "NODE FAILED id: %s ip: %s fails: %d pinged: %d up-time: %d"

View File

@ -57,7 +57,7 @@ POSSIBILITY OF SUCH DAMAGE.
#include <libtorrent/time.hpp>
#include <libtorrent/aux_/time.hpp> // for aux::time_now
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
#include <fstream>
#endif
@ -222,7 +222,7 @@ void rpc_manager::check_invariant() const
void rpc_manager::unreachable(udp::endpoint const& ep)
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
m_log->log(dht_logger::rpc_manager, "PORT_UNREACHABLE [ ip: %s ]"
, print_endpoint(ep).c_str());
#endif
@ -235,7 +235,7 @@ void rpc_manager::unreachable(udp::endpoint const& ep)
if (o->target_ep() != ep) { ++i; continue; }
observer_ptr ptr = i->second;
i = m_transactions.erase(i);
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
m_log->log(dht_logger::rpc_manager, "found transaction [ tid: %d ]"
, int(ptr->transaction_id()));
#endif
@ -276,7 +276,7 @@ bool rpc_manager::incoming(msg const& m, node_id* id
if (!o)
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
m_log->log(dht_logger::rpc_manager, "reply with unknown transaction id size: %d from %s"
, transaction_id.size(), print_endpoint(m.addr).c_str());
#endif
@ -293,7 +293,7 @@ bool rpc_manager::incoming(msg const& m, node_id* id
time_point now = clock_type::now();
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
std::ofstream reply_stats("round_trip_ms.log", std::ios::app);
reply_stats << m.addr << "\t" << total_milliseconds(now - o->sent())
<< std::endl;
@ -334,7 +334,7 @@ bool rpc_manager::incoming(msg const& m, node_id* id
return false;
}
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
m_log->log(dht_logger::rpc_manager, "[%p] reply with transaction id: %d from %s"
, o->m_algorithm.get(), transaction_id.size()
, print_endpoint(m.addr).c_str());
@ -374,7 +374,7 @@ time_duration rpc_manager::tick()
time_duration diff = now - o->sent();
if (diff >= seconds(timeout))
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
m_log->log(dht_logger::rpc_manager, "[%p] timing out transaction id: %d from: %s"
, o->m_algorithm.get(), o->transaction_id()
, print_endpoint(o->target_ep()).c_str());
@ -388,7 +388,7 @@ time_duration rpc_manager::tick()
// already called it once
if (diff >= seconds(short_timeout) && !o->has_short_timeout())
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
m_log->log(dht_logger::rpc_manager, "[%p] short-timing out transaction id: %d from: %s"
, o->m_algorithm.get(), o->transaction_id()
, print_endpoint(o->target_ep()).c_str());
@ -435,7 +435,7 @@ bool rpc_manager::invoke(entry& e, udp::endpoint target_addr
o->set_target(target_addr);
o->set_transaction_id(tid);
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
m_log->log(dht_logger::rpc_manager, "[%p] invoking %s -> %s"
, o->m_algorithm.get(), e["q"].string().c_str()
, print_endpoint(target_addr).c_str());

View File

@ -89,7 +89,7 @@ traversal_algorithm::traversal_algorithm(
, m_responses(0)
, m_timeouts(0)
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
char hex_target[41];
to_hex(reinterpret_cast<char const*>(&target[0]), 20, hex_target);
get_node().observer()->log(dht_logger::traversal, "[%p] NEW target: %s k: %d"
@ -117,7 +117,7 @@ void traversal_algorithm::add_entry(node_id const& id, udp::endpoint addr, unsig
void* ptr = m_node.m_rpc.allocate_observer();
if (ptr == 0)
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
get_node().observer()->log(dht_logger::traversal, "[%p] failed to allocate memory or observer. aborting!"
, this);
#endif
@ -167,7 +167,7 @@ void traversal_algorithm::add_entry(node_id const& id, udp::endpoint addr, unsig
// we already have a node in this search with an IP very
// close to this one. We know that it's not the same, because
// it claims a different node-ID. Ignore this to avoid attacks
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
char hex_id[41];
to_hex(reinterpret_cast<char const*>(&o->id()[0]), 20, hex_id);
get_node().observer()->log(dht_logger::traversal
@ -182,7 +182,7 @@ void traversal_algorithm::add_entry(node_id const& id, udp::endpoint addr, unsig
TORRENT_ASSERT((o->flags & observer::flag_no_id) || std::find_if(m_results.begin(), m_results.end()
, boost::bind(&observer::id, _1) == id) == m_results.end());
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
char hex_id[41];
to_hex(reinterpret_cast<char const*>(&id[0]), 20, hex_id);
get_node().observer()->log(dht_logger::traversal
@ -238,7 +238,7 @@ char const* traversal_algorithm::name() const
void traversal_algorithm::traverse(node_id const& id, udp::endpoint addr)
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
if (id.is_all_zeros())
{
get_node().observer()->log(dht_logger::traversal
@ -304,7 +304,7 @@ void traversal_algorithm::failed(observer_ptr o, int flags)
if ((o->flags & observer::flag_short_timeout) == 0)
++m_branch_factor;
o->flags |= observer::flag_short_timeout;
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
char hex_id[41];
to_hex(reinterpret_cast<char const*>(&o->id()[0]), 20, hex_id);
get_node().observer()->log(dht_logger::traversal
@ -323,7 +323,7 @@ void traversal_algorithm::failed(observer_ptr o, int flags)
if (o->flags & observer::flag_short_timeout)
--m_branch_factor;
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
char hex_id[41];
to_hex(reinterpret_cast<char const*>(&o->id()[0]), 20, hex_id);
get_node().observer()->log(dht_logger::traversal
@ -350,7 +350,7 @@ void traversal_algorithm::failed(observer_ptr o, int flags)
void traversal_algorithm::done()
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
int results_target = m_node.m_table.bucket_size();
int closest_target = 160;
@ -433,7 +433,7 @@ bool traversal_algorithm::add_requests()
continue;
}
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
char hex_id[41];
to_hex(reinterpret_cast<char const*>(&o->id()[0]), 20, hex_id);
get_node().observer()->log(dht_logger::traversal
@ -468,7 +468,7 @@ bool traversal_algorithm::add_requests()
void traversal_algorithm::add_router_entries()
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
get_node().observer()->log(dht_logger::traversal
, "[%p] using router nodes to initiate traversal algorithm %d routers"
, this, int(std::distance(m_node.m_table.router_begin(), m_node.m_table.router_end())));
@ -523,7 +523,7 @@ void traversal_observer::reply(msg const& m)
bdecode_node r = m.message.dict_find_dict("r");
if (!r)
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
m_algorithm->get_node().observer()->log(dht_logger::traversal
, "[%p] missing response dict"
, m_algorithm.get());
@ -531,7 +531,7 @@ void traversal_observer::reply(msg const& m)
return;
}
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
bdecode_node nid = r.dict_find_string("id");
char hex_id[41];
to_hex(nid.string_ptr(), 20, hex_id);
@ -559,7 +559,7 @@ void traversal_observer::reply(msg const& m)
bdecode_node id = r.dict_find_string("id");
if (!id || id.string_length() != 20)
{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
m_algorithm->get_node().observer()->log(dht_logger::traversal, "[%p] invalid id in response"
, m_algorithm.get(), m_algorithm->name());
#endif
@ -581,7 +581,7 @@ void traversal_algorithm::abort()
o.flags |= observer::flag_done;
}
#ifdef TORRENT_DHT_VERBOSE_LOGGING
#ifndef TORRENT_DISABLE_LOGGING
get_node().observer()->log(dht_logger::traversal, "[%p] ABORTED type: %s"
, this, name());
#endif

View File

@ -6473,7 +6473,7 @@ retry:
}
TORRENT_FORMAT(3,4)
void session_impl::log(libtorrent::dht::dht_logger::dht_module_t m, char const* fmt, ...)
void session_impl::log(libtorrent::dht::dht_logger::module_t m, char const* fmt, ...)
{
if (!m_alerts.should_post<dht_log_alert>()) return;
@ -6485,6 +6485,34 @@ retry:
m_alerts.emplace_alert<dht_log_alert>((dht_log_alert::dht_module_t)m, buf);
}
TORRENT_FORMAT(5, 6)
void session_impl::log_message(message_direction_t dir, char const* pkt, int len
, char const* fmt, ...)
{
if (!m_alerts.should_post<dht_log_alert>()) return;
char buf[1024];
int offset = 0;
char const* prefix[] =
{ "<== ", "<== ERROR ", "==> ", "==> ERROR " };
offset += snprintf(&buf[offset], sizeof(buf) - offset, prefix[dir]);
va_list v;
va_start(v, fmt);
offset += vsnprintf(&buf[offset], sizeof(buf) - offset, fmt, v);
va_end(v);
bdecode_node print;
error_code ec;
int ret = bdecode(buf, buf + len, print, ec, NULL, 100, 100);
std::string msg = print_entry(print, true);
strncpy(&buf[offset], msg.c_str(), sizeof(buf) - offset);
m_alerts.emplace_alert<dht_log_alert>(dht_log_alert::tracker, buf);
}
void session_impl::set_external_address(address const& ip
, int source_type, address const& source)
{

View File

@ -433,7 +433,9 @@ struct obs : dht::dht_observer
virtual void outgoing_get_peers(sha1_hash const& target
, sha1_hash const& sent_target, udp::endpoint const& ep) TORRENT_OVERRIDE {}
virtual void announce(sha1_hash const& ih, address const& addr, int port) TORRENT_OVERRIDE {}
virtual void log(dht_logger::dht_module_t l, char const* fmt, ...) TORRENT_OVERRIDE {}
virtual void log(dht_logger::module_t l, char const* fmt, ...) TORRENT_OVERRIDE {}
virtual void log_message(message_direction_t dir, char const* pkt, int len
, char const* fmt, ...) TORRENT_OVERRIDE {}
};
// TODO: test obfuscated_get_peers

View File

@ -36,16 +36,38 @@ POSSIBILITY OF SUCH DAMAGE.
#include "libtorrent/time.hpp"
#include "libtorrent/kademlia/dos_blocker.hpp"
#include "libtorrent/kademlia/dht_observer.hpp"
#include "libtorrent/error_code.hpp"
struct log_t : libtorrent::dht::dht_logger
{
virtual void log(dht_logger::dht_module_t m, char const* fmt, ...)
virtual void log(dht_logger::module_t m, char const* fmt, ...)
TORRENT_OVERRIDE TORRENT_FORMAT(3, 4)
{
va_list v;
va_start(v, fmt);
vfprintf(stderr, fmt, v);
va_end(v);
}
virtual void log_message(message_direction_t dir, char const* pkt, int len
, char const* fmt, ...) TORRENT_OVERRIDE TORRENT_FORMAT(5, 6)
{
char const* prefix[] =
{ "<== ", "<== ERROR ", "==> ", "==> ERROR " };
printf(prefix[dir]);
va_list v;
va_start(v, fmt);
vprintf(fmt, v);
va_end(v);
libtorrent::bdecode_node print;
libtorrent::error_code ec;
int ret = bdecode(pkt, pkt + len, print, ec, NULL, 100, 100);
std::string msg = print_entry(print, true);
printf("%s", msg.c_str());
}
};
int test_main()