keep track of where redundant downloads come from. make the timing out of block requests more reasonable in an attempt to actually complete pieces from other peers when stuck on a slow one

include/libtorrent/aux_/session_impl.hpp

@@ -446,10 +446,11 @@ namespace libtorrent
 
 			int next_port();
 
-			void add_redundant_bytes(size_type b)
+			void add_redundant_bytes(size_type b, int reason)
 			{
 				TORRENT_ASSERT(b > 0);
 				m_total_redundant_bytes += b;
+				m_redundant_bytes[reason] += b;
 			}
 
 			void add_failed_bytes(size_type b)
@@ -1064,6 +1065,9 @@ namespace libtorrent
 			size_type m_total_failed_bytes;
 			size_type m_total_redundant_bytes;
 
+			// redundant bytes per category
+			size_type m_redundant_bytes[7];
+
 			std::vector<boost::shared_ptr<feed> > m_feeds;
 
 			// this is the set of (subscribed) torrents that have changed

include/libtorrent/torrent.hpp

@@ -675,7 +675,12 @@ namespace libtorrent
 		// this is done when a piece fails
 		void restore_piece_state(int index);
 
-		void add_redundant_bytes(int b);
+		enum wasted_reason_t
+		{
+			piece_timed_out, piece_cancelled, piece_unknown, piece_seed, piece_end_game, piece_closing
+			, waste_reason_max
+		};
+		void add_redundant_bytes(int b, wasted_reason_t reason);
 		void add_failed_bytes(int b);
 
 		// this is true if we have all the pieces

parse_session_stats.py

@@ -134,6 +134,7 @@ reports = [
 	('peers_download', 'num', '', 'number of peers by state wrt. downloading', ['peers down interesting', 'peers down unchoked', 'peers down requests', 'peers disk-down', 'peers bw-down','num end-game peers']),
 	('peer_errors', 'num', '', 'number of peers by error that disconnected them', ['error peers', 'peer disconnects', 'peers eof', 'peers connection reset', 'connect timeouts', 'uninteresting peers disconnect', 'banned for hash failure']),
 	('waste', '% of all downloaded bytes', '%%', 'proportion of all downloaded bytes that were wasted', ['% failed payload bytes', '% wasted payload bytes', '% protocol bytes']),
+	('waste by source', '% of all wasted bytes', '%%', 'what\' causing the waste', [ 'redundant timed-out', 'redundant cancelled', 'redundant unknown', 'redundant seed', 'redundant end-game', 'redundant closing']),
 	('average_disk_time_absolute', 'job time', 's', 'running averages of timings of disk operations', ['disk read time', 'disk write time', 'disk hash time', 'disk job time', 'disk sort time']),
 	('average_disk_queue_time', 'job queued time', 's', 'running averages of disk queue time', ['disk queue time', 'disk job time']),
 	('disk_time', '% of total disk job time', '%%', 'proportion of time spent by the disk thread', ['% read time', '% write time', '% hash time', '% sort time']),

src/peer_connection.cpp

@@ -2347,7 +2347,7 @@ namespace libtorrent
 			m_received_in_piece = 0;
 #endif
 			if (!m_download_queue.empty()) m_download_queue.erase(m_download_queue.begin());
-			t->add_redundant_bytes(p.length);
+			t->add_redundant_bytes(p.length, torrent::piece_seed);
 			return;
 		}
 
@@ -2380,7 +2380,7 @@ namespace libtorrent
 			TORRENT_ASSERT_VAL(m_received_in_piece == p.length, m_received_in_piece);
 			m_received_in_piece = 0;
 #endif
-			t->add_redundant_bytes(p.length);
+			t->add_redundant_bytes(p.length, torrent::piece_unknown);
 			return;
 		}
 
