From d54c85d31b266247cedb25394bc57420e11db767 Mon Sep 17 00:00:00 2001 From: Arvid Norberg Date: Wed, 28 Sep 2011 00:03:12 +0000 Subject: [PATCH] log uTP receive delay in stats log --- include/libtorrent/utp_stream.hpp | 1 + parse_session_stats.py | 5 +++-- src/session_impl.cpp | 14 ++++++++++++++ src/utp_stream.cpp | 11 +++++++++-- 4 files changed, 27 insertions(+), 4 deletions(-) diff --git a/include/libtorrent/utp_stream.hpp b/include/libtorrent/utp_stream.hpp index 0717b34a4..e80087d2f 100644 --- a/include/libtorrent/utp_stream.hpp +++ b/include/libtorrent/utp_stream.hpp @@ -220,6 +220,7 @@ public: size_t read_some(bool clear_buffers); int send_delay() const; + int recv_delay() const; void do_connect(tcp::endpoint const& ep, connect_handler_t h); diff --git a/parse_session_stats.py b/parse_session_stats.py index a85d4d034..a4ddc76df 100755 --- a/parse_session_stats.py +++ b/parse_session_stats.py @@ -144,8 +144,9 @@ reports = [ ('disk_iops', 'operations/s', '', 'number of disk operations per second', ['read ops/s', 'write ops/s', 'smooth read ops/s', 'smooth write ops/s']), ('disk pending reads', 'Bytes', '', 'number of bytes peers are waiting for to be read from the disk', ['pending reading bytes']), ('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', 'buffering delay', 's', 'network delays measured by uTP', ['uTP peak send delay','uTP avg send delay']), - ('uTP delay histogram', 'buffering delay', 's', 'network delays measured by uTP', ['uTP avg send delay'], True), + ('uTP delay', 'buffering delay', 's', 'network delays measured by uTP', ['uTP peak send delay','uTP peak recv delay', 'uTP avg send delay', 'uTP avg recv delay']), + ('uTP send delay histogram', 'buffering delay', 's', 'send delays measured by uTP', ['uTP avg send delay'], True), + ('uTP recv delay histogram', 'buffering delay', 's', 'receive delays measured by uTP', ['uTP avg recv delay'], True), ('system memory', '', '', 'virtual memory page count', ['active resident pages', 'inactive resident pages', 'pinned resident pages', 'free pages']), ('memory paging', '', '', 'vm disk activity', ['pageins', 'pageouts']), ('page faults', '', '', '', ['page faults']), diff --git a/src/session_impl.cpp b/src/session_impl.cpp index cfd30372d..0a1b6c8f6 100644 --- a/src/session_impl.cpp +++ b/src/session_impl.cpp @@ -1031,6 +1031,8 @@ namespace aux { ":uTP down rate" ":uTP peak send delay" ":uTP avg send delay" + ":uTP peak recv delay" + ":uTP avg recv delay" ":read ops/s" ":write ops/s" ":active resident pages" @@ -3271,8 +3273,11 @@ namespace aux { int utp_up_rate = 0; int utp_down_rate = 0; int utp_peak_send_delay = 0; + int utp_peak_recv_delay = 0; boost::uint64_t utp_send_delay_sum = 0; + boost::uint64_t utp_recv_delay_sum = 0; int utp_num_delay_sockets = 0; + int utp_num_recv_delay_sockets = 0; int num_complete_connections = 0; int num_half_open = 0; int peers_down_unchoked = 0; @@ -3329,12 +3334,19 @@ namespace aux { utp_up_rate += ul_rate; utp_down_rate += dl_rate; int send_delay = utp_socket->send_delay(); + int recv_delay = utp_socket->recv_delay(); utp_peak_send_delay = (std::max)(utp_peak_send_delay, send_delay); + utp_peak_recv_delay = (std::max)(utp_peak_recv_delay, recv_delay); if (send_delay > 0) { utp_send_delay_sum += send_delay; ++utp_num_delay_sockets; } + if (recv_delay > 0) + { + utp_recv_delay_sum += recv_delay; + ++utp_num_recv_delay_sockets; + } } else { @@ -3477,6 +3489,8 @@ namespace aux { STAT_LOG(d, utp_down_rate); STAT_LOG(f, float(utp_peak_send_delay) / 1000000.f); STAT_LOG(f, float(utp_num_delay_sockets ? float(utp_send_delay_sum) / float(utp_num_delay_sockets) : 0) / 1000000.f); + STAT_LOG(f, float(utp_peak_recv_delay) / 1000000.f); + STAT_LOG(f, float(utp_num_recv_delay_sockets ? float(utp_recv_delay_sum) / float(utp_num_recv_delay_sockets) : 0) / 1000000.f); STAT_LOG(f, float(cs.reads - m_last_cache_status.reads) * 1000.0 / float(tick_interval_ms)); STAT_LOG(f, float(cs.writes - m_last_cache_status.writes) * 1000.0 / float(tick_interval_ms)); diff --git a/src/utp_stream.cpp b/src/utp_stream.cpp index 35057f66a..c70be0cd7 100644 --- a/src/utp_stream.cpp +++ b/src/utp_stream.cpp @@ -237,7 +237,7 @@ struct utp_socket_impl , m_in_packets(0) , m_out_packets(0) , m_send_delay(0) -// , m_recv_delay(0) + , m_recv_delay(0) , m_port(0) , m_send_id(send_id) , m_recv_id(recv_id) @@ -470,7 +470,7 @@ struct utp_socket_impl // the last send delay sample boost::int32_t m_send_delay; // the last receive delay sample -// boost::int32_t m_recv_delay; + boost::int32_t m_recv_delay; // average RTT sliding_average<16> m_rtt; @@ -683,6 +683,11 @@ int utp_stream::send_delay() const return m_impl ? m_impl->m_send_delay : 0; } +int utp_stream::recv_delay() const +{ + return m_impl ? m_impl->m_recv_delay : 0; +} + utp_stream::utp_stream(asio::io_service& io_service) : m_io_service(io_service) , m_impl(0) @@ -2505,6 +2510,8 @@ bool utp_socket_impl::incoming_packet(char const* buf, int size m_send_delay = delay; } + m_recv_delay = (std::min)(their_delay, min_rtt); + consume_incoming_data(ph, ptr, payload_size, receive_time); // the parameter to send_pkt tells it if we're acking data