diff --git a/Makefile.am b/Makefile.am index d49a559cb..7ff4a4092 100644 --- a/Makefile.am +++ b/Makefile.am @@ -46,8 +46,12 @@ docs/read_disk_buffers.png \ docs/read_disk_buffers.graffle \ docs/write_disk_buffers.png \ docs/write_disk_buffers.graffle \ +docs/disk_io.png \ +docs/disk_access.png \ docs/storage.png \ +docs/storage.graffle \ docs/disk_buffer.png \ +docs/disk_buffer_sample.png \ docs/disk_buffer_before_optimization.png \ docs/unicode_support.png docs/client_test.png docs/style.css Jamfile project-root.jam \ libtorrent-rasterbar.pc \ diff --git a/disk_io.png b/disk_io.png new file mode 100644 index 000000000..0ec82d167 Binary files /dev/null and b/disk_io.png differ diff --git a/docs/disk_access.png b/docs/disk_access.png new file mode 100644 index 000000000..c236b6bb3 Binary files /dev/null and b/docs/disk_access.png differ diff --git a/docs/disk_buffer_sample.png b/docs/disk_buffer_sample.png new file mode 100644 index 000000000..8d8d7d494 Binary files /dev/null and b/docs/disk_buffer_sample.png differ diff --git a/docs/tuning.rst b/docs/tuning.rst index 1eed722ea..f11ff4801 100644 --- a/docs/tuning.rst +++ b/docs/tuning.rst @@ -192,11 +192,143 @@ same semantics. benchmarking ============ -disk cache stats ----------------- +There are a bunch of built-in instrumentation of libtorrent that can be used to get an insight +into what it's doing and how well it performs. This instrumentation is enabled by defining +preprocessor symbols when building. -disk access stats ------------------ +There are also a number of scripts that parses the log files and generates graphs (requires +gnuplot and python). + +disk metrics +------------ + +To enable disk I/O instrumentation, define ``TORRENT_DISK_STATS`` when building. When built +with this configuration libtorrent will create three log files, measuring various aspects of +the disk I/O. The following table is an overview of these files and what they measure. + ++--------------------------+--------------------------------------------------------------+ +| filename | description | ++==========================+==============================================================+ +| ``disk_io_thread.log`` | This is a log of which operation the disk I/O thread is | +| | engaged in, with timestamps. This tells you what the thread | +| | is spending its time doing. | +| | | ++--------------------------+--------------------------------------------------------------+ +| ``disk_buffers.log`` | This log keeps track of what the buffers allocated from the | +| | disk buffer pool are used for. There are 5 categories. | +| | receive buffer, send buffer, write cache, read cache and | +| | temporary hash storage. This is key when optimizing memory | +| | usage. | +| | | ++--------------------------+--------------------------------------------------------------+ +| ``disk_access.log`` | This is a low level log of read and write operations, with | +| | timestamps and file offsets. The file offsets are byte | +| | offsets in the torrent (not in any particular file, in the | +| | case of a multi-file torrent). This can be used as an | +| | estimate of the physical drive location. The purpose of | +| | this log is to identify the amount of seeking the drive has | +| | to do. | +| | | ++--------------------------+--------------------------------------------------------------+ + + +disk_io_thread.log +'''''''''''''''''' + +The structure of this log is simple. For each line, there are two columns, a timestamp and +the operation that was started. There is a special operation called ``idle`` which means +it looped back to the top and started waiting for new jobs. If there are more jobs to +handle immediately, the ``idle`` state is still there, but the timestamp is the same as the +next job that is handled. + +Some operations have a 3:rd column with an optional parameter. ``read`` and ``write`` tells +you the number of bytes that were requested to be read or written. ``flushing`` tells you +the number of bytes that were flushed from the disk cache. + +This is an example excerpt from a log:: + + 3702 idle + 3706 check_fastresume + 3707 idle + 4708 save_resume_data + 4708 idle + 8230 read 16384 + 8255 idle + 8431 read 16384 + +The script to parse this log and generate a graph is called ``parse_disk_log.py``. It takes +the log file as the first command line argument, and produces a file: ``disk_io.png``. +The time stamp is in milliseconds since start. + +You can pass in a second, optional, argument to specify the window size it will average +the time measurements over. The default is 5 seconds. For long test runs, it might be interesting +to increase that number. It is specified as a number of seconds. + +.. image:: disk_io.png + +This is an example graph generated by the parse script. + +disk_buffers.log +'''''''''''''''' + +The disk buffer log tells you where the buffer memory is used. The log format has a time stamp, +the name of the buffer usage which use-count changed, colon, and the new number of blocks that are +in use for this particular key. For example:: + + 23671 write cache: 18 + 23671 receive buffer: 3 + 24153 receive buffer: 2 + 24153 write cache: 19 + 24154 receive buffer: 3 + 24198 receive buffer: 2 + 24198 write cache: 20 + 24202 receive buffer: 3 + 24305 send buffer: 0 + 24305 send buffer: 1 + 24909 receive buffer: 2 + 24909 write cache: 21 + 24910 receive buffer: 3 + +The time stamp is in milliseconds since start. + +To generate a graph, use ``parse_disk_buffer_log.py``. It takes the log file as the first +command line argument. It generates ``disk_buffer.png``. + +.. image:: disk_buffer_sample.png + +This is an example graph generated by the parse script. + +disk_access.log +''''''''''''''' + +The disc access log has three fields. The timestamp (milliseconds since start), operation +and offset. The offset is the absolute offset within the torrent (not within a file). This +log is only useful when you're downloading a single torrent, otherwise the offsets will not +be unique. + +In order to easily plot this directly in gnuplot, without parsing it, there are two lines +associated with each read or write operation. The first one is the offset where the operation +started, and the second one is where the operation ended. + +Example:: + + 15437 read 301187072 + 15437 read_end 301203456 + 16651 read 213385216 + 16680 read_end 213647360 + 25879 write 249036800 + 25879 write_end 249298944 + 26811 read 325582848 + 26943 read_end 325844992 + 36736 read 367001600 + 36766 read_end 367263744 + +The disk access log does not have any good visualization tool yet. There is however a gnuplot +file, ``disk_access.gnuplot`` which assumes ``disk_access.log`` is in the current directory. + +.. image:: disk_access.png + +The density of the disk seeks tells you how hard the drive has to work. session stats -------------