@@ -2444,7 +2444,13 @@ namespace libtorrent
 		// if the block we got is already finished, then ignore it
 		if (picker.is_downloaded(block_finished))
 		{
-			t->add_redundant_bytes(p.length);
+			torrent::wasted_reason_t reason;
+			if (b->timed_out) reason = torrent::piece_timed_out;
+			else if (b->not_wanted) reason = torrent::piece_cancelled;
+			else if (b->busy) reason = torrent::piece_end_game;
+			else reason = torrent::piece_unknown;
+
+			t->add_redundant_bytes(p.length, reason);
 
 			m_download_queue.erase(b);
 			m_timeout_extend = 0;
@@ -3515,7 +3521,7 @@ namespace libtorrent
 					&& pbp->bytes_downloaded > 0
 					&& pbp->bytes_downloaded < pbp->full_block_bytes)
 				{
-					t->add_redundant_bytes(pbp->bytes_downloaded);
+					t->add_redundant_bytes(pbp->bytes_downloaded, torrent::piece_closing);
 				}
 			}
 
@@ -4267,7 +4273,16 @@ namespace libtorrent
 		if (!t->has_picker()) return;
 		piece_picker& picker = t->picker();
 
-		int prev_request_queue = m_request_queue.size();
+		// first, if we have any unsent requests, just
+		// wipe those out
+		while (!m_request_queue.empty())
+		{
+			t->picker().abort_download(m_request_queue.back().block, peer_info_struct());
+			m_request_queue.pop_back();
+		}
+		m_queued_time_critical = 0;
+
+		TORRENT_ASSERT(!m_download_queue.empty());
 
 		// request a new block before removing the previous
 		// one, in order to prevent it from
@@ -4278,25 +4293,28 @@ namespace libtorrent
 		++m_ses.m_snubbed_piece_picks;
 #endif
 		request_a_block(*t, *this);
+
+		// the block we just picked (potentially)
+		// hasn't been put in m_download_queue yet.
+		// it's in m_request_queue and will be sent
+		// once send_block_requests() is called.
+
 		m_desired_queue_size = 1;
 
-		piece_block r(piece_block::invalid);
-		// time out the last request in the queue
-		if (prev_request_queue > 0)
+		// time out the last request eligible
+		// block in the queue
+		int i = m_download_queue.size() - 1;
+		for (; i >= 0; --i)
 		{
-			std::vector<pending_block>::iterator i
-				= m_request_queue.begin() + (prev_request_queue - 1);
-			r = i->block;
-			m_request_queue.erase(i);
-			if (prev_request_queue <= m_queued_time_critical)
-				--m_queued_time_critical;
+			if (!m_download_queue[i].timed_out
+				&& !m_download_queue[i].not_wanted)
+				break;
 		}
-		else
+
+		if (i >= 0)
 		{
-			TORRENT_ASSERT(!m_download_queue.empty());
-			pending_block& qe = m_download_queue.back();
-			if (!qe.timed_out && !qe.not_wanted)
-				r = qe.block;
+			pending_block& qe = m_download_queue[i];
+			piece_block r = qe.block;
 
 			// only time out a request if it blocks the piece
 			// from being completed (i.e. no free blocks to
@@ -4317,12 +4335,8 @@ namespace libtorrent
 					, remote(), pid(), qe.block.block_index, qe.block.piece_index));
 			}
 			qe.timed_out = true;
-		}
-		if (!m_download_queue.empty() || !m_request_queue.empty())
-			m_timeout_extend += m_ses.settings().request_timeout;
-
-		if (r != piece_block::invalid)
 			picker.abort_download(r, peer_info_struct());
+		}
 
 		send_block_requests();
 	}

src/session_impl.cpp

