premiere-libtorrent/src/kademlia/dht_tracker.cpp

/*

Copyright (c) 2006, Arvid Norberg
All rights reserved.

Redistribution and use in source and binary forms, with or without
modification, are permitted provided that the following conditions
are met:

    * Redistributions of source code must retain the above copyright
      notice, this list of conditions and the following disclaimer.
    * Redistributions in binary form must reproduce the above copyright
      notice, this list of conditions and the following disclaimer in
      the documentation and/or other materials provided with the distribution.
    * Neither the name of the author nor the names of its
      contributors may be used to endorse or promote products derived
      from this software without specific prior written permission.

THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS IS"
AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE
ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT OWNER OR CONTRIBUTORS BE
LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR
CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF
SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS
INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN
CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE)
ARISING IN ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE
POSSIBILITY OF SUCH DAMAGE.

*/

#include "libtorrent/pch.hpp"

#include <fstream>
#include <set>
#include <numeric>
#include <stdexcept>
#include <boost/bind.hpp>
#include <boost/ref.hpp>
#include <boost/optional.hpp>
#include <boost/lexical_cast.hpp>
#include <boost/filesystem/operations.hpp>

#include "libtorrent/kademlia/node.hpp"
#include "libtorrent/kademlia/node_id.hpp"
#include "libtorrent/kademlia/traversal_algorithm.hpp"
#include "libtorrent/kademlia/dht_tracker.hpp"
#include "libtorrent/kademlia/msg.hpp"

#include "libtorrent/aux_/session_impl.hpp"
#include "libtorrent/socket.hpp"
#include "libtorrent/socket_io.hpp"
#include "libtorrent/bencode.hpp"
#include "libtorrent/io.hpp"
#include "libtorrent/version.hpp"
#include "libtorrent/escape_string.hpp"

using boost::ref;
using boost::lexical_cast;
using libtorrent::dht::node_impl;
using libtorrent::dht::node_id;
using libtorrent::dht::packet_t;
using libtorrent::dht::msg;
using namespace libtorrent::detail;

enum
{
	key_refresh = 5 // generate a new write token key every 5 minutes
};

namespace
{
	const int tick_period = 1; // minutes

	struct count_peers
	{
		int& count;
		count_peers(int& c): count(c) {}
		void operator()(std::pair<libtorrent::dht::node_id
			, libtorrent::dht::torrent_entry> const& t)
		{
			count += t.second.peers.size();
		}
	};
	
	template <class EndpointType>
	void read_endpoint_list(libtorrent::entry const* n, std::vector<EndpointType>& epl)
	{
		using namespace libtorrent;
		if (n->type() != entry::list_t) return;
		entry::list_type const& contacts = n->list();
		for (entry::list_type::const_iterator i = contacts.begin()
			, end(contacts.end()); i != end; ++i)
		{
			if (i->type() != entry::string_t) return;
			std::string const& p = i->string();
			if (p.size() < 6) continue;
			std::string::const_iterator in = p.begin();
			if (p.size() == 6)
				epl.push_back(read_v4_endpoint<EndpointType>(in));
#if TORRENT_USE_IPV6
			else if (p.size() == 18)
				epl.push_back(read_v6_endpoint<EndpointType>(in));
#endif
		}
	}

}

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;
#endif
		
	void intrusive_ptr_add_ref(dht_tracker const* c)
	{
		TORRENT_ASSERT(c != 0);
		TORRENT_ASSERT(c->m_refs >= 0);
		++c->m_refs;
	}

	void intrusive_ptr_release(dht_tracker const* c)
	{
		TORRENT_ASSERT(c != 0);
		TORRENT_ASSERT(c->m_refs > 0);
		if (--c->m_refs == 0)
			delete c;
	}

#ifdef TORRENT_DHT_VERBOSE_LOGGING
	std::string parse_dht_client(lazy_entry const& e)
	{
		lazy_entry const* ver = e.dict_find_string("v");
		if (!ver) return "generic";
		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;
		}
	}
#endif

#ifdef TORRENT_DHT_VERBOSE_LOGGING
	TORRENT_DEFINE_LOG(dht_tracker)
