peer_connection log related optimization (#1086)

peer_connection log related optimization and making m_alert_mask atomic

include/libtorrent/alert_manager.hpp

@@ -43,6 +43,7 @@ POSSIBILITY OF SUCH DAMAGE.
 #include <utility> // for std::forward
 #include <mutex>
 #include <condition_variable>
+#include <atomic>
 
 namespace libtorrent {
 
@@ -81,26 +82,29 @@ namespace libtorrent {
 		template <class T>
 		bool should_post() const
 		{
+			if ((m_alert_mask.load(std::memory_order_relaxed)
+				& T::static_category) == 0)
+				return false;
+
 			std::lock_guard<std::mutex> lock(m_mutex);
 			if (m_alerts[m_generation].size() >= m_queue_size_limit
 				* (1 + T::priority))
 			{
 				return false;
 			}
-			return (m_alert_mask & T::static_category) != 0;
+
+			return true;
 		}
 
 		alert* wait_for_alert(time_duration max_wait);
 
 		void set_alert_mask(std::uint32_t m)
 		{
-			std::lock_guard<std::mutex> lock(m_mutex);
 			m_alert_mask = m;
 		}
 
 		std::uint32_t alert_mask() const
 		{
-			std::lock_guard<std::mutex> lock(m_mutex);
 			return m_alert_mask;
 		}
 
@@ -123,7 +127,7 @@ namespace libtorrent {
 
 		mutable std::mutex m_mutex;
 		std::condition_variable m_condition;
-		std::uint32_t m_alert_mask;
+		std::atomic<std::uint32_t> m_alert_mask;
 		int m_queue_size_limit;
 
 		// this function (if set) is called whenever the number of alerts in

include/libtorrent/peer_connection.hpp

@@ -414,7 +414,7 @@ namespace libtorrent
 		void keep_alive();
 
 		peer_id const& pid() const { return m_peer_id; }
-		void set_pid(const peer_id& peer_id) { m_peer_id = peer_id; }
+		void set_pid(peer_id const& peer_id) { m_peer_id = peer_id; }
 		bool has_piece(int i) const;
 
 		std::vector<pending_block> const& download_queue() const;
@@ -542,6 +542,7 @@ namespace libtorrent
 		int est_reciprocation_rate() const { return m_est_reciprocation_rate; }
 
 #ifndef TORRENT_DISABLE_LOGGING
+		bool should_log(peer_log_alert::direction_t direction) const;
 		void peer_log(peer_log_alert::direction_t direction
 			, char const* event, char const* fmt, ...) const TORRENT_FORMAT(4,5);
 		void peer_log(peer_log_alert::direction_t direction

include/libtorrent/peer_connection_handle.hpp

@@ -96,6 +96,7 @@ struct TORRENT_EXPORT peer_connection_handle
 
 #ifndef TORRENT_DISABLE_LOGGING
 
+	bool should_log(peer_log_alert::direction_t direction) const;
 	void peer_log(peer_log_alert::direction_t direction
 		, char const* event, char const* fmt = "", ...) const TORRENT_FORMAT(4,5);
 

include/libtorrent/peer_connection_interface.hpp

@@ -63,6 +63,7 @@ namespace libtorrent
 		virtual stat const& statistics() const = 0;
 		virtual void get_peer_info(peer_info& p) const = 0;
 #ifndef TORRENT_DISABLE_LOGGING
+		virtual bool should_log(peer_log_alert::direction_t direction) const = 0;
 		virtual void peer_log(peer_log_alert::direction_t direction
 			, char const* event, char const* fmt = "", ...) const TORRENT_FORMAT(4,5) = 0;
 #endif

src/bt_peer_connection.cpp

@@ -927,7 +927,7 @@ namespace libtorrent
 				// set the length of the request to not
 				// exceed the end of the torrent. This is
 				// necessary in order to maintain a correct
-				// m_outsanding_bytes
+				// m_outstanding_bytes
 				if (r.piece == t->torrent_file().num_pieces() - 1)
 				{
 					r.length = (std::min)(t->torrent_file().piece_size(
@@ -1046,7 +1046,7 @@ namespace libtorrent
 		TORRENT_ASSERT(t);
 
 		received_bytes(0, received);
-		// if we don't have the metedata, we cannot
+		// if we don't have the metadata, we cannot
 		// verify the bitfield size
 		if (t->valid_metadata()
 			&& m_recv_buffer.packet_size() - 1 != (t->torrent_file().num_pieces() + 7) / 8)
@@ -1592,7 +1592,6 @@ namespace libtorrent
 		detail::write_endpoint(ep, ptr);
 
 #ifndef TORRENT_DISABLE_LOGGING
-		error_code ec;
 		static const char* hp_msg_name[] = {"rendezvous", "connect", "failed"};
 		static const char* hp_error_string[] = {"", "no such peer", "not connected", "no support", "no self"};
 		peer_log(peer_log_alert::outgoing_message, "HOLEPUNCH"
@@ -2119,7 +2118,7 @@ namespace libtorrent
 
 		if (t->is_seed())
 		{
-			memset(ptr, 0xff, packet_size - 5);
+			std::memset(ptr, 0xff, packet_size - 5);
 
 			// Clear trailing bits
 			unsigned char *p = msg + packet_size - 1;
@@ -2127,7 +2126,7 @@ namespace libtorrent
 		}
 		else
 		{
-			memset(ptr, 0, packet_size - 5);
+			std::memset(ptr, 0, packet_size - 5);
 			piece_picker const& p = t->picker();
 			int mask = 0x80;
 			for (int i = 0; i < num_pieces; ++i)

src/peer_connection.cpp

@@ -85,14 +85,11 @@ using namespace std::placeholders;
 namespace libtorrent
 {
 
-	enum
-	{
-		// the limits of the download queue size
-		min_request_queue = 2
-	};
-
 	namespace {
 
+	// the limits of the download queue size
+	constexpr int min_request_queue = 2;
+
 	bool pending_block_in_buffer(pending_block const& pb)
 	{
 		return pb.send_buffer_offset != pending_block::not_in_buffer;
@@ -163,18 +160,21 @@ namespace libtorrent
 
 		TORRENT_ASSERT(pack.peerinfo == nullptr || pack.peerinfo->banned == false);
 #ifndef TORRENT_DISABLE_LOGGING
-		error_code ec;
+		if (should_log(m_outgoing ? peer_log_alert::outgoing : peer_log_alert::incoming))
-		TORRENT_ASSERT(m_socket->remote_endpoint(ec) == m_remote || ec);
+		{
-		tcp::endpoint local_ep = m_socket->local_endpoint(ec);
+			error_code ec;
+			TORRENT_ASSERT(m_socket->remote_endpoint(ec) == m_remote || ec);
+			tcp::endpoint local_ep = m_socket->local_endpoint(ec);
 
-		peer_log(m_outgoing ? peer_log_alert::outgoing : peer_log_alert::incoming
+			peer_log(m_outgoing ? peer_log_alert::outgoing : peer_log_alert::incoming
-			, m_outgoing ? "OUTGOING_CONNECTION" : "INCOMING_CONNECTION"
+				, m_outgoing ? "OUTGOING_CONNECTION" : "INCOMING_CONNECTION"
-			, "ep: %s type: %s seed: %d p: %p local: %s"
+				, "ep: %s type: %s seed: %d p: %p local: %s"
-			, print_endpoint(m_remote).c_str()
+				, print_endpoint(m_remote).c_str()
-			, m_socket->type_name()
+				, m_socket->type_name()
-			, m_peer_info ? m_peer_info->seed : 0
+				, m_peer_info ? m_peer_info->seed : 0
-			, static_cast<void*>(m_peer_info)
+				, static_cast<void*>(m_peer_info)
-			, print_endpoint(local_ep).c_str());
+				, print_endpoint(local_ep).c_str());
+		}
 #endif
 #if TORRENT_USE_ASSERTS
 		piece_failed = false;
@@ -272,8 +272,11 @@ namespace libtorrent
 			{
 				m_socket->set_option(type_of_service(m_settings.get_int(settings_pack::peer_tos)), ec);
 #ifndef TORRENT_DISABLE_LOGGING
-				peer_log(peer_log_alert::outgoing, "SET_TOS", "tos: %d e: %s"
+				if (should_log(peer_log_alert::outgoing))
-					, m_settings.get_int(settings_pack::peer_tos), ec.message().c_str());
+				{
+					peer_log(peer_log_alert::outgoing, "SET_TOS", "tos: %d e: %s"
+						, m_settings.get_int(settings_pack::peer_tos), ec.message().c_str());
+				}
 #endif
 			}
 #if TORRENT_USE_IPV6 && defined IPV6_TCLASS
@@ -285,17 +288,23 @@ namespace libtorrent
 		}
 
 #ifndef TORRENT_DISABLE_LOGGING
-		peer_log(peer_log_alert::info, "SET_PEER_CLASS", "a: %s"
+		if (should_log(peer_log_alert::info))
-			, print_address(m_remote.address()).c_str());
+		{
+			peer_log(peer_log_alert::info, "SET_PEER_CLASS", "a: %s"
+				, print_address(m_remote.address()).c_str());
+		}
 #endif
 
 		m_ses.set_peer_classes(this, m_remote.address(), m_socket->type());
 
 #ifndef TORRENT_DISABLE_LOGGING
-		for (int i = 0; i < num_classes(); ++i)
+		if (should_log(peer_log_alert::info))
 		{
-			peer_log(peer_log_alert::info, "CLASS", "%s"
+			for (int i = 0; i < num_classes(); ++i)
-				, m_ses.peer_classes().at(class_at(i))->label.c_str());
+			{
+				peer_log(peer_log_alert::info, "CLASS", "%s"
+					, m_ses.peer_classes().at(class_at(i))->label.c_str());
+			}
 		}
 #endif
 
@@ -322,9 +331,12 @@ namespace libtorrent
 		tcp::endpoint bound_ip = m_ses.bind_outgoing_socket(*m_socket
 			, m_remote.address(), ec);
 #ifndef TORRENT_DISABLE_LOGGING
-		peer_log(peer_log_alert::outgoing, "BIND", "dst: %s ec: %s"
+		if (should_log(peer_log_alert::outgoing))
-			, print_endpoint(bound_ip).c_str()
+		{
-			, ec.message().c_str());
+			peer_log(peer_log_alert::outgoing, "BIND", "dst: %s ec: %s"
+				, print_endpoint(bound_ip).c_str()
+				, ec.message().c_str());
+		}
 #else
 		TORRENT_UNUSED(bound_ip);
 #endif
@@ -335,8 +347,11 @@ namespace libtorrent
 		}
 
 #ifndef TORRENT_DISABLE_LOGGING
-		peer_log(peer_log_alert::outgoing, "ASYNC_CONNECT", "dst: %s"
+		if (should_log(peer_log_alert::outgoing))
-			, print_endpoint(m_remote).c_str());
+		{
+			peer_log(peer_log_alert::outgoing, "ASYNC_CONNECT", "dst: %s"
+				, print_endpoint(m_remote).c_str());
+		}
 #endif
 		ADD_OUTSTANDING_ASYNC("peer_connection::on_connection_complete");
 
@@ -358,8 +373,11 @@ namespace libtorrent
 				t->get_handle(), remote(), pid(), m_socket->type());
 		}
 #ifndef TORRENT_DISABLE_LOGGING
-		peer_log(peer_log_alert::info, "LOCAL ENDPOINT", "e: %s"
+		if (should_log(peer_log_alert::info))
-			, print_endpoint(m_socket->local_endpoint(ec)).c_str());
+		{
+			peer_log(peer_log_alert::info, "LOCAL ENDPOINT", "e: %s"
+				, print_endpoint(m_socket->local_endpoint(ec)).c_str());
+		}
 #endif
 	}
 
@@ -441,6 +459,11 @@ namespace libtorrent
 	}
 
 #ifndef TORRENT_DISABLE_LOGGING
+	bool peer_connection::should_log(peer_log_alert::direction_t) const
+	{
+		return m_ses.alerts().should_post<peer_log_alert>();
+	}
+
 	void peer_connection::peer_log(peer_log_alert::direction_t direction
 		, char const* event) const
 	{
@@ -1125,9 +1148,11 @@ namespace libtorrent
 		{
 			t = m_ses.delay_load_torrent(ih, this);
 #ifndef TORRENT_DISABLE_LOGGING
-			if (t)
+			if (t && should_log(peer_log_alert::info))
+			{
 				peer_log(peer_log_alert::info, "ATTACH"
 					, "Delay loaded torrent: %s:", aux::to_hex(ih).c_str());
+			}
 #endif
 		}
 
@@ -1135,9 +1160,12 @@ namespace libtorrent
 		{
 			// we couldn't find the torrent!
 #ifndef TORRENT_DISABLE_LOGGING
-			peer_log(peer_log_alert::info, "ATTACH"
+			if (should_log(peer_log_alert::info))
-				, "couldn't find a torrent with the given info_hash: %s torrents:"
+			{
-				, aux::to_hex(ih).c_str());
+				peer_log(peer_log_alert::info, "ATTACH"
+					, "couldn't find a torrent with the given info_hash: %s torrents:"
+					, aux::to_hex(ih).c_str());
+			}
 #endif
 
 #ifndef TORRENT_DISABLE_DHT
@@ -1326,10 +1354,9 @@ namespace libtorrent
 			// if the peer is not in parole mode, clear the queued
 			// up block requests
 			piece_picker& p = t->picker();
-			for (std::vector<pending_block>::const_iterator i = m_request_queue.begin()
+			for (auto const& r : m_request_queue)
-				, end(m_request_queue.end()); i != end; ++i)
 			{
-				p.abort_download(i->block, peer_info_struct());
+				p.abort_download(r.block, peer_info_struct());
 			}
 			m_request_queue.clear();
 			m_queued_time_critical = 0;
@@ -1338,10 +1365,10 @@ namespace libtorrent
 
 	namespace {
 
-	bool match_request(peer_request const& r, piece_block const& b, int block_size)
+	bool match_request(peer_request const& r, piece_block const& b, int const block_size)
 	{
-		if (int(b.piece_index) != r.piece) return false;
+		if (b.piece_index != r.piece) return false;
-		if (int(b.block_index) != r.start / block_size) return false;
+		if (b.block_index != r.start / block_size) return false;
 		if (r.start % block_size != 0) return false;
 		return true;
 	}
@@ -1637,9 +1664,12 @@ namespace libtorrent
 #ifndef TORRENT_DISABLE_LOGGING
 		else
 		{
-			peer_log(peer_log_alert::info, "UNCHOKE", "did not unchoke, the number of uploads (%d) "
+			if (should_log(peer_log_alert::info))
-				"is more than or equal to the limit (%d)"
+			{
-				, m_ses.num_uploads(), m_settings.get_int(settings_pack::unchoke_slots_limit));
+				peer_log(peer_log_alert::info, "UNCHOKE", "did not unchoke, the number of uploads (%d) "
+					"is more than or equal to the limit (%d)"
+					, m_ses.num_uploads(), m_settings.get_int(settings_pack::unchoke_slots_limit));
+			}
 		}
 #endif
 	}
@@ -1942,12 +1972,15 @@ namespace libtorrent
 		if (is_disconnecting()) return;
 
 #ifndef TORRENT_DISABLE_LOGGING
-		std::string bitfield_str;
+		if (should_log(peer_log_alert::incoming_message))
-		bitfield_str.resize(bits.size());
+		{
-		for (int i = 0; i < bits.size(); ++i)
+			std::string bitfield_str;
-			bitfield_str[i] = bits[i] ? '1' : '0';
+			bitfield_str.resize(bits.size());
-		peer_log(peer_log_alert::incoming_message, "BITFIELD"
+			for (int i = 0; i < bits.size(); ++i)
-			, "%s", bitfield_str.c_str());
+				bitfield_str[i] = bits[i] ? '1' : '0';
+			peer_log(peer_log_alert::incoming_message, "BITFIELD"
+				, "%s", bitfield_str.c_str());
+		}
 #endif
 
 		// if we don't have the metadata, we cannot
@@ -1956,9 +1989,12 @@ namespace libtorrent
 			&& bits.size() != m_have_piece.size())
 		{
 #ifndef TORRENT_DISABLE_LOGGING
-			peer_log(peer_log_alert::incoming_message, "BITFIELD"
+			if (should_log(peer_log_alert::incoming_message))
-				, "invalid size: %d expected %d", bits.size()
+			{
-				, m_have_piece.size());
+				peer_log(peer_log_alert::incoming_message, "BITFIELD"
+					, "invalid size: %d expected %d", bits.size()
+					, m_have_piece.size());
+			}
 #endif
 			disconnect(errors::invalid_bitfield_size, op_bittorrent, 2);
 			return;
@@ -2137,15 +2173,18 @@ namespace libtorrent
 			m_counters.inc_stats_counter(counters::invalid_piece_requests);
 			++m_num_invalid_requests;
 #ifndef TORRENT_DISABLE_LOGGING
-			peer_log(peer_log_alert::info, "INVALID_REQUEST", "piece not superseeded "
+			if (should_log(peer_log_alert::info))
-				"i: %d t: %d n: %d h: %d ss1: %d ss2: %d"
+			{
-				, m_peer_interested
+				peer_log(peer_log_alert::info, "INVALID_REQUEST", "piece not superseeded "
-				, valid_piece_index
+					"i: %d t: %d n: %d h: %d ss1: %d ss2: %d"
-					? t->torrent_file().piece_size(r.piece) : -1
+					, m_peer_interested
-				, t->torrent_file().num_pieces()
+					, valid_piece_index
-				, valid_piece_index ? t->has_piece_passed(r.piece) : 0
+						? t->torrent_file().piece_size(r.piece) : -1
-				, m_superseed_piece[0]
+					, t->torrent_file().num_pieces()
-				, m_superseed_piece[1]);
+					, valid_piece_index ? t->has_piece_passed(r.piece) : 0
+					, m_superseed_piece[0]
+					, m_superseed_piece[1]);
+			}
 #endif
 
 			write_reject_request(r);
@@ -2214,13 +2253,16 @@ namespace libtorrent
 		if (!m_peer_interested)
 		{
 #ifndef TORRENT_DISABLE_LOGGING
-			peer_log(peer_log_alert::info, "INVALID_REQUEST", "peer is not interested "
+			if (should_log(peer_log_alert::info))
-				" t: %d n: %d block_limit: %d"
+			{
-				, valid_piece_index
+				peer_log(peer_log_alert::info, "INVALID_REQUEST", "peer is not interested "
-					? t->torrent_file().piece_size(r.piece) : -1
+					" t: %d n: %d block_limit: %d"
-				, t->torrent_file().num_pieces()
+					, valid_piece_index
-				, t->block_size());
+						? t->torrent_file().piece_size(r.piece) : -1
-			peer_log(peer_log_alert::info, "INTERESTED", "artificial incoming INTERESTED message");
+					, t->torrent_file().num_pieces()
+					, t->block_size());
+				peer_log(peer_log_alert::info, "INTERESTED", "artificial incoming INTERESTED message");
+			}
 #endif
 			if (t->alerts().should_post<invalid_request_alert>())
 			{
@@ -2254,14 +2296,17 @@ namespace libtorrent
 			m_counters.inc_stats_counter(counters::invalid_piece_requests);
 
 #ifndef TORRENT_DISABLE_LOGGING
-			peer_log(peer_log_alert::info, "INVALID_REQUEST"
+			if (should_log(peer_log_alert::info))
-				, "i: %d t: %d n: %d h: %d block_limit: %d"
+			{
-				, m_peer_interested
+				peer_log(peer_log_alert::info, "INVALID_REQUEST"
-				, valid_piece_index
+					, "i: %d t: %d n: %d h: %d block_limit: %d"
-					? t->torrent_file().piece_size(r.piece) : -1
+					, m_peer_interested
-				, t->torrent_file().num_pieces()
+					, valid_piece_index
-				, t->has_piece_passed(r.piece)
+						? t->torrent_file().piece_size(r.piece) : -1
-				, t->block_size());
+					, t->torrent_file().num_pieces()
+					, t->has_piece_passed(r.piece)
+					, t->block_size());
+			}
 
 			peer_log(peer_log_alert::outgoing_message, "REJECT_PIECE"
 				, "piece: %d s: %d l: %d invalid request"
@@ -2598,9 +2643,12 @@ namespace libtorrent
 #endif
 
 #ifndef TORRENT_DISABLE_LOGGING
-		peer_log(peer_log_alert::incoming_message, "PIECE", "piece: %d s: %x l: %x ds: %d qs: %d q: %d"
+		if (should_log(peer_log_alert::incoming_message))
-			, p.piece, p.start, p.length, statistics().download_rate()
+		{
-			, int(m_desired_queue_size), int(m_download_queue.size()));
+			peer_log(peer_log_alert::incoming_message, "PIECE", "piece: %d s: %x l: %x ds: %d qs: %d q: %d"
+				, p.piece, p.start, p.length, statistics().download_rate()
+				, int(m_desired_queue_size), int(m_download_queue.size()));
+		}
 #endif
 
 		if (p.length == 0)
@@ -2700,8 +2748,11 @@ namespace libtorrent
 
 			m_request_time.add_sample(total_milliseconds(now - m_requested));
 #ifndef TORRENT_DISABLE_LOGGING
-			peer_log(peer_log_alert::info, "REQUEST_TIME", "%d +- %d ms"
+			if (should_log(peer_log_alert::info))
-				, m_request_time.mean(), m_request_time.avg_deviation());
+			{
+				peer_log(peer_log_alert::info, "REQUEST_TIME", "%d +- %d ms"
+					, m_request_time.mean(), m_request_time.avg_deviation());
+			}
 #endif
 
 			// we completed an incoming block, and there are still outstanding
@@ -2731,6 +2782,7 @@ namespace libtorrent
 		}
 
 #ifndef TORRENT_DISABLE_LOGGING
+		// TODO: filter torrent expensive debug log
 		t->debug_log("PIECE [%p] (%d ms) (%d)", static_cast<void*>(this)
 			, int(total_milliseconds(now - m_unchoke_time)), t->num_have());
 
@@ -2770,8 +2822,11 @@ namespace libtorrent
 
 		m_request_time.add_sample(total_milliseconds(now - m_requested));
 #ifndef TORRENT_DISABLE_LOGGING
-		peer_log(peer_log_alert::info, "REQUEST_TIME", "%d +- %d ms"
+		if (should_log(peer_log_alert::info))
-			, m_request_time.mean(), m_request_time.avg_deviation());
+		{
+			peer_log(peer_log_alert::info, "REQUEST_TIME", "%d +- %d ms"
+				, m_request_time.mean(), m_request_time.avg_deviation());
+		}
 #endif
 
 		// we completed an incoming block, and there are still outstanding
@@ -2888,8 +2943,11 @@ namespace libtorrent
 		if (t) t->dec_refcount("async_write");
 
 #ifndef TORRENT_DISABLE_LOGGING
-		peer_log(peer_log_alert::info, "FILE_ASYNC_WRITE_COMPLETE", "ret: %d piece: %d s: %x l: %x e: %s"
+		if (should_log(peer_log_alert::info))
-			, j->ret, p.piece, p.start, p.length, j->error.ec.message().c_str());
+		{
+			peer_log(peer_log_alert::info, "FILE_ASYNC_WRITE_COMPLETE", "ret: %d piece: %d s: %x l: %x e: %s"
+				, j->ret, p.piece, p.start, p.length, j->error.ec.message().c_str());
+		}
 #endif
 
 		m_counters.inc_stats_counter(counters::queued_write_bytes, -p.length);
@@ -3862,11 +3920,14 @@ namespace libtorrent
 			}
 
 #ifndef TORRENT_DISABLE_LOGGING
-			peer_log(peer_log_alert::outgoing_message, "REQUEST"
+			if (should_log(peer_log_alert::outgoing_message))
-				, "piece: %d s: %x l: %x ds: %dB/s dqs: %d rqs: %d blk: %s"
+			{
-				, r.piece, r.start, r.length, statistics().download_rate()
+				peer_log(peer_log_alert::outgoing_message, "REQUEST"
-				, int(m_desired_queue_size), int(m_download_queue.size())
+					, "piece: %d s: %x l: %x ds: %dB/s dqs: %d rqs: %d blk: %s"
-				, m_request_large_blocks?"large":"single");
+					, r.piece, r.start, r.length, statistics().download_rate()
+					, int(m_desired_queue_size), int(m_download_queue.size())
+					, m_request_large_blocks?"large":"single");
+			}
 #endif
 		}
 		m_last_piece = aux::time_now();
@@ -3890,10 +3951,14 @@ namespace libtorrent
 		TORRENT_ASSERT(e);
 
 #ifndef TORRENT_DISABLE_LOGGING
-		peer_log(peer_log_alert::info, "CONNECTION FAILED"
+		if (should_log(peer_log_alert::info))
-			, "%s", print_endpoint(m_remote).c_str());
+		{
+			peer_log(peer_log_alert::info, "CONNECTION FAILED"
+				, "%s", print_endpoint(m_remote).c_str());
+		}
 #endif
 #ifndef TORRENT_DISABLE_LOGGING
+		// TODO: filter session log
 		m_ses.session_log("CONNECTION FAILED: %s", print_endpoint(m_remote).c_str());
 #endif
 
@@ -3974,29 +4039,32 @@ namespace libtorrent
 		torrent_peer* self_peer = peer_info_struct();
 
 #ifndef TORRENT_DISABLE_LOGGING
-		switch (error)
+		if (should_log(peer_log_alert::info))
 		{
-		case 0:
+			switch (error)
-			peer_log(peer_log_alert::info, "CONNECTION_CLOSED", "op: %d error: %s"
+			{
-				, op, ec.message().c_str());
+			case 0:
-			break;
+				peer_log(peer_log_alert::info, "CONNECTION_CLOSED", "op: %d error: %s"
-		case 1:
+					, op, ec.message().c_str());
-			peer_log(peer_log_alert::info, "CONNECTION_FAILED", "op: %d error: %s"
+				break;
-				, op, ec.message().c_str());
+			case 1:
-			break;
+				peer_log(peer_log_alert::info, "CONNECTION_FAILED", "op: %d error: %s"
-		case 2:
+					, op, ec.message().c_str());
-			peer_log(peer_log_alert::info, "PEER_ERROR" ,"op: %d error: %s"
+				break;
-				, op, ec.message().c_str());
+			case 2:
-			break;
+				peer_log(peer_log_alert::info, "PEER_ERROR" ,"op: %d error: %s"
-		}
+					, op, ec.message().c_str());
+				break;
+			}
 
-		if (ec == error_code(boost::asio::error::eof
+			if (ec == error_code(boost::asio::error::eof
-			, boost::asio::error::get_misc_category())
+				, boost::asio::error::get_misc_category())
-			&& !in_handshake()
+				&& !in_handshake()
-			&& !is_connecting()
+				&& !is_connecting()
-			&& aux::time_now() - connected_time() < seconds(15))
+				&& aux::time_now() - connected_time() < seconds(15))
-		{
+			{
-			peer_log(peer_log_alert::info, "SHORT_LIVED_DISCONNECT", "");
+				peer_log(peer_log_alert::info, "SHORT_LIVED_DISCONNECT", "");
+			}
 		}
 #endif
 
@@ -4722,8 +4790,11 @@ namespace libtorrent
 			&& can_disconnect(error_code(errors::timed_out_no_interest)))
 		{
 #ifndef TORRENT_DISABLE_LOGGING
-			peer_log(peer_log_alert::info, "MUTUAL_NO_INTEREST", "t1: %d t2: %d"
+			if (should_log(peer_log_alert::info))
-				, int(total_seconds(d1)), int(total_seconds(d2)));
+			{
+				peer_log(peer_log_alert::info, "MUTUAL_NO_INTEREST", "t1: %d t2: %d"
+					, int(total_seconds(d1)), int(total_seconds(d2)));
+			}
 #endif
 			disconnect(errors::timed_out_no_interest, op_bittorrent);
 			return;
@@ -4753,10 +4824,13 @@ namespace libtorrent
 		{
 			m_slow_start = false;
 #ifndef TORRENT_DISABLE_LOGGING
-			peer_log(peer_log_alert::info, "SLOW_START", "exit slow start: "
+			if (should_log(peer_log_alert::info))
-				"prev-dl: %d dl: %d"
+			{
-				, int(m_downloaded_last_second)
+				peer_log(peer_log_alert::info, "SLOW_START", "exit slow start: "
-				, m_statistics.last_payload_downloaded());
+					"prev-dl: %d dl: %d"
+					, int(m_downloaded_last_second)
+					, m_statistics.last_payload_downloaded());
+			}
 #endif
 		}
 		m_downloaded_last_second = m_statistics.last_payload_downloaded();
@@ -4796,10 +4870,13 @@ namespace libtorrent
 			// in this case we'll clear our download queue and
 			// re-request the blocks.
 #ifndef TORRENT_DISABLE_LOGGING
-			peer_log(peer_log_alert::info, "PIECE_REQUEST_TIMED_OUT"
+			if (should_log(peer_log_alert::info))
-				, "%d time: %d to: %d"
+			{
-				, int(m_download_queue.size()), int(total_seconds(now - m_last_piece))
+				peer_log(peer_log_alert::info, "PIECE_REQUEST_TIMED_OUT"
-				, piece_timeout);
+					, "%d time: %d to: %d"
+					, int(m_download_queue.size()), int(total_seconds(now - m_last_piece))
+					, piece_timeout);
+			}
 #endif
 
 			snub_peer();
@@ -4932,13 +5009,16 @@ namespace libtorrent
 		}
 
 #ifndef TORRENT_DISABLE_LOGGING
-		peer_log(peer_log_alert::outgoing, "SEND_BUFFER_WATERMARK"
+		if (should_log(peer_log_alert::outgoing))
-			, "current watermark: %d max: %d min: %d factor: %d uploaded: %d B/s"
+		{
-			, buffer_size_watermark
+			peer_log(peer_log_alert::outgoing, "SEND_BUFFER_WATERMARK"
-			, m_ses.settings().get_int(settings_pack::send_buffer_watermark)
+				, "current watermark: %d max: %d min: %d factor: %d uploaded: %d B/s"
-			, m_ses.settings().get_int(settings_pack::send_buffer_low_watermark)
+				, buffer_size_watermark
-			, m_ses.settings().get_int(settings_pack::send_buffer_watermark_factor)
+				, m_ses.settings().get_int(settings_pack::send_buffer_watermark)
-			, int(m_uploaded_last_second));
+				, m_ses.settings().get_int(settings_pack::send_buffer_low_watermark)
+				, m_ses.settings().get_int(settings_pack::send_buffer_watermark_factor)
+				, int(m_uploaded_last_second));
+		}
 #endif
 
 		// don't just pop the front element here, since in seed mode one request may
@@ -5114,12 +5194,15 @@ namespace libtorrent
 		int const disk_rtt = int(total_microseconds(clock_type::now() - issue_time));
 
 #ifndef TORRENT_DISABLE_LOGGING
-		peer_log(peer_log_alert::info, "FILE_ASYNC_READ_COMPLETE"
+		if (should_log(peer_log_alert::info))
-			, "ret: %d piece: %d s: %x l: %x b: %p c: %s e: %s rtt: %d us"
+		{
-			, j->ret, r.piece, r.start, r.length
+			peer_log(peer_log_alert::info, "FILE_ASYNC_READ_COMPLETE"
-			, static_cast<void*>(j->buffer.disk_block)
+				, "ret: %d piece: %d s: %x l: %x b: %p c: %s e: %s rtt: %d us"
-			, (j->flags & disk_io_job::cache_hit ? "cache hit" : "cache miss")
+				, j->ret, r.piece, r.start, r.length
-			, j->error.ec.message().c_str(), disk_rtt);
+				, static_cast<void*>(j->buffer.disk_block)
+				, (j->flags & disk_io_job::cache_hit ? "cache hit" : "cache miss")
+				, j->error.ec.message().c_str(), disk_rtt);
+		}
 #endif
 
 		m_reading_bytes -= r.length;
@@ -5317,12 +5400,15 @@ namespace libtorrent
 		if (ret == 0)
 		{
 #ifndef TORRENT_DISABLE_LOGGING
-			peer_log(
+			auto const dir = channel == download_channel ? peer_log_alert::incoming
-				channel == download_channel ? peer_log_alert::incoming
+				: peer_log_alert::outgoing;
-					: peer_log_alert::outgoing,
+			if (should_log(dir))
-				"REQUEST_BANDWIDTH", "bytes: %d quota: %d wanted_transfer: %d "
+			{
-				"prio: %d num_channels: %d", bytes, m_quota[channel]
+				peer_log(dir,
-				, wanted_transfer(channel), priority, c);
+					"REQUEST_BANDWIDTH", "bytes: %d quota: %d wanted_transfer: %d "
+					"prio: %d num_channels: %d", bytes, m_quota[channel]
+					, wanted_transfer(channel), priority, c);
+			}
 #endif
 			m_channel_state[channel] |= peer_info::bw_limit;
 		}
@@ -5427,24 +5513,27 @@ namespace libtorrent
 		if (!can_write())
 		{
 #ifndef TORRENT_DISABLE_LOGGING
-			if (m_send_buffer.empty())
+			if (should_log(peer_log_alert::outgoing))
 			{
-				peer_log(peer_log_alert::outgoing, "SEND_BUFFER_DEPLETED"
+				if (m_send_buffer.empty())
-					, "quota: %d buf: %d connecting: %s disconnecting: %s "
+				{
-					"pending_disk: %d piece-requests: %d"
+					peer_log(peer_log_alert::outgoing, "SEND_BUFFER_DEPLETED"
-					, m_quota[upload_channel]
+						, "quota: %d buf: %d connecting: %s disconnecting: %s "
-					, m_send_buffer.size(), m_connecting?"yes":"no"
+						"pending_disk: %d piece-requests: %d"
-					, m_disconnecting?"yes":"no", m_reading_bytes
+						, m_quota[upload_channel]
-					, int(m_requests.size()));
+						, m_send_buffer.size(), m_connecting?"yes":"no"
-			}
+						, m_disconnecting?"yes":"no", m_reading_bytes
-			else
+						, int(m_requests.size()));
-			{
+				}
-				peer_log(peer_log_alert::outgoing, "CANNOT_WRITE"
+				else
-					, "quota: %d buf: %d connecting: %s disconnecting: %s "
+				{
-					"pending_disk: %d"
+					peer_log(peer_log_alert::outgoing, "CANNOT_WRITE"
-					, m_quota[upload_channel]
+						, "quota: %d buf: %d connecting: %s disconnecting: %s "
-					, m_send_buffer.size(), m_connecting?"yes":"no"
+						"pending_disk: %d"
-					, m_disconnecting?"yes":"no", m_reading_bytes);
+						, m_quota[upload_channel]
+						, m_send_buffer.size(), m_connecting?"yes":"no"
+						, m_disconnecting?"yes":"no", m_reading_bytes);
+				}
 			}
 #endif
 			return;
@@ -5528,14 +5617,17 @@ namespace libtorrent
 		if (!can_read())
 		{
 #ifndef TORRENT_DISABLE_LOGGING
-			peer_log(peer_log_alert::incoming, "CANNOT_READ", "quota: %d  "
+			if (should_log(peer_log_alert::incoming))
-				"can-write-to-disk: %s queue-limit: %d disconnecting: %s "
+			{
-				" connecting: %s"
+				peer_log(peer_log_alert::incoming, "CANNOT_READ", "quota: %d  "
-				, m_quota[download_channel]
+					"can-write-to-disk: %s queue-limit: %d disconnecting: %s "
-				, ((m_channel_state[download_channel] & peer_info::bw_disk)?"no":"yes")
+					" connecting: %s"
-				, m_settings.get_int(settings_pack::max_queued_disk_bytes)
+					, m_quota[download_channel]
-				, (m_disconnecting?"yes":"no")
+					, ((m_channel_state[download_channel] & peer_info::bw_disk)?"no":"yes")
-				, (m_connecting?"yes":"no"));
+					, m_settings.get_int(settings_pack::max_queued_disk_bytes)
+					, (m_disconnecting?"yes":"no")
+					, (m_connecting?"yes":"no"));
+			}
 #endif
 			// if we block reading, waiting for the disk, we will wake up
 			// by the disk_io_thread posting a message every time it drops
@@ -5632,7 +5724,7 @@ namespace libtorrent
 
 			const int alloc_buf_size = m_ses.send_buffer_size();
 			int buf_size = (std::min)(alloc_buf_size, size);
-			memcpy(chain_buf, buf, buf_size);
+			std::memcpy(chain_buf, buf, buf_size);
 			buf += buf_size;
 			size -= buf_size;
 			m_send_buffer.append_buffer(chain_buf, alloc_buf_size, buf_size
@@ -5675,10 +5767,13 @@ namespace libtorrent
 		COMPLETE_ASYNC("peer_connection::on_receive_data");
 
 #ifndef TORRENT_DISABLE_LOGGING
-		peer_log(peer_log_alert::incoming, "ON_RECEIVE_DATA"
+		if (should_log(peer_log_alert::incoming))
-			, "bytes: %d error: (%s:%d) %s"
+		{
-			, int(bytes_transferred), error.category().name(), error.value()
+			peer_log(peer_log_alert::incoming, "ON_RECEIVE_DATA"
-			, error.message().c_str());
+				, "bytes: %d error: (%s:%d) %s"
+				, int(bytes_transferred), error.category().name(), error.value()
+				, error.message().c_str());
+		}
 #endif
 
 		// leave this bit set until we're done looping, reading from the socket.
@@ -5695,9 +5790,12 @@ namespace libtorrent
 		if (error)
 		{
 #ifndef TORRENT_DISABLE_LOGGING
-			peer_log(peer_log_alert::info, "ERROR"
+			if (should_log(peer_log_alert::info))
-				, "in peer_connection::on_receive_data_impl error: %s"
+			{
-				, error.message().c_str());
+				peer_log(peer_log_alert::info, "ERROR"
+					, "in peer_connection::on_receive_data_impl error: %s"
+					, error.message().c_str());
+			}
 #endif
 			on_receive(error, bytes_transferred);
 			disconnect(error, op_sock_read);
@@ -5764,8 +5862,11 @@ namespace libtorrent
 				if (bytes == 0 && !ec) ec = boost::asio::error::eof;
 
 #ifndef TORRENT_DISABLE_LOGGING
-				peer_log(peer_log_alert::incoming, "SYNC_READ", "max: %d ret: %d e: %s"
+				if (should_log(peer_log_alert::incoming))
-					, int(buffer_size), int(bytes), ec ? ec.message().c_str() : "");
+				{
+					peer_log(peer_log_alert::incoming, "SYNC_READ", "max: %d ret: %d e: %s"
+						, int(buffer_size), int(bytes), ec ? ec.message().c_str() : "");
+				}
 #endif
 
 				TORRENT_ASSERT(bytes > 0 || ec);
@@ -5966,8 +6067,11 @@ namespace libtorrent
 
 		TORRENT_ASSERT(m_socket);
 #ifndef TORRENT_DISABLE_LOGGING
-		peer_log(peer_log_alert::outgoing, "COMPLETED"
+		if (should_log(peer_log_alert::outgoing))
-			, "ep: %s", print_endpoint(m_remote).c_str());
+		{
+			peer_log(peer_log_alert::outgoing, "COMPLETED"
+				, "ep: %s", print_endpoint(m_remote).c_str());
+		}
 #endif
 
 		// set the socket to non-blocking, so that we can
@@ -5997,8 +6101,11 @@ namespace libtorrent
 			error_code err;
 			m_socket->set_option(type_of_service(m_settings.get_int(settings_pack::peer_tos)), err);
 #ifndef TORRENT_DISABLE_LOGGING
-			peer_log(peer_log_alert::outgoing, "SET_TOS", "tos: %d e: %s"
+			if (should_log(peer_log_alert::outgoing))
-				, m_settings.get_int(settings_pack::peer_tos), err.message().c_str());
+			{
+				peer_log(peer_log_alert::outgoing, "SET_TOS", "tos: %d e: %s"
+					, m_settings.get_int(settings_pack::peer_tos), err.message().c_str());
+			}
 #endif
 		}
 #if TORRENT_USE_IPV6 && defined IPV6_TCLASS
@@ -6007,8 +6114,11 @@ namespace libtorrent
 			error_code err;
 			m_socket->set_option(traffic_class(m_settings.get_int(settings_pack::peer_tos)), err);
 #ifndef TORRENT_DISABLE_LOGGING
-			peer_log(peer_log_alert::outgoing, "SET_TOS", "tos: %d e: %s"
+			if (should_log(peer_log_alert::outgoing))
-				, m_settings.get_int(settings_pack::peer_tos), err.message().c_str());
+			{
+				peer_log(peer_log_alert::outgoing, "SET_TOS", "tos: %d e: %s"
+					, m_settings.get_int(settings_pack::peer_tos), err.message().c_str());
+			}
 #endif
 		}
 #endif
@@ -6046,8 +6156,11 @@ namespace libtorrent
 		m_ses.deferred_submit_jobs();
 
 #ifndef TORRENT_DISABLE_LOGGING
-		peer_log(peer_log_alert::info, "ON_SEND_DATA", "bytes: %d error: %s"
+		if (should_log(peer_log_alert::info))
-			, int(bytes_transferred), error.message().c_str());
+		{
+			peer_log(peer_log_alert::info, "ON_SEND_DATA", "bytes: %d error: %s"
+				, int(bytes_transferred), error.message().c_str());
+		}
 #endif
 
 		INVARIANT_CHECK;
@@ -6091,8 +6204,11 @@ namespace libtorrent
 		if (error)
 		{
 #ifndef TORRENT_DISABLE_LOGGING
-			peer_log(peer_log_alert::info, "ERROR"
+			if (should_log(peer_log_alert::info))
-				, "%s in peer_connection::on_send_data", error.message().c_str());
+			{
+				peer_log(peer_log_alert::info, "ERROR"
+					, "%s in peer_connection::on_send_data", error.message().c_str());
+			}
 #endif
 			disconnect(error, op_sock_write);
 			return;

src/peer_connection_handle.cpp

@@ -210,6 +210,13 @@ bool peer_connection_handle::failed() const
 
 #ifndef TORRENT_DISABLE_LOGGING
 
+bool peer_connection_handle::should_log(peer_log_alert::direction_t direction) const
+{
+	std::shared_ptr<peer_connection> pc = native_handle();
+	TORRENT_ASSERT(pc);
+	return pc->should_log(direction);
+}
+
 TORRENT_FORMAT(4,5)
 void peer_connection_handle::peer_log(peer_log_alert::direction_t direction
 	, char const* event, char const* fmt, ...) const

src/torrent.cpp

@@ -8934,10 +8934,17 @@ namespace libtorrent
 	void torrent::log_to_all_peers(char const* message)
 	{
 		TORRENT_ASSERT(is_single_thread());
-		for (peer_iterator i = m_connections.begin();
+
-				i != m_connections.end(); ++i)
+		auto it = m_connections.begin();
+		bool log_peers = it != m_connections.end()
+			&& (*it)->should_log(peer_log_alert::info);
+
+		if (log_peers)
 		{
-			(*i)->peer_log(peer_log_alert::info, "TORRENT", "%s", message);
+			for (auto const& c : m_connections)
+			{
+				c->peer_log(peer_log_alert::info, "TORRENT", "%s", message);
+			}
 		}
 
 		debug_log("%s", message);

test/test_peer_list.cpp

@@ -70,6 +70,9 @@ struct mock_peer_connection
 	virtual ~mock_peer_connection() = default;
 
 #if !defined TORRENT_DISABLE_LOGGING
+	bool should_log(peer_log_alert::direction_t) const override
+	{ return true; }
+
 	void peer_log(peer_log_alert::direction_t dir, char const* event
 		, char const* fmt, ...) const override
 	{