added disk buffer instrumentation and log parser

include/libtorrent/aux_/session_impl.hpp

@@ -319,7 +319,7 @@ namespace libtorrent
 			std::pair<char*, int> allocate_buffer(int size);
 			void free_buffer(char* buf, int size);
 
-			char* allocate_disk_buffer();
+			char* allocate_disk_buffer(char const* category);
 			void free_disk_buffer(char* buf);
 
 			void set_external_address(address const& ip);

include/libtorrent/disk_io_thread.hpp

@@ -165,10 +165,10 @@ namespace libtorrent
 		bool is_disk_buffer(char* buffer) const;
 #endif
 
-		char* allocate_buffer();
+		char* allocate_buffer(char const* category);
 		void free_buffer(char* buf);
 
-		char* allocate_buffers(int blocks);
+		char* allocate_buffers(int blocks, char const* category);
 		void free_buffers(char* buf, int blocks);
 
 		int block_size() const { return m_block_size; }
@@ -197,6 +197,9 @@ namespace libtorrent
 
 #ifdef TORRENT_STATS
 		int m_allocations;
+		std::map<std::string, int> m_categories;
+		std::map<char*, std::string> m_buf_to_category;
+		std::ofstream m_log;
 #endif
 	};
 

parse_disk_buffer_log.py

@@ -0,0 +1,73 @@
+#!/bin/python
+
+import os, sys, time
+
+#lines = open(sys.argv[1], 'rb').readlines()
+#
+## logfile format:
+## <time(ms)> <key>: <value>
+## example:
+## 16434 read cache: 17
+#
+#keys = []
+#fields = {}
+#maximum = {}
+#out = open('disk_buffer_log.dat', 'w+')
+#
+#last_t = 0
+#for l in lines:
+#	try:
+#		t = int(l[0:l.find(' ')])
+#		c = l[l.find(' ')+1:l.find(':')]
+#		n = int(l[l.find(':')+1:-1])
+#	except:
+#		print l
+#		continue
+#
+#	if last_t != t:
+#		print >>out, '%d\t' % last_t,
+#		for i in keys:
+#			print >>out, '%d\t' % maximum[i],
+#		print >>out, '\n',
+#
+#	if not c in keys:
+#		keys.append(c)
+#		fields[c] = 0
+#		maximum[c] = 0
+#
+#	fields[c] = n
+#	if n > maximum[c]: maximum[c] = n
+#
+#	if last_t != t:
+#		last_t = t
+#		maximum = fields
+#
+#for i in keys:
+#	print i,
+#print
+#	
+#out.close()
+
+keys = ['check piece', 'send buffer', 'read cache', 'receive buffer', 'hash temp']
+
+out = open('disk_buffer.gnuplot', 'wb')
+print >>out, "set term png size 1200,700"
+print >>out, 'set output "disk_buffer.png"'
+print >>out, 'set xrange [0:*]'
+print >>out, 'set xlabel "time (ms)"'
+print >>out, 'set ylabel "buffers"'
+print >>out, "set style data lines"
+print >>out, "set key box"
+print >>out, 'plot',
+count = 1 + len(keys)
+keys.reverse()
+for k in keys:
+	expr = "$%d" % count
+	for i in xrange(2, count): expr += "+$%d" % i
+	print >>out, ' "disk_buffer_log.dat" using 1:(%s) title "%s" with filledcurves x1,' % (expr, k),
+	count -= 1
+print >>out, 'x=0'
+out.close()
+
+os.system('gnuplot disk_buffer.gnuplot')
+

src/disk_io_thread.cpp

@@ -52,6 +52,9 @@ namespace libtorrent
 	{
 #ifdef TORRENT_STATS
 		m_allocations = 0;
+#endif
+#ifdef TORRENT_DISK_STATS
+		m_log.open("disk_buffers.log", std::ios::trunc);
 #endif
 	}
 
@@ -67,17 +70,21 @@ namespace libtorrent
 	}
 #endif
 
