improved logging, fixed option to allow multiple connections from the same IP

ChangeLog

@@ -1,3 +1,9 @@
+	* logging now supports multiple sessions (different sessions now log
+	  to different directories).
+	* fixed random number generator seed problem, generating the same
+	  peer-id for sessions constructed the same second.
+	* added an option to accept multiple connections from the same IP.
+	* improved tracker logging.
 	* moved the file_pool into session. The number of open files is now
 	  limited per session.
 	* fixed uninitialized private flag in torrent_info

docs/manual.html

@@ -1733,7 +1733,7 @@ peers this client is connected to. The fractional part tells the share of
 pieces that have more copies than the rarest piece(s). For example: 2.5 would
 mean that the rarest pieces have only 2 copies among the peers this torrent is
 connected to, and that 50% of all the pieces have more than two copies.</p>
-<p>If sequenced download is activated (in <a class="reference" href="#session-settings">session_settings</a>), the distributed
+<p>If sequenced download is activated (see <a class="reference" href="#torrent-handle">torrent_handle</a>), the distributed
 copies will be saturated at the <tt class="docutils literal"><span class="pre">sequenced_download_threshold</span></tt>.</p>
 <p><tt class="docutils literal"><span class="pre">block_size</span></tt> is the size of a block, in bytes. A block is a sub piece, it
 is the number of bytes that each piece request asks for and the number of

docs/manual.rst

@@ -1706,7 +1706,7 @@ pieces that have more copies than the rarest piece(s). For example: 2.5 would
 mean that the rarest pieces have only 2 copies among the peers this torrent is
 connected to, and that 50% of all the pieces have more than two copies.
 
-If sequenced download is activated (in session_settings_), the distributed
+If sequenced download is activated (see torrent_handle_), the distributed
 copies will be saturated at the ``sequenced_download_threshold``.
 
 ``block_size`` is the size of a block, in bytes. A block is a sub piece, it

include/libtorrent/aux_/session_impl.hpp

@@ -149,6 +149,10 @@ namespace libtorrent
 			bool m_abort;
 		};
 
+#if defined(TORRENT_LOGGING) || defined(TORRENT_VERBOSE_LOGGING)
+		struct tracker_logger;
+#endif
+
 		// this is the link between the main thread and the
 		// thread started to run the main downloader loop
 		struct session_impl: boost::noncopyable
@@ -360,7 +364,12 @@ namespace libtorrent
 			void check_invariant(const char *place = 0);
 #endif
 #if defined(TORRENT_VERBOSE_LOGGING) || defined(TORRENT_LOGGING)
-			boost::shared_ptr<logger> create_log(std::string const& name, bool append = true);
+			boost::shared_ptr<logger> create_log(std::string const& name, int instance, bool append = true);
+			
+			// this list of tracker loggers serves as tracker_callbacks when
+			// shutting down. This list is just here to keep them alive during
+			// whe shutting down process
+			std::list<boost::shared_ptr<tracker_logger> > m_tracker_loggers;
 		public:
 			boost::shared_ptr<logger> m_logger;
 		private:
@@ -384,6 +393,61 @@ namespace libtorrent
 			// on all torrents before they start downloading
 			boost::scoped_ptr<boost::thread> m_checker_thread;
 		};
+		
+#if defined(TORRENT_LOGGING) || defined(TORRENT_VERBOSE_LOGGING)
+		struct tracker_logger : request_callback
+		{
+			tracker_logger(session_impl& ses): m_ses(ses) {}
+			void tracker_warning(std::string const& str)
+			{
+				debug_log("*** tracker warning: " + str);
+			}
+
+			void tracker_response(tracker_request const&
+				, std::vector<peer_entry>& peers
+				, int interval
+				, int complete
+				, int incomplete)
+			{
+				std::stringstream s;
+				s << "TRACKER RESPONSE:\n"
+					"interval: " << interval << "\n"
+					"peers:\n";
+				for (std::vector<peer_entry>::const_iterator i = peers.begin();
+					i != peers.end(); ++i)
+				{
+					s << "  " << std::setfill(' ') << std::setw(16) << i->ip
+						<< " " << std::setw(5) << std::dec << i->port << "  ";
+					if (!i->pid.is_all_zeros()) s << " " << i->pid;
+					s << "\n";
+				}
+				debug_log(s.str());
+			}
+
+			void tracker_request_timed_out(
+				tracker_request const&)
+			{
+				debug_log("*** tracker timed out");
+			}
+
+			void tracker_request_error(
+				tracker_request const&
+				, int response_code
+				, const std::string& str)
+			{
+				debug_log(std::string("*** tracker error: ")
+					+ boost::lexical_cast<std::string>(response_code) + ": "
+					+ str);
+			}
+			
+			void debug_log(const std::string& line)
+			{
+				(*m_ses.m_logger) << line << "\n";
+			}
+			session_impl& m_ses;
+		};
+#endif
+
 	}
 }
 

