From 60f16ced5ea3f537e5bd1c5ab4a240ad000173c4 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Miko=C5=82aj=20Ma=C5=82ecki?= Date: Thu, 10 Sep 2020 15:11:20 +0200 Subject: [PATCH 1/4] [FR] Added response time statistics --- srtcore/common.h | 20 +++++++++++++++ srtcore/core.cpp | 13 ++++++++-- srtcore/core.h | 67 ++++++++++++++++++++++++++++++++++++++++++++++++ srtcore/srt.h | 4 +++ 4 files changed, 102 insertions(+), 2 deletions(-) diff --git a/srtcore/common.h b/srtcore/common.h index b1781bef8..e5c289f17 100644 --- a/srtcore/common.h +++ b/srtcore/common.h @@ -1471,6 +1471,11 @@ struct MetricOp { m = 0; } + + static bool is_zero(const METRIC_TYPE& m) + { + return m == 0; + } }; template <> @@ -1483,4 +1488,19 @@ struct MetricOp } }; +template <> +struct MetricOp +{ + typedef srt::sync::steady_clock::duration duration; + static bool is_zero(const duration& m) + { + return m == duration::zero(); + } + + static void Clear(duration& m) + { + m = duration::zero(); + } +}; + #endif diff --git a/srtcore/core.cpp b/srtcore/core.cpp index 9808e7dbc..165e9eba8 100644 --- a/srtcore/core.cpp +++ b/srtcore/core.cpp @@ -1464,6 +1464,8 @@ void CUDT::clearData() m_stats.traceRcvBytesUndecrypt = 0; m_stats.sndDuration = m_stats.m_sndDurationTotal = 0; + m_stats.tdAverageResponseTime.Init(); + m_stats.tdMaxResponseTime.Init(); } // Resetting these data because this happens when agent isn't connected. @@ -7379,6 +7381,11 @@ void CUDT::bstats(CBytePerfMon *perf, bool clear, bool instantaneous) perf->msRcvBuf = 0; } + perf->msAvgResponseTimeTotal = count_milliseconds(m_stats.tdAverageResponseTime.total); + perf->msMaxResponseTimeTotal = count_milliseconds(m_stats.tdMaxResponseTime.total); + perf->msAvgResponseTime = count_milliseconds(m_stats.tdAverageResponseTime.local); + perf->msMaxResponseTime = count_milliseconds(m_stats.tdMaxResponseTime.local); + if (clear) { m_stats.traceSndDrop = 0; @@ -7405,6 +7412,8 @@ void CUDT::bstats(CBytePerfMon *perf, bool clear, bool instantaneous) m_stats.rcvFilterLoss = 0; m_stats.tsLastSampleTime = currtime; + m_stats.tdAverageResponseTime.Clear(); + m_stats.tdMaxResponseTime.Clear(); } } @@ -8362,7 +8371,7 @@ void CUDT::processCtrl(const CPacket &ctrlpkt) // Just heard from the peer, reset the expiration count. m_iEXPCount = 1; const steady_clock::time_point currtime = steady_clock::now(); - m_tsLastRspTime = currtime; + calculateResponseTime(currtime); bool using_rexmit_flag = m_bPeerRexmitFlag; HLOGC(inlog.Debug, @@ -9256,7 +9265,7 @@ int CUDT::processData(CUnit* in_unit) // m_pRcvBuffer->addLocalTsbPdDriftSample(packet.getMsgTimeStamp()); // Just heard from the peer, reset the expiration count. m_iEXPCount = 1; - m_tsLastRspTime = steady_clock::now(); + calculateResponseTime(steady_clock::now()); const bool need_tsbpd = m_bTsbPd || m_bGroupTsbPd; diff --git a/srtcore/core.h b/srtcore/core.h index b94a2a2fa..bf1cacc06 100644 --- a/srtcore/core.h +++ b/srtcore/core.h @@ -138,6 +138,53 @@ enum SeqPairItems SEQ_BEGIN = 0, SEQ_END = 1, SEQ_SIZE = 2 }; +template +struct AverageMetricUsage: public MetricUsage +{ + using MetricUsage::Clear; + using MetricUsage::Init; + using MetricUsage::local; + using MetricUsage::total; + + void Update(METRIC_TYPE value) + { + if (MetricOp::is_zero(local)) + local = value; + else + { + local = (local + value)/2; + } + + if (MetricOp::is_zero(total)) + total = value; + else + { + total = (total + value)/2; + } + } +}; + + +template +struct MaxMetricUsage: public MetricUsage +{ + using MetricUsage::Clear; + using MetricUsage::Init; + using MetricUsage::local; + using MetricUsage::total; + + void Update(METRIC_TYPE value) + { + if (value > local) + local = value; + + if (value > total) + total = value; + } +}; + + + struct SRT_SocketOptionObject { struct SingleOption @@ -1110,8 +1157,28 @@ class CUDT int64_t sndDuration; // real time for sending time_point sndDurationCounter; // timers to record the sending Duration + + AverageMetricUsage tdAverageResponseTime; + MaxMetricUsage tdMaxResponseTime; } m_stats; + /// This function records the passed current time as the last response time. + /// Before doing it, however, it checks if there exist any previous such time + /// and updates statistics accordingly. + void calculateResponseTime(const time_point& now) + { + if (!is_zero(m_tsLastRspTime)) + { + duration td = now - m_tsLastRspTime; + enterCS(m_StatsLock); + m_stats.tdAverageResponseTime.Update(td); + m_stats.tdMaxResponseTime.Update(td); + leaveCS(m_StatsLock); + } + + m_tsLastRspTime = now; + } + public: static const int SELF_CLOCK_INTERVAL = 64; // ACK interval for self-clocking static const int SEND_LITE_ACK = sizeof(int32_t); // special size for ack containing only ack seq diff --git a/srtcore/srt.h b/srtcore/srt.h index dcc78c8c7..4b18c745f 100644 --- a/srtcore/srt.h +++ b/srtcore/srt.h @@ -401,12 +401,16 @@ struct CBytePerfMon int64_t pktRecvUniqueTotal; // total number of packets to be received by the application uint64_t byteSentUniqueTotal; // total number of data bytes, sent by the application uint64_t byteRecvUniqueTotal; // total number of data bytes to be received by the application + uint32_t msAvgResponseTimeTotal; + uint32_t msMaxResponseTimeTotal; // Local int64_t pktSentUnique; // number of data packets sent by the application int64_t pktRecvUnique; // number of packets to be received by the application uint64_t byteSentUnique; // number of data bytes, sent by the application uint64_t byteRecvUnique; // number of data bytes to be received by the application + uint32_t msAvgResponseTime; + uint32_t msMaxResponseTime; }; //////////////////////////////////////////////////////////////////////////////// From fdb165d7eb9703e68afc7299f6e6ec862e512166 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Miko=C5=82aj=20Ma=C5=82ecki?= Date: Fri, 11 Sep 2020 09:52:33 +0200 Subject: [PATCH 2/4] Fixed build break --- srtcore/core.h | 2 ++ 1 file changed, 2 insertions(+) diff --git a/srtcore/core.h b/srtcore/core.h index bf1cacc06..1b86726c2 100644 --- a/srtcore/core.h +++ b/srtcore/core.h @@ -1167,6 +1167,8 @@ class CUDT /// and updates statistics accordingly. void calculateResponseTime(const time_point& now) { + using namespace srt::sync; + if (!is_zero(m_tsLastRspTime)) { duration td = now - m_tsLastRspTime; From 04564f06cd0089ed4009ee0620dfcc99d8eed429 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Miko=C5=82aj=20Ma=C5=82ecki?= Date: Tue, 20 Oct 2020 09:51:36 +0200 Subject: [PATCH 3/4] Fixed coverage of experimental-bonding for new stats utils --- srtcore/core.h | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/srtcore/core.h b/srtcore/core.h index 358404081..09957ae1f 100644 --- a/srtcore/core.h +++ b/srtcore/core.h @@ -138,7 +138,6 @@ enum SeqPairItems SEQ_BEGIN = 0, SEQ_END = 1, SEQ_SIZE = 2 }; -#if ENABLE_EXPERIMENTAL_BONDING template struct AverageMetricUsage: public MetricUsage { @@ -184,7 +183,7 @@ struct MaxMetricUsage: public MetricUsage } }; - +#if ENABLE_EXPERIMENTAL_BONDING struct SRT_SocketOptionObject { From 7a898f438965a221d17ebd09e3fb483e7cc59cfc Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Miko=C5=82aj=20Ma=C5=82ecki?= Date: Mon, 23 Nov 2020 11:22:33 +0100 Subject: [PATCH 4/4] Changed function name --- srtcore/core.cpp | 4 ++-- srtcore/core.h | 2 +- 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/srtcore/core.cpp b/srtcore/core.cpp index 2cb3b3846..076293d47 100644 --- a/srtcore/core.cpp +++ b/srtcore/core.cpp @@ -8707,7 +8707,7 @@ void CUDT::processCtrl(const CPacket &ctrlpkt) // Just heard from the peer, reset the expiration count. m_iEXPCount = 1; const steady_clock::time_point currtime = steady_clock::now(); - calculateResponseTime(currtime); + recordResponseTime(currtime); bool using_rexmit_flag = m_bPeerRexmitFlag; HLOGC(inlog.Debug, @@ -9623,7 +9623,7 @@ int CUDT::processData(CUnit* in_unit) // Just heard from the peer, reset the expiration count. m_iEXPCount = 1; - calculateResponseTime(steady_clock::now()); + recordResponseTime(steady_clock::now()); const bool need_tsbpd = m_bTsbPd || m_bGroupTsbPd; diff --git a/srtcore/core.h b/srtcore/core.h index db5907663..d5f5fd8cc 100644 --- a/srtcore/core.h +++ b/srtcore/core.h @@ -1226,7 +1226,7 @@ class CUDT /// This function records the passed current time as the last response time. /// Before doing it, however, it checks if there exist any previous such time /// and updates statistics accordingly. - void calculateResponseTime(const time_point& now) + void recordResponseTime(const time_point& now) { using namespace srt::sync;