#endif

	boost::optional<node_id> extract_node_id(lazy_entry const* e)
	{
		if (e == 0 || e->type() != lazy_entry::dict_t) return boost::optional<node_id>();
		lazy_entry const* nid = e->dict_find_string("node-id");
		if (nid == 0 || nid->string_length() != 20) return boost::optional<node_id>();
		return boost::optional<node_id>(node_id(nid->string_ptr()));
	}

	boost::optional<node_id> extract_node_id(entry const* e)
	{
		if (e == 0 || e->type() != entry::dictionary_t) return boost::optional<node_id>();
		entry const* nid = e->find_key("node-id");
		if (nid == 0 || nid->type() != entry::string_t || nid->string().length() != 20)
			return boost::optional<node_id>();
		return boost::optional<node_id>(node_id(nid->string().c_str()));
	}

	void send_callback(void* userdata, entry const& e, udp::endpoint const& addr, int flags)
	{
		dht_tracker* self = (dht_tracker*)userdata;
		self->send_packet(e, addr, flags);
	}

	// class that puts the networking and the kademlia node in a single
	// unit and connecting them together.
	dht_tracker::dht_tracker(libtorrent::aux::session_impl& ses, rate_limited_udp_socket& sock
		, dht_settings const& settings, entry const* state)
		: m_dht(ses, &send_callback, settings, extract_node_id(state), this)
		, m_ses(ses)
		, m_sock(sock)
		, m_last_new_key(time_now() - minutes(key_refresh))
		, m_timer(sock.get_io_service())
		, m_connection_timer(sock.get_io_service())
		, m_refresh_timer(sock.get_io_service())
		, m_settings(settings)
		, m_refresh_bucket(160)
		, m_abort(false)
		, m_host_resolver(sock.get_io_service())
		, m_sent_bytes(0)
		, m_received_bytes(0)
		, m_refs(0)
	{
		using boost::bind;

#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);
		m_announces = 0;
		m_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);
//		node_log().enable(false);
		traversal_log().enable(false);
//		dht_tracker_log.enable(false);

		TORRENT_LOG(dht_tracker) << "starting DHT tracker with node id: " << m_dht.nid();