@@ -624,6 +624,7 @@ namespace aux {
 		, m_network_thread(0)
 #endif
 	{
+		memset(m_redundant_bytes, 0, sizeof(m_redundant_bytes));
 		m_udp_socket.set_rate_limit(m_settings.dht_upload_rate_limit);
 
 		m_disk_queues[0] = 0;
@@ -1021,14 +1022,8 @@ namespace aux {
 
 		error_code ec;
 		char filename[100];
-#ifdef TORRENT_WINDOWS
 		create_directory("session_stats", ec);
 		snprintf(filename, sizeof(filename), "session_stats/%d.%04d.log", int(getpid()), m_log_seq);
-#else
-		snprintf(filename, sizeof(filename), "/var/log/session_stats%d", int(getpid()));
-		create_directory(filename, ec);
-		snprintf(filename, sizeof(filename), "/var/log/session_stats%d/%04d.log", int(getpid()), m_log_seq);
-#endif
 		m_stats_logger = fopen(filename, "w+");
 		if (m_stats_logger == 0)
 		{
@@ -1143,6 +1138,13 @@ namespace aux {
 			":down 8:down 16:down 32:down 64:down 128:down 256:down 512:down 1024:down 2048:down 4096:down 8192:down 16384:down 32768:down 65536:down 131072:down 262144:down 524288:down 1048576"
 			":network thread system time"
 			":network thread user+system time"
+
+			":redundant timed-out"
+			":redundant cancelled"
+			":redundant unknown"
+			":redundant seed"
+			":redundant end-game"
+			":redundant closing"
 			"\n\n", m_stats_logger);
 	}
 #endif
@@ -3603,19 +3605,13 @@ namespace aux {
 			STAT_LOG(d, reading_bytes);
 
 			for (int i = 0; i < max_messages; ++i)
-			{
 				STAT_LOG(d, m_num_messages[i]);
-			}
 			int num_max = sizeof(m_send_buffer_sizes)/sizeof(m_send_buffer_sizes[0]);
 			for (int i = 0; i < num_max; ++i)
-			{
 				STAT_LOG(d, m_send_buffer_sizes[i]);
-			}
 			num_max = sizeof(m_recv_buffer_sizes)/sizeof(m_recv_buffer_sizes[0]);
 			for (int i = 0; i < num_max; ++i)
-			{
 				STAT_LOG(d, m_recv_buffer_sizes[i]);
-			}
 
 			STAT_LOG(f, total_milliseconds(cur_cpu_usage.user_time
 				- m_network_thread_cpu_usage.user_time) * 100.0 / double(tick_interval_ms));
@@ -3625,6 +3621,9 @@ namespace aux {
 					- m_network_thread_cpu_usage.user_time)) * 100.0
 				/ double(tick_interval_ms));
 
+			for (int i = 0; i < torrent::waste_reason_max; ++i)
+				STAT_LOG(f, (m_redundant_bytes[i] * 100.) / double(m_total_redundant_bytes));
+
 			fprintf(m_stats_logger, "\n");
 
 #undef STAT_LOG

src/torrent.cpp

@@ -8244,12 +8244,12 @@ ctx->set_verify_callback(verify_function, ec);
 		}
 	}
 
-	void torrent::add_redundant_bytes(int b)
+	void torrent::add_redundant_bytes(int b, torrent::wasted_reason_t reason)
 	{
 		TORRENT_ASSERT(m_ses.is_network_thread());
 		TORRENT_ASSERT(b > 0);
 		m_total_redundant_bytes += b;
-		m_ses.add_redundant_bytes(b);
+		m_ses.add_redundant_bytes(b, reason);
 //		TORRENT_ASSERT(m_total_redundant_bytes + m_total_failed_bytes
 //			<= m_stat.total_payload_download());
 	}

src/ut_metadata.cpp

@@ -463,7 +463,7 @@ namespace libtorrent { namespace
 #ifdef TORRENT_VERBOSE_LOGGING
 			source.m_pc.peer_log("*** UT_METADATA [ ALREADY HAVE METADATA ]");				
 #endif
-			m_torrent.add_redundant_bytes(size);
+			m_torrent.add_redundant_bytes(size, torrent::piece_unknown);
 			return false;
 		}