-	char* disk_buffer_pool::allocate_buffer()
+	char* disk_buffer_pool::allocate_buffer(char const* category)
 	{
 		mutex_t::scoped_lock l(m_pool_mutex);
+#ifdef TORRENT_DISABLE_POOL_ALLOCATOR
+		char* ret = page_aligned_allocator::malloc(m_block_size);
+#else
+		char* ret = (char*)m_pool.ordered_malloc();
+#endif
 #ifdef TORRENT_STATS
 		++m_allocations;
+		++m_categories[category];
+		m_buf_to_category[ret] = category;
+		m_log << log_time() << " " << category << ": " << m_categories[category] << "\n";
 #endif
-#ifdef TORRENT_DISABLE_POOL_ALLOCATOR
-		return page_aligned_allocator::malloc(m_block_size);
-#else
-		return (char*)m_pool.ordered_malloc();
-#endif
+		return ret;
 	}
 
 	void disk_buffer_pool::free_buffer(char* buf)
@@ -86,6 +93,12 @@ namespace libtorrent
 		mutex_t::scoped_lock l(m_pool_mutex);
 #ifdef TORRENT_STATS
 		--m_allocations;
+		TORRENT_ASSERT(m_categories.find(m_buf_to_category[buf])
+			!= m_categories.end());
+		std::string const& category = m_buf_to_category[buf];
+		--m_categories[category];
+		m_log << log_time() << " " << category << ": " << m_categories[category] << "\n";
+		m_buf_to_category.erase(buf);
 #endif
 #ifdef TORRENT_DISABLE_POOL_ALLOCATOR
 		page_aligned_allocator::free(buf);
@@ -94,17 +107,21 @@ namespace libtorrent
 #endif
 	}
 
-	char* disk_buffer_pool::allocate_buffers(int num_blocks)
+	char* disk_buffer_pool::allocate_buffers(int num_blocks, char const* category)
 	{
 		mutex_t::scoped_lock l(m_pool_mutex);
+#ifdef TORRENT_DISABLE_POOL_ALLOCATOR
+		char* ret = page_aligned_allocator::malloc(m_block_size * num_blocks);
+#else
+		char* ret = (char*)m_pool.ordered_malloc(num_blocks);
+#endif
 #ifdef TORRENT_STATS
 		m_allocations += num_blocks;
+		m_categories[category] += num_blocks;
+		m_buf_to_category[ret] = category;
+		m_log << log_time() << " " << category << ": " << m_categories[category] << "\n";
 #endif
-#ifdef TORRENT_DISABLE_POOL_ALLOCATOR
-		return page_aligned_allocator::malloc(m_block_size * num_blocks);
-#else
-		return (char*)m_pool.ordered_malloc(num_blocks);
-#endif
+		return ret;
 	}
 
 	void disk_buffer_pool::free_buffers(char* buf, int num_blocks)
@@ -114,6 +131,12 @@ namespace libtorrent
 		mutex_t::scoped_lock l(m_pool_mutex);
 #ifdef TORRENT_STATS
 		m_allocations -= num_blocks;
+		TORRENT_ASSERT(m_categories.find(m_buf_to_category[buf])
+			!= m_categories.end());
+		std::string const& category = m_buf_to_category[buf];
+		m_categories[category] -= num_blocks;
+		m_log << log_time() << " " << category << ": " << m_categories[category] << "\n";
+		m_buf_to_category.erase(buf);
 #endif
 #ifdef TORRENT_DISABLE_POOL_ALLOCATOR
 		page_aligned_allocator::free(buf);
@@ -499,7 +522,7 @@ namespace libtorrent
 			// stop allocating and don't read more than
 			// what we've allocated now
 			if (p.blocks[i]) break;
-			p.blocks[i] = allocate_buffer();
+			p.blocks[i] = allocate_buffer("read cache");
 
 			// the allocation failed, break
 			if (p.blocks[i] == 0) break;
@@ -961,7 +984,7 @@ namespace libtorrent
 #endif
 					INVARIANT_CHECK;
 					TORRENT_ASSERT(j.buffer == 0);