include/libtorrent/debug.hpp

@@ -67,10 +67,10 @@ namespace libtorrent
 
 	struct logger
 	{
-		logger(boost::filesystem::path const& filename, bool append = true)
+		logger(boost::filesystem::path const& filename, int instance, bool append = true)
 		{
 			using namespace boost::filesystem;
-			path dir(complete("libtorrent_logs"));
+			path dir(complete("libtorrent_logs" + boost::lexical_cast<std::string>(instance)));
 			if (!exists(dir)) create_directories(dir);
 			m_file.open(dir / filename, std::ios_base::out | (append ? std::ios_base::app : std::ios_base::out));
 			*this << "\n\n\n*** starting log ***\n";

include/libtorrent/file_pool.hpp

@@ -61,7 +61,7 @@ namespace libtorrent
 	namespace pt = boost::posix_time;
 	namespace fs = boost::filesystem;
 
-	struct file_pool
+	struct TORRENT_EXPORT file_pool : boost::noncopyable
 	{
 		file_pool(int size = 40): m_size(size) {}
 

include/libtorrent/storage.hpp

@@ -61,7 +61,7 @@ namespace libtorrent
 	}
 
 	class session;
-	class file_pool;
+	struct file_pool;
 
 #if defined(_WIN32) && defined(UNICODE)
 

src/file_pool.cpp

@@ -32,6 +32,8 @@ POSSIBILITY OF SUCH DAMAGE.
 
 #include "libtorrent/file_pool.hpp"
 
+#include <iostream>
+
 namespace libtorrent
 {
 	using boost::multi_index::nth_index;
@@ -39,7 +41,6 @@ namespace libtorrent
 
 	boost::shared_ptr<file> file_pool::open_file(void* st, fs::path const& p, file::open_mode m)
 	{
-	
 		assert(st != 0);
 		assert(p.is_complete());
 		typedef nth_index<file_set, 0>::type path_view;

src/http_tracker_connection.cpp

@@ -364,17 +364,21 @@ namespace libtorrent
 			m_send_buffer += base64encode(auth);
 		}
 		m_send_buffer += "\r\n\r\n";
+
 #if defined(TORRENT_VERBOSE_LOGGING) || defined(TORRENT_LOGGING)
 		if (has_requester())
 		{
 			requester().debug_log("==> TRACKER_REQUEST [ str: " + m_send_buffer + " ]");
 			std::stringstream info_hash_str;
 			info_hash_str << req.info_hash;
-			requester().debug_log("info_hash: " + info_hash_str.str() + "\n");
+			requester().debug_log("info_hash: "
+				+ boost::lexical_cast<std::string>(req.info_hash));
+			requester().debug_log("name lookup: " + *connect_to_host);
 		}
 #endif
 
-		tcp::resolver::query q(*connect_to_host, "0");
+		tcp::resolver::query q(*connect_to_host
+			, boost::lexical_cast<std::string>(m_port));
 		m_name_lookup.async_resolve(q
 			, boost::bind(&http_tracker_connection::name_lookup, self(), _1, _2));
 		set_timeout(m_settings.tracker_completion_timeout
@@ -392,6 +396,9 @@ namespace libtorrent
 	void http_tracker_connection::name_lookup(asio::error_code const& error
 		, tcp::resolver::iterator i) try
 	{
+#if defined(TORRENT_VERBOSE_LOGGING) || defined(TORRENT_LOGGING)
+		if (has_requester()) requester().debug_log("tracker name lookup handler called");
+#endif
 		if (error == asio::error::operation_aborted) return;
 		if (m_timed_out) return;
 
@@ -406,9 +413,8 @@ namespace libtorrent
 #endif
 		restart_read_timeout();
 		m_socket.reset(new stream_socket(m_name_lookup.io_service()));
-		tcp::endpoint a(i->endpoint().address(), m_port);
-		if (has_requester()) requester().m_tracker_address = a;
-		m_socket->async_connect(a, bind(&http_tracker_connection::connected, self(), _1));
+		if (has_requester()) requester().m_tracker_address = *i;
+		m_socket->async_connect(*i, bind(&http_tracker_connection::connected, self(), _1));
 	}
 	catch (std::exception& e)
 	{

src/peer_connection.cpp

@@ -125,7 +125,7 @@ namespace libtorrent
 	{
 #ifdef TORRENT_VERBOSE_LOGGING
 		m_logger = m_ses.create_log(m_remote.address().to_string() + "_"
-			+ boost::lexical_cast<std::string>(m_remote.port()));
+			+ boost::lexical_cast<std::string>(m_remote.port()), m_ses.listen_port());
 		(*m_logger) << "*** OUTGOING CONNECTION\n";
 #endif
 
@@ -219,7 +219,7 @@ namespace libtorrent
 #ifdef TORRENT_VERBOSE_LOGGING
 		assert(m_socket->remote_endpoint() == remote());
 		m_logger = m_ses.create_log(remote().address().to_string() + "_"
-			+ boost::lexical_cast<std::string>(remote().port()));
+			+ boost::lexical_cast<std::string>(remote().port()), m_ses.listen_port());
 		(*m_logger) << "*** INCOMING CONNECTION\n";
 #endif
 
@@ -1958,7 +1958,8 @@ namespace libtorrent
 		if (e)
 		{
 #if defined(TORRENT_VERBOSE_LOGGING) || defined(TORRENT_LOGGING)
-			(*m_ses.m_logger) << "CONNECTION FAILED: " << m_remote.address().to_string() << "\n";
+			(*m_ses.m_logger) << "CONNECTION FAILED: " << m_remote.address().to_string()
+				<< ": " << e.message() << "\n";
 #endif
 			m_ses.connection_failed(m_socket, m_remote, e.message().c_str());
 			return;

src/policy.cpp

@@ -325,23 +325,35 @@ namespace
 
 	struct match_peer_ip
 	{
-		match_peer_ip(const tcp::endpoint& ip)
+		match_peer_ip(tcp::endpoint const& ip)
 			: m_ip(ip)
 		{}
 
-		bool operator()(const policy::peer& p) const
+		bool operator()(policy::peer const& p) const
 		{ return p.ip.address() == m_ip.address(); }
 
 		tcp::endpoint m_ip;
 	};
 
+	struct match_peer_id
+	{
+		match_peer_id(peer_id const& id)
+			: m_id(id)
+		{}
+
+		bool operator()(policy::peer const& p) const
+		{ return p.connection && p.connection->pid() == m_id; }
+
+		peer_id m_id;
+	};
+
 	struct match_peer_connection
 	{
-		match_peer_connection(const peer_connection& c)
+		match_peer_connection(peer_connection const& c)
 			: m_conn(c)
 		{}
 
-		bool operator()(const policy::peer& p) const
+		bool operator()(policy::peer const& p) const
 		{ return p.connection == &m_conn; }
 
 		const peer_connection& m_conn;
@@ -900,7 +912,17 @@ namespace libtorrent
 
 		if (m_torrent->settings().allow_multiple_connections_per_ip)
 		{
-			i = m_peers.end();
+			if (c.pid().is_all_zeros())
+			{
+				i = m_peers.end();
+			}
+			else
+			{
+				i = std::find_if(
+					m_peers.begin()
+					, m_peers.end()
+					, match_peer_id(c.pid()));
+			}
 		}
 		else
 		{
@@ -970,10 +992,29 @@ namespace libtorrent
 
 		try
 		{
-			std::vector<peer>::iterator i = std::find_if(
-				m_peers.begin()
-				, m_peers.end()
-				, match_peer_ip(remote));
+			std::vector<peer>::iterator i;
+			
+			if (m_torrent->settings().allow_multiple_connections_per_ip)
+			{
+				if (pid.is_all_zeros())
+				{
+					i = m_peers.end();
+				}
+				else
+				{
+					i = std::find_if(
+						m_peers.begin()
+						, m_peers.end()
+						, match_peer_id(pid));
+				}
+			}
+			else
+			{
+				i = std::find_if(
+					m_peers.begin()
+					, m_peers.end()
+					, match_peer_ip(remote));
+			}
 			
 			bool just_added = false;
 			
@@ -1008,7 +1049,8 @@ namespace libtorrent
 
 #if defined(TORRENT_VERBOSE_LOGGING) || defined(TORRENT_LOGGING)
 					m_torrent->debug_log("already connected to peer: " + remote.address().to_string() + ":"
-						+ boost::lexical_cast<std::string>(remote.port()));
+						+ boost::lexical_cast<std::string>(remote.port()) + " "
+						+ boost::lexical_cast<std::string>(i->connection->pid()));
 #endif
 
 					assert(i->connection->associated_torrent().lock().get() == m_torrent);

src/session_impl.cpp

@@ -461,6 +461,12 @@ namespace libtorrent { namespace detail
 	}
 #endif
 
+	struct seed_random_generator
+	{
+		seed_random_generator()
+		{ std::srand((unsigned int)std::time(0)); }
+	};
+
 	session_impl::session_impl(
 		std::pair<int, int> listen_port_range
 		, fingerprint const& cl_fprint
@@ -482,14 +488,14 @@ namespace libtorrent { namespace detail
 	{
 
 #if defined(TORRENT_VERBOSE_LOGGING) || defined(TORRENT_LOGGING)
-		m_logger = create_log("main_session", false);
+		m_logger = create_log("main_session", listen_port(), false);
 		using boost::posix_time::second_clock;
 		using boost::posix_time::to_simple_string;
 		(*m_logger) << to_simple_string(second_clock::universal_time()) << "\n";
 #endif
 
 		// ---- generate a peer id ----
-		std::srand((unsigned int)std::time(0));
+		static seed_random_generator seeder;
 
 		m_key = rand() + (rand() << 15) + (rand() << 30);
 		std::string print = cl_fprint.to_string();
@@ -643,7 +649,7 @@ namespace libtorrent { namespace detail
 			if (m_alerts.should_post(alert::fatal))
 			{
 				m_alerts.post_alert(listen_failed_alert(
-					std::string("failed to open listen port") + e.what()));
+					std::string("failed to open listen port: ") + e.what()));
 			}
 		}
 
@@ -1068,7 +1074,13 @@ namespace libtorrent { namespace detail
 				req.listen_port = m_listen_interface.port();
 				req.key = m_key;
 				std::string login = i->second->tracker_login();
+#if defined(TORRENT_VERBOSE_LOGGING) || defined(TORRENT_LOGGING)
+				boost::shared_ptr<tracker_logger> tl(new tracker_logger(*this));
+				m_tracker_loggers.push_back(tl);
+				m_tracker_manager.queue_request(m_selector, req, login, tl);
+#else
 				m_tracker_manager.queue_request(m_selector, req, login);
+#endif
 			}
 		}
 
@@ -1132,10 +1144,11 @@ namespace libtorrent { namespace detail
 	}
 
 #if defined(TORRENT_VERBOSE_LOGGING) || defined(TORRENT_LOGGING)
-	boost::shared_ptr<logger> session_impl::create_log(std::string const& name, bool append)
+	boost::shared_ptr<logger> session_impl::create_log(std::string const& name
+		, int instance, bool append)
 	{
 		// current options are file_logger, cout_logger and null_logger
-		return boost::shared_ptr<logger>(new logger(name + ".log", append));
+		return boost::shared_ptr<logger>(new logger(name + ".log", instance, append));
 	}
 #endif
 
@@ -1344,8 +1357,16 @@ namespace libtorrent { namespace detail
 				assert(req.event == tracker_request::stopped);
 				req.listen_port = m_listen_interface.port();
 				req.key = m_key;
+
+#if defined(TORRENT_VERBOSE_LOGGING) || defined(TORRENT_LOGGING)
+				boost::shared_ptr<tracker_logger> tl(new tracker_logger(*this));
+				m_tracker_loggers.push_back(tl);
+				m_tracker_manager.queue_request(m_selector, req
+					, t.tracker_login(), tl);
+#else
 				m_tracker_manager.queue_request(m_selector, req
 					, t.tracker_login());
+#endif
 
 				if (m_alerts.should_post(alert::info))
 				{
@@ -1413,6 +1434,14 @@ namespace libtorrent { namespace detail
 		m_listen_interface = new_interface;
 
 		open_listen_port();
+
+#if defined(TORRENT_VERBOSE_LOGGING) || defined(TORRENT_LOGGING)
+		m_logger = create_log("main_session", listen_port(), false);
+		using boost::posix_time::second_clock;
+		using boost::posix_time::to_simple_string;
+		(*m_logger) << to_simple_string(second_clock::universal_time()) << "\n";
+#endif
+
 		return m_listen_socket;
 	}
 

src/storage.cpp

@@ -1097,7 +1097,7 @@ namespace libtorrent
 		, int& num_pieces
 		, const std::multimap<sha1_hash, int>& hash_to_piece)
 	{
-		INVARIANT_CHECK;
+//		INVARIANT_CHECK;
 
 		assert((int)have_pieces.size() == m_info.num_pieces());
 
@@ -1707,7 +1707,7 @@ namespace libtorrent
 		boost::recursive_mutex::scoped_lock lock(m_mutex);
 		// ----------------------------------------------------------------------
 
-		//		INVARIANT_CHECK;
+//		INVARIANT_CHECK;
 
 		assert(piece_index >= 0);
 		assert(piece_index < (int)m_piece_to_slot.size());
@@ -1866,7 +1866,7 @@ namespace libtorrent
 		boost::recursive_mutex::scoped_lock lock(m_mutex);
 		// ----------------------------------------------------------------------
 
-		//		INVARIANT_CHECK;
+//		INVARIANT_CHECK;
 
 		assert(!m_unallocated_slots.empty());