added an option to generate a disk io log file

Jamfile

@@ -139,6 +139,9 @@ rule building ( properties * )
 	return $(result) ;
 }
 
+feature disk-stats : off on : composite propagated symmetric link-incompatible ;
+feature.compose <disk-stats>on : <define>TORRENT_DISK_STATS ;
+
 feature logging : none default verbose : composite propagated symmetric link-incompatible ;
 feature.compose <logging>default : <define>TORRENT_LOGGING ;
 feature.compose <logging>verbose : <define>TORRENT_VERBOSE_LOGGING ;

include/libtorrent/disk_io_thread.hpp

@@ -30,6 +30,10 @@ POSSIBILITY OF SUCH DAMAGE.
 
 */
 
+#ifdef TORRENT_DISK_STATS
+#include <fstream>
+#endif
+
 #include "libtorrent/storage.hpp"
 #include <boost/thread/thread.hpp>
 #include <boost/function.hpp>
@@ -122,6 +126,10 @@ namespace libtorrent
 		int m_block_size;
 #endif
 
+#ifdef TORRENT_DISK_STATS
+		std::ofstream m_log;
+#endif
+
 		// thread for performing blocking disk io operations
 		boost::thread m_disk_io_thread;
 	};

parse_disk_log.py

@@ -0,0 +1,68 @@
+import os, sys, time
+
+lines = open(sys.argv[1], 'rb').readlines()
+
+time_limit = -1
+if len(sys.argv) > 2:
+	time_limit = long(sys.argv[2])
+
+keys = ['write', 'read', 'hash', 'move', 'release', 'idle']
+
+# logfile format:
+# <time(ms)> <state>
+# example:
+# 34523 idle
+# 34722 write
+
+quantization = 5000
+
+out = open('disk_io.dat', 'wb')
+state = 'idle'
+time = 0
+i = 0
+state_timer = {}
+for k in keys: state_timer[k] = 0
+for l in lines:
+	l = l[:-1].split(' ')
+	if len(l) < 2:
+		print l
+		continue
+	try:
+		new_time = long(l[0])
+		while new_time > i + quantization:
+			i += quantization
+			state_timer[state] += i - time
+			time = i
+			for k in keys: print >>out, state_timer[k],
+			print >>out
+			for k in keys: state_timer[k] = 0
+		state_timer[state] += new_time - time
+		time = new_time
+		state = l[1]
+	except:
+		print l
+out.close()
+
+
+out = open('disk_io.gnuplot', 'wb')
+print >>out, "set term png size 1200,700"
+print >>out, 'set output "disk_io.png"'
+print >>out, 'set xrange [0:*]'
+print >>out, 'set ylabel "time (ms)"'
+print >>out, "set style data lines"
+print >>out, 'set title "disk io utilization per %s second(s)"' % (quantization / 1000)
+print >>out, "set key box"
+print >>out, "set style data histogram"
+print >>out, "set style histogram rowstacked"
+print >>out, "set style fill solid"
+print >>out, 'plot',
+i = 0
+for k in keys:
+	if k != 'idle':
+		print >>out, ' "disk_io.dat" using %d title "%s",' % (i + 1, keys[i]),
+	i = i + 1
+print >>out, 'x=0'
+out.close()
+
+os.system('gnuplot disk_io.gnuplot');
+

src/disk_io_thread.cpp

@@ -34,6 +34,24 @@ POSSIBILITY OF SUCH DAMAGE.
 #include <deque>
 #include "libtorrent/disk_io_thread.hpp"
 
+#ifdef TORRENT_DISK_STATS
+
+#include "libtorrent/time.hpp"
+#include <boost/lexical_cast.hpp>
+
+namespace
+{
+	std::string log_time()
+	{
+		using namespace libtorrent;
+		static ptime start = time_now();
+		return boost::lexical_cast<std::string>(
+			total_milliseconds(time_now() - start));
+	}
+}
+
+#endif
+
 namespace libtorrent
 {
 
@@ -45,7 +63,12 @@ namespace libtorrent
 		, m_block_size(block_size)
 #endif
 		, m_disk_io_thread(boost::ref(*this))
-	{}
+	{
+	
+#ifdef TORRENT_DISK_STATS
+		m_log.open("disk_io_thread.log", std::ios::trunc);
+#endif
+	}
 
 	disk_io_thread::~disk_io_thread()
 	{
@@ -172,6 +195,9 @@ namespace libtorrent
 	{
 		for (;;)
 		{
+#ifdef TORRENT_DISK_STATS
+			m_log << log_time() << " idle" << std::endl;
+#endif
 			boost::mutex::scoped_lock l(m_mutex);
 			while (m_jobs.empty() && !m_abort)
 				m_signal.wait(l);
@@ -189,10 +215,16 @@ namespace libtorrent
 			bool free_buffer = true;
 			try
 			{
+#ifdef TORRENT_DISK_STATS
+				ptime start = time_now();
+#endif
 //				std::cerr << "DISK THREAD: executing job: " << j.action << std::endl;
 				switch (j.action)
 				{
 					case disk_io_job::read:
+#ifdef TORRENT_DISK_STATS
+						m_log << log_time() << " read " << j.buffer_size << std::endl;
+#endif
 						if (j.buffer == 0)
 						{
 							l.lock();
@@ -217,6 +249,9 @@ namespace libtorrent
 						// usleep(300);
 						break;
 					case disk_io_job::write:
+#ifdef TORRENT_DISK_STATS
+						m_log << log_time() << " write " << j.buffer_size << std::endl;
+#endif
 						assert(j.buffer);
 						assert(j.buffer_size <= m_block_size);
 						j.storage->write_impl(j.buffer, j.piece, j.offset
@@ -227,16 +262,25 @@ namespace libtorrent
 						break;
 					case disk_io_job::hash:
 						{
+#ifdef TORRENT_DISK_STATS
+							m_log << log_time() << " hash" << std::endl;
+#endif
 							sha1_hash h = j.storage->hash_for_piece_impl(j.piece);
 							j.str.resize(20);
 							std::memcpy(&j.str[0], &h[0], 20);
 						}
 						break;
 					case disk_io_job::move_storage:
+#ifdef TORRENT_DISK_STATS
+						m_log << log_time() << " move" << std::endl;
+#endif
 						ret = j.storage->move_storage_impl(j.str) ? 1 : 0;
 						j.str = j.storage->save_path().string();
 						break;
 					case disk_io_job::release_files:
+#ifdef TORRENT_DISK_STATS
+						m_log << log_time() << " release" << std::endl;
+#endif
 						j.storage->release_files_impl();
 						break;
 				}