diff --git a/include/libtorrent/utp_stream.hpp b/include/libtorrent/utp_stream.hpp index a4ebd1f7f..87d88dedf 100644 --- a/include/libtorrent/utp_stream.hpp +++ b/include/libtorrent/utp_stream.hpp @@ -216,6 +216,8 @@ public: void set_write_handler(handler_t h); size_t read_some(bool clear_buffers); + int send_delay() const; + void do_connect(tcp::endpoint const& ep, connect_handler_t h); endpoint_type local_endpoint() const diff --git a/parse_session_stats.py b/parse_session_stats.py index 21f223f8e..61d9c7d7e 100755 --- a/parse_session_stats.py +++ b/parse_session_stats.py @@ -46,7 +46,7 @@ def gen_report(name, unit, lines, short_unit, generation, log_file): print >>out, "set tics nomirror" print >>out, "set style data lines" print >>out, "set key box" - print >>out, "set format y \"%%.0s%%c%s\";" % short_unit + print >>out, "set format y \"%%.1s%%c%s\";" % short_unit print >>out, 'plot', column = 2 first = True @@ -107,23 +107,24 @@ reports = [ ('peers', 'num', '', 'num connected peers', ['peers', 'connecting peers', 'connection attempts', 'banned peers', 'max connections']), ('connect_candidates', 'num', '', 'number of peers we know of that we can connect to', ['connect candidates']), ('peers_list_size', 'num', '', 'number of known peers (not necessarily connected)', ['num list peers']), - ('overall_rates', 'Bytes / second', 'B/s', 'download and upload rates', ['uploaded bytes', 'downloaded bytes', 'upload rate', 'download rate', 'smooth upload rate', 'smooth download rate']), + ('overall_rates', 'rate', 'B/s', 'download and upload rates', ['uploaded bytes', 'downloaded bytes', 'upload rate', 'download rate', 'smooth upload rate', 'smooth download rate']), ('disk_write_queue', 'Bytes', 'B', 'bytes queued up by peers, to be written to disk', ['disk write queued bytes', 'disk queue limit', 'disk queue low watermark']), ('peers_upload', 'num', '', 'number of peers by state wrt. uploading', ['peers up interested', 'peers up unchoked', 'peers up requests', 'peers disk-up', 'peers bw-up', 'max unchoked']), ('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']), - ('average_disk_time_absolute', 'microseconds', 'us', 'running averages of timings of disk operations', ['disk read time', 'disk write time', 'disk queue time', 'disk hash time', 'disk job time', 'disk sort time']), + ('average_disk_time_absolute', 'job time', 's', 'running averages of timings of disk operations', ['disk read time', 'disk write time', 'disk queue time', 'disk hash time', 'disk job time', 'disk sort time']), ('disk_time', '% of total disk job time', '%%', 'proportion of time spent by the disk thread', ['% read time', '% write time', '% hash time', '% sort time']), ('disk_cache_hits', 'blocks (16kiB)', '', '', ['disk block read', 'read cache hits', 'disk block written', 'disk read back']), ('disk_cache', 'blocks (16kiB)', '', 'disk cache size and usage', ['read disk cache size', 'disk cache size', 'disk buffer allocations', 'cache size']), ('disk_readback', '% of written blocks', '%%', 'portion of written blocks that had to be read back for hash verification', ['% read back']), ('disk_queue', 'number of queued disk jobs', '', 'queued disk jobs', ['disk queue size', 'disk read queue size', 'read job queue size limit']), - ('mixed mode', 'rate', '', 'rates by transport protocol', ['tcp up rate','tcp down rate','utp up rate','utp down rate','tcp up limit','tcp down limit']), + ('mixed mode', 'rate', 'B/s', 'rates by transport protocol', ['TCP up rate','TCP down rate','uTP up rate','uTP down rate','TCP up limit','TCP down limit']), + ('uTP delay', 'buffer delay', 's', 'network delays measured by uTP', ['uTP peak send delay','uTP avg send delay']), # ('absolute_waste', 'num', '', ['failed bytes', 'redundant bytes', 'download rate']), #somewhat uninteresting stats - ('tick_rate', 'milliseconds between ticks', 'ms', '', ['tick interval', 'tick residual']), + ('tick_rate', 'time between ticks', 's', '', ['tick interval', 'tick residual']), ('peer_dl_rates', 'num', '', 'peers split into download rate buckets', ['peers down 0', 'peers down 0-2', 'peers down 2-5', 'peers down 5-10', 'peers down 50-100', 'peers down 100-']), ('peer_dl_rates2', 'num', '', 'peers split into download rate buckets (only downloading peers)', ['peers down 0-2', 'peers down 2-5', 'peers down 5-10', 'peers down 50-100', 'peers down 100-']), ('peer_ul_rates', 'num', '', 'peers split into upload rate buckets', ['peers up 0', 'peers up 0-2', 'peers up 2-5', 'peers up 5-10', 'peers up 50-100', 'peers up 100-']), diff --git a/src/session_impl.cpp b/src/session_impl.cpp index 7897da1c1..4d31c2312 100644 --- a/src/session_impl.cpp +++ b/src/session_impl.cpp @@ -961,10 +961,12 @@ namespace aux { ":num end-game peers" ":TCP up rate" ":TCP down rate" - ":TCP down limit" ":TCP up limit" + ":TCP down limit" ":uTP up rate" ":uTP down rate" + ":uTP peak send delay" + ":uTP avg send delay" "\n\n", m_stats_logger); } #endif @@ -3153,6 +3155,9 @@ namespace aux { int tcp_down_rate = 0; int utp_up_rate = 0; int utp_down_rate = 0; + int utp_peak_send_delay = 0; + boost::uint64_t utp_send_delay_sum = 0; + int utp_num_delay_sockets = 0; int num_complete_connections = 0; int num_half_open = 0; int peers_down_unchoked = 0; @@ -3201,10 +3206,18 @@ namespace aux { ++peer_dl_rate_buckets[dl_bucket]; ++peer_ul_rate_buckets[ul_bucket]; - if (p->get_socket()->get()) + utp_stream* utp_socket = p->get_socket()->get(); + if (utp_socket) { utp_up_rate += ul_rate; - utp_down_rate += ul_rate; + utp_down_rate += dl_rate; + int send_delay = utp_socket->send_delay(); + utp_peak_send_delay = (std::max)(utp_peak_send_delay, send_delay); + if (send_delay > 0) + { + utp_send_delay_sum += send_delay; + ++utp_num_delay_sockets; + } } else { @@ -3234,11 +3247,11 @@ namespace aux { "%d\t%d\t%d\t%d\t%d\t%d\t%d\t%d\t%d\t%d\t" "%d\t%d\t%d\t%d\t%d\t%d\t%d\t%d\t%d\t%d\t" "%d\t%d\t%d\t%d\t%d\t%d\t%d\t%d\t%d\t%d\t" - "%f\t%f\t%f\t%d\t%d\t%d\t%d\t%d\t%d\t%d\t" - "%d\t%d\t%d\t%d\t%d\t%d\t%d\t%d\t%d\t%d\t" + "%f\t%f\t%f\t%f\t%f\t%f\t%d\t%d\t%d\t%d\t" + "%d\t%d\t%d\t%d\t%d\t%d\t%d\t%f\t%f\t%f\t" "%d\t%d\t%d\t%d\t%d\t%d\t%d\t%d\t%f\t%f\t" - "%f\t%f\t%d\t%f\t%d\t%d\t%d\t%d\t%d\t%d\t" - "%d\t%d\t%d\t%d\t%d\t%d\t%d\t%d\n" + "%f\t%f\t%d\t%f\t%d\t%f\t%f\t%d\t%d\t%d\t" + "%d\t%d\t%d\t%d\t%d\t%d\t%d\t%d\t%f\t%f\n" , total_milliseconds(now - m_last_log_rotation) / 1000.f , int(m_stat.total_upload() - m_last_uploaded) , int(m_stat.total_download() - m_last_downloaded) @@ -3302,9 +3315,9 @@ namespace aux { , (float(m_total_failed_bytes) * 100.f / m_stat.total_payload_download()) , (float(m_total_redundant_bytes) * 100.f / m_stat.total_payload_download()) , (float(m_stat.total_protocol_download()) * 100.f / m_stat.total_download()) - , int(cs.average_read_time) - , int(cs.average_write_time) - , int(cs.average_queue_time) + , float(cs.average_read_time) / 1000000.f + , float(cs.average_write_time) / 1000000.f + , float(cs.average_queue_time) / 1000000.f , int(cs.job_queue_length) , int(cs.queued_bytes) , int(cs.blocks_read_hit - m_last_cache_status.blocks_read_hit) @@ -3316,9 +3329,9 @@ namespace aux { , cs.read_cache_size , cs.cache_size , cs.total_used_buffers - , int(cs.average_hash_time) - , int(cs.average_job_time) - , int(cs.average_sort_time) + , float(cs.average_hash_time) / 1000000.f + , float(cs.average_job_time) / 1000000.f + , float(cs.average_sort_time) / 1000000.f , m_connection_attempts , m_num_banned_peers , m_banned_for_hash_failure @@ -3334,8 +3347,8 @@ namespace aux { , int(cs.total_read_back - m_last_cache_status.total_read_back) , float(cs.total_read_back * 100.f / (cs.blocks_written == 0 ? 1: cs.blocks_written)) , cs.read_queue_size - , tick_interval_ms - , m_tick_residual + , float(tick_interval_ms) / 1000.f + , float(m_tick_residual) / 1000.f , m_allowed_upload_slots , m_settings.unchoke_slots_limit * 2 , m_stat.low_pass_upload_rate() @@ -3347,6 +3360,8 @@ namespace aux { , int(m_tcp_download_channel.throttle()) , utp_up_rate , utp_down_rate + , float(utp_peak_send_delay) / 1000000.f + , float(utp_num_delay_sockets ? float(utp_send_delay_sum) / float(utp_num_delay_sockets) : 0) / 1000000.f ); m_last_cache_status = cs; m_last_failed = m_total_failed_bytes; diff --git a/src/utp_stream.cpp b/src/utp_stream.cpp index 807f93862..a12c5c3a2 100644 --- a/src/utp_stream.cpp +++ b/src/utp_stream.cpp @@ -236,6 +236,8 @@ struct utp_socket_impl , m_in_buf_size(100 * 1024 * 1024) , m_in_packets(0) , m_out_packets(0) + , m_send_delay(0) +// , m_recv_delay(0) , m_port(0) , m_send_id(send_id) , m_recv_id(recv_id) @@ -473,6 +475,11 @@ struct utp_socket_impl boost::uint32_t m_in_packets; boost::uint32_t m_out_packets; + // the last send delay sample + boost::int32_t m_send_delay; + // the last receive delay sample +// boost::int32_t m_recv_delay; + // average RTT sliding_average<16> m_rtt; @@ -679,6 +686,11 @@ int utp_socket_state(utp_socket_impl const* s) return s->m_state; } +int utp_stream::send_delay() const +{ + return m_impl ? m_impl->m_send_delay : 0; +} + utp_stream::utp_stream(asio::io_service& io_service) : m_io_service(io_service) , m_impl(0) @@ -2485,7 +2497,10 @@ bool utp_socket_impl::incoming_packet(char const* buf, int size delay = *std::min_element(m_delay_sample_hist, m_delay_sample_hist + num_delay_hist); if (sample && acked_bytes && prev_bytes_in_flight) + { do_ledbat(acked_bytes, delay, prev_bytes_in_flight, receive_time); + m_send_delay = delay; + } consume_incoming_data(ph, ptr, payload_size, receive_time);