#endif
	}

	void dht_tracker::start(entry const& bootstrap)
	{
		std::vector<udp::endpoint> initial_nodes;

		mutex_t::scoped_lock l(m_mutex);
		if (bootstrap.type() == entry::dictionary_t)
		{
#ifndef BOOST_NO_EXCEPTIONS
			try
			{
#endif
			if (entry const* nodes = bootstrap.find_key("nodes"))
				read_endpoint_list<udp::endpoint>(nodes, initial_nodes);
#ifndef BOOST_NO_EXCEPTIONS
			} catch (std::exception&) {}
#endif
		}

		error_code ec;
		m_timer.expires_from_now(seconds(1), ec);
		m_timer.async_wait(bind(&dht_tracker::tick, self(), _1));

		m_connection_timer.expires_from_now(seconds(10), ec);
		m_connection_timer.async_wait(
			bind(&dht_tracker::connection_timeout, self(), _1));

		m_refresh_timer.expires_from_now(seconds(5), ec);
		m_refresh_timer.async_wait(bind(&dht_tracker::refresh_timeout, self(), _1));
		m_dht.bootstrap(initial_nodes, bind(&dht_tracker::on_bootstrap, self(), _1));
	}

	void dht_tracker::stop()
	{
		mutex_t::scoped_lock l(m_mutex);
		m_abort = true;
		error_code ec;
		m_timer.cancel(ec);
		m_connection_timer.cancel(ec);
		m_refresh_timer.cancel(ec);
		m_host_resolver.cancel();
	}

	void dht_tracker::dht_status(session_status& s)
	{
		mutex_t::scoped_lock l(m_mutex);
		m_dht.status(s);
	}

	void dht_tracker::network_stats(int& sent, int& received)
	{
		mutex_t::scoped_lock l(m_mutex);
		sent = m_sent_bytes;
		received = m_received_bytes;
		m_sent_bytes = 0;
		m_received_bytes = 0;
	}

	void dht_tracker::connection_timeout(error_code const& e)
	{
		mutex_t::scoped_lock l(m_mutex);
		if (e || m_abort) return;

		time_duration d = m_dht.connection_timeout();
		error_code ec;
		m_connection_timer.expires_from_now(d, ec);
		m_connection_timer.async_wait(bind(&dht_tracker::connection_timeout, self(), _1));
	}

	void dht_tracker::refresh_timeout(error_code const& e)
	{
		mutex_t::scoped_lock l(m_mutex);
		if (e || m_abort) return;

		time_duration d = m_dht.refresh_timeout();
		error_code ec;
		m_refresh_timer.expires_from_now(d, ec);
		m_refresh_timer.async_wait(
			bind(&dht_tracker::refresh_timeout, self(), _1));
	}

	void dht_tracker::tick(error_code const& e)
	{
		mutex_t::scoped_lock l(m_mutex);
		if (e || m_abort) return;

		error_code ec;
		m_timer.expires_from_now(minutes(tick_period), ec);
		m_timer.async_wait(bind(&dht_tracker::tick, self(), _1));

		ptime now = time_now();
		if (now - m_last_new_key > minutes(key_refresh))
		{
			m_last_new_key = now;
			m_dht.new_write_key();
#ifdef TORRENT_DHT_VERBOSE_LOGGING
			TORRENT_LOG(dht_tracker) << " *** new write key";
#endif
		}
		
#ifdef TORRENT_DHT_VERBOSE_LOGGING
		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 = std::distance(m_dht.begin_data(), m_dht.end_data());
		
		// count peers
		int peers = 0;
		std::for_each(m_dht.begin_data(), m_dht.end_data(), count_peers(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"
				":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;
		boost::tie(active, passive) = m_dht.size();
		pc << (m_counter * tick_period)
			<< "\t" << active
			<< "\t" << passive;
		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" << m_announces / float(tick_period)
			<< "\t" << m_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);
		m_announces = 0;
		m_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
		, boost::function<void(std::vector<tcp::endpoint> const&)> f)
	{
		mutex_t::scoped_lock l(m_mutex);
		m_dht.announce(ih, listen_port, f);
	}


	void dht_tracker::on_unreachable(udp::endpoint const& ep)
	{
		mutex_t::scoped_lock l(m_mutex);
		m_dht.unreachable(ep);
	}

	// translate bittorrent kademlia message into the generice kademlia message
	// used by the library
	void dht_tracker::on_receive(udp::endpoint const& ep, char const* buf, int bytes_transferred)
	{
		mutex_t::scoped_lock l(m_mutex);
		// account for IP and UDP overhead
		m_received_bytes += bytes_transferred + (ep.address().is_v6() ? 48 : 28);

		node_ban_entry* match = 0;
		node_ban_entry* min = m_ban_nodes;
		ptime now = time_now();
		for (node_ban_entry* i = m_ban_nodes; i < m_ban_nodes + num_ban_nodes; ++i)
		{
			if (i->src == ep.address())
			{
				match = i;
				break;
			}
			if (i->count < min->count) min = i;
		}

		if (match)
		{
			++match->count;
			if (match->count >= 20)
			{
				if (now < match->limit)
				{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
					if (match->count == 20)
					{
						TORRENT_LOG(dht_tracker) << " BANNING PEER [ ip: "
							<< ep << " time: " << total_milliseconds((now - match->limit) + seconds(5)) / 1000.f
							<< " count: " << match->count << " ]";
					}
#endif
					// we've received 20 messages in less than 5 seconds from
					// this node. Ignore it until it's silent for 5 minutes
					match->limit = now + minutes(5);
					return;
				}

				// we got 50 messages from this peer, but it was in
				// more than 5 seconds. Reset the counter and the timer
				match->count = 0;
				match->limit = now + seconds(5);
			}
		}
		else
		{
			min->count = 1;
			min->limit = now + seconds(5);
			min->src = ep.address();
		}

#ifdef TORRENT_DHT_VERBOSE_LOGGING
		++m_total_message_input;
		m_total_in_bytes += bytes_transferred;
#endif

		using libtorrent::entry;
		using libtorrent::bdecode;
			
		TORRENT_ASSERT(bytes_transferred > 0);

		lazy_entry e;
		int ret = lazy_bdecode(buf, buf + bytes_transferred, e);
		if (ret != 0)
		{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
			TORRENT_LOG(dht_tracker) << "<== " << ep << " ERROR: Invalid bencoding";
#endif
			return;
		}

		libtorrent::dht::msg m = {e, ep};

		if (e.type() != lazy_entry::dict_t)
		{
#ifdef TORRENT_DHT_VERBOSE_LOGGING
			TORRENT_LOG(dht_tracker) << "<== " << ep << " ERROR: not a dictionary: "
				<< print_entry(e, true);
#endif
			entry r;
			libtorrent::dht::incoming_error(r, "message is not a dictionary");
			send_packet(r, ep, 0);
			return;
		}

#ifdef TORRENT_DHT_VERBOSE_LOGGING
		parse_dht_client(e);
		TORRENT_LOG(dht_tracker) << "<== " << ep << " " << print_entry(e, true);
#endif

		m_dht.incoming(m);
	}

	entry dht_tracker::state() const
	{
		mutex_t::scoped_lock l(m_mutex);
		entry ret(entry::dictionary_t);
		{
			entry nodes(entry::list_t);
			for (node_impl::iterator i(m_dht.begin())
				, end(m_dht.end()); i != end; ++i)
			{
				std::string node;
				std::back_insert_iterator<std::string> out(node);
				write_endpoint(udp::endpoint(i->addr, i->port), out);
				nodes.list().push_back(entry(node));
			}
			bucket_t cache;
			m_dht.replacement_cache(cache);
			for (bucket_t::iterator i(cache.begin())
				, end(cache.end()); i != end; ++i)
			{
				std::string node;
				std::back_insert_iterator<std::string> out(node);
				write_endpoint(udp::endpoint(i->addr, i->port), out);
				nodes.list().push_back(entry(node));
			}
			if (!nodes.list().empty())
				ret["nodes"] = nodes;
		}

		char node_id[41];
		to_hex((char*)&m_dht.nid()[0], 20, node_id);
		ret["node-id"] = node_id;
		return ret;
	}

	void dht_tracker::add_node(udp::endpoint node)
	{
		mutex_t::scoped_lock l(m_mutex);
		m_dht.add_node(node);
	}

	void dht_tracker::add_node(std::pair<std::string, int> const& node)
	{
		mutex_t::scoped_lock l(m_mutex);
		udp::resolver::query q(node.first, lexical_cast<std::string>(node.second));
		m_host_resolver.async_resolve(q,
			bind(&dht_tracker::on_name_lookup, self(), _1, _2));
	}

	void dht_tracker::on_name_lookup(error_code const& e
		, udp::resolver::iterator host)
	{
		if (e || host == udp::resolver::iterator()) return;
		add_node(host->endpoint());
	}

	void dht_tracker::add_router_node(std::pair<std::string, int> const& node)
	{
		mutex_t::scoped_lock l(m_mutex);
		udp::resolver::query q(node.first, lexical_cast<std::string>(node.second));
		m_host_resolver.async_resolve(q,
			bind(&dht_tracker::on_router_name_lookup, self(), _1, _2));
	}

	void dht_tracker::on_router_name_lookup(error_code const& e
		, udp::resolver::iterator host)
	{
		if (e || host == udp::resolver::iterator()) return;
		m_dht.add_router_node(host->endpoint());
	}

	void dht_tracker::on_bootstrap(std::vector<std::pair<node_entry, std::string> > const&)
	{}

	void dht_tracker::send_packet(libtorrent::entry const& e, udp::endpoint const& addr, int send_flags)
	{
		using libtorrent::bencode;
		using libtorrent::entry;

		m_send_buf.clear();
		bencode(std::back_inserter(m_send_buf), e);

#ifdef TORRENT_DHT_VERBOSE_LOGGING
		std::stringstream log_line;
		lazy_entry print;
		int ret = lazy_bdecode(&m_send_buf[0], &m_send_buf[0] + m_send_buf.size(), print);
		TORRENT_ASSERT(ret == 0);
		log_line << print_entry(print, true);
#endif

		error_code ec;
		if (m_sock.send(addr, &m_send_buf[0], (int)m_send_buf.size(), ec, send_flags))
		{
			// account for IP and UDP overhead
			m_sent_bytes += m_send_buf.size() + (addr.address().is_v6() ? 48 : 28);

#ifdef TORRENT_DHT_VERBOSE_LOGGING
			m_total_out_bytes += m_send_buf.size();
		
			if (e["y"].string() == "r")
			{
				// TODO: fix this stats logging
//				++m_replies_sent[e["r"]];
//				m_replies_bytes_sent[e["r"]] += int(m_send_buf.size());
			}
			else if (e["y"].string() == "q")
			{
				m_queries_out_bytes += m_send_buf.size();
			}
			TORRENT_LOG(dht_tracker) << "==> " << addr << " " << log_line.str();
#endif
		}
#ifdef TORRENT_DHT_VERBOSE_LOGGING
		else
		{
			TORRENT_LOG(dht_tracker) << "==> " << addr << " DROPPED " << log_line.str();
		}
#endif
	}

}}