-					j.buffer = allocate_buffer();
+					j.buffer = allocate_buffer("send buffer");
 					TORRENT_ASSERT(j.buffer_size <= m_block_size);
 					if (j.buffer == 0)
 					{

src/peer_connection.cpp

@@ -1666,7 +1666,7 @@ namespace libtorrent
 
 	void peer_connection::incoming_piece(peer_request const& p, char const* data)
 	{
-		char* buffer = m_ses.allocate_disk_buffer();
+		char* buffer = m_ses.allocate_disk_buffer("receive buffer");
 		if (buffer == 0)
 		{
 			disconnect("out of memory");
@@ -2801,7 +2801,7 @@ namespace libtorrent
 			return false;
 		}
 
-		m_disk_recv_buffer.reset(m_ses.allocate_disk_buffer());
+		m_disk_recv_buffer.reset(m_ses.allocate_disk_buffer("receive buffer"));
 		if (!m_disk_recv_buffer)
 		{
 			disconnect("out of memory");

src/session_impl.cpp

@@ -2638,9 +2638,9 @@ namespace aux {
 		m_disk_thread.free_buffer(buf);
 	}
 
-	char* session_impl::allocate_disk_buffer()
+	char* session_impl::allocate_disk_buffer(char const* category)
 	{
-		return m_disk_thread.allocate_buffer();
+		return m_disk_thread.allocate_buffer(category);
 	}
 	
 	std::pair<char*, int> session_impl::allocate_buffer(int size)

src/storage.cpp

@@ -498,7 +498,7 @@ namespace libtorrent
 			file::iovec_t* bufs = TORRENT_ALLOCA(file::iovec_t, num_blocks);
 			for (int i = 0; i < num_blocks; ++i)
 			{
-				bufs[i].iov_base = disk_pool()->allocate_buffer();
+				bufs[i].iov_base = disk_pool()->allocate_buffer("hash temp");
 				bufs[i].iov_len = (std::min)(block_size, size);
 				size -= bufs[i].iov_len;
 			}
@@ -960,7 +960,7 @@ namespace libtorrent
 	file::iovec_t* bufs = TORRENT_ALLOCA(file::iovec_t, num_blocks); \
 	for (int i = 0, size = piece_size; i < num_blocks; ++i) \
 	{ \
-		bufs[i].iov_base = disk_pool()->allocate_buffer(); \
+		bufs[i].iov_base = disk_pool()->allocate_buffer("move temp"); \
 		bufs[i].iov_len = (std::min)(disk_pool()->block_size(), size); \
 		size -= bufs[i].iov_len; \
 	}
@@ -1243,7 +1243,7 @@ ret:
 		const int num_blocks = (aligned_size + block_size - 1) / block_size;
 		TORRENT_ASSERT((aligned_size & size_align) == 0);
 
-		disk_buffer_holder tmp_buf(*disk_pool(), disk_pool()->allocate_buffers(num_blocks), num_blocks);
+		disk_buffer_holder tmp_buf(*disk_pool(), disk_pool()->allocate_buffers(num_blocks, "read scratch"), num_blocks);
 		file::iovec_t b = {tmp_buf.get(), aligned_size};
 		size_type ret = file_handle->readv(aligned_start, &b, 1, ec);
 		if (ret < 0) return ret;
@@ -2105,7 +2105,7 @@ ret:
 						int blocks_per_piece = (std::max)(m_files.piece_length()
 							/ m_io_thread.block_size(), 1);
 						m_scratch_buffer2.reset(m_io_thread.allocate_buffers(
-							blocks_per_piece), blocks_per_piece);
+							blocks_per_piece, "check scratch"), blocks_per_piece);
 					}
 
 					int piece_size = m_files.piece_size(other_piece);
@@ -2165,7 +2165,7 @@ ret:
 				{
 					int blocks_per_piece = (std::max)(m_files.piece_length() / m_io_thread.block_size(), 1);
 					m_scratch_buffer.reset(m_io_thread.allocate_buffers(
-						blocks_per_piece), blocks_per_piece);
+						blocks_per_piece, "check scratch"), blocks_per_piece);
 				}
 			
 				int piece_size = m_files.piece_size(other_piece);
@@ -2303,7 +2303,8 @@ ret:
 		if (!m_piece_data)
 		{
 			int blocks_per_piece = (std::max)(m_files.piece_length() / m_io_thread.block_size(), 1);
-			m_piece_data.reset(m_io_thread.allocate_buffers(blocks_per_piece), blocks_per_piece);
+			m_piece_data.reset(m_io_thread.allocate_buffers(blocks_per_piece, "check piece")
+				, blocks_per_piece);
 		}
 
 		int piece_size = m_files.piece_size(m_current_slot);

src/torrent.cpp

@@ -461,7 +461,7 @@ namespace libtorrent
 				continue;
 
 			p.length = (std::min)(piece_size - p.start, m_block_size);
-			char* buffer = m_ses.allocate_disk_buffer();
+			char* buffer = m_ses.allocate_disk_buffer("add piece");
 			// out of memory
 			if (buffer == 0)
 			{