Skip to content

Commit

Permalink
[core] Separated CC log area
Browse files Browse the repository at this point in the history
  • Loading branch information
@maxsharabayko @rndi
maxsharabayko authored and rndi committed Nov 20, 2019
1 parent ffb8039 commit 400994e
Show file tree
Hide file tree
Showing 5 changed files with 33 additions and 27 deletions.
3 changes: 2 additions & 1 deletion apps/logsupport.cpp
View file
Expand Up @@ -84,7 +84,7 @@ set<srt_logging::LogFA> SrtParseLogFA(string fa, set<string>* punknown)
if ( fa == "" )
return fas;

static string names [] = { "general", "bstats", "control", "data", "tsbpd", "rexmit" };
static string names [] = { "general", "bstats", "control", "data", "tsbpd", "rexmit", "haicrypt", "cc" };
size_t names_s = sizeof (names)/sizeof (names[0]);

if ( fa == "all" )
Expand All @@ -95,6 +95,7 @@ set<srt_logging::LogFA> SrtParseLogFA(string fa, set<string>* punknown)
fas.insert(SRT_LOGFA_DATA);
fas.insert(SRT_LOGFA_TSBPD);
fas.insert(SRT_LOGFA_REXMIT);
fas.insert(SRT_LOGFA_CONGEST);
return fas;
}

Expand Down
51 changes: 26 additions & 25 deletions srtcore/congctl.cpp
View file
Expand Up @@ -81,7 +81,7 @@ class LiveCC: public SrtCongestionControlBase
m_iMinNakInterval_us = 20000; //Minimum NAK Report Period (usec)
m_iNakReportAccel = 2; //Default NAK Report Period (RTT) accelerator

HLOGC(mglog.Debug, log << "Creating LiveCC: bw=" << m_llSndMaxBW << " avgplsize=" << m_zSndAvgPayloadSize);
HLOGC(cclog.Debug, log << "Creating LiveCC: bw=" << m_llSndMaxBW << " avgplsize=" << m_zSndAvgPayloadSize);

updatePktSndPeriod();

Expand All @@ -101,7 +101,7 @@ class LiveCC: public SrtCongestionControlBase
{
if (api != SrtCongestion::STA_MESSAGE)
{
LOGC(mglog.Error, log << "LiveCC: invalid API use. Only sendmsg/recvmsg allowed.");
LOGC(cclog.Error, log << "LiveCC: invalid API use. Only sendmsg/recvmsg allowed.");
return false;
}

Expand All @@ -110,7 +110,7 @@ class LiveCC: public SrtCongestionControlBase
// For sending, check if the size of data doesn't exceed the maximum live packet size.
if (size > m_zMaxPayloadSize)
{
LOGC(mglog.Error, log << "LiveCC: payload size: " << size << " exceeds maximum allowed " << m_zMaxPayloadSize);
LOGC(cclog.Error, log << "LiveCC: payload size: " << size << " exceeds maximum allowed " << m_zMaxPayloadSize);
return false;
}
}
Expand All @@ -119,7 +119,7 @@ class LiveCC: public SrtCongestionControlBase
// For receiving, check if the buffer has enough space to keep the payload.
if (size < m_zMaxPayloadSize)
{
LOGC(mglog.Error, log << "LiveCC: buffer size: " << size << " is too small for the maximum possible " << m_zMaxPayloadSize);
LOGC(cclog.Error, log << "LiveCC: buffer size: " << size << " is too small for the maximum possible " << m_zMaxPayloadSize);
return false;
}
}
Expand Down Expand Up @@ -148,7 +148,7 @@ class LiveCC: public SrtCongestionControlBase
// thread will pick up a "slightly outdated" average value from this
// field - this is insignificant.
m_zSndAvgPayloadSize = avg_iir<128, size_t>(m_zSndAvgPayloadSize, packet.getLength());
HLOGC(mglog.Debug, log << "LiveCC: avg payload size updated: " << m_zSndAvgPayloadSize);
HLOGC(cclog.Debug, log << "LiveCC: avg payload size updated: " << m_zSndAvgPayloadSize);
}

void updatePktSndPeriod_onTimer(ETransmissionEvent , EventVariant var)
Expand All @@ -167,7 +167,7 @@ class LiveCC: public SrtCongestionControlBase
// packet = payload + header
const double pktsize = (double) m_zSndAvgPayloadSize + CPacket::SRT_DATA_HDR_SIZE;
m_dPktSndPeriod = 1000 * 1000.0 * (pktsize / m_llSndMaxBW);
HLOGC(mglog.Debug, log << "LiveCC: sending period updated: " << m_dPktSndPeriod
HLOGC(cclog.Debug, log << "LiveCC: sending period updated: " << m_dPktSndPeriod
<< " (pktsize=" << pktsize << ", bw=" << m_llSndMaxBW);
}

Expand Down Expand Up @@ -294,7 +294,7 @@ class FileCC : public SrtCongestionControlBase
parent->ConnectSignal(TEV_LOSSREPORT, SSLOT(slowdownSndPeriod));
parent->ConnectSignal(TEV_CHECKTIMER, SSLOT(speedupToWindowSize));

HLOGC(mglog.Debug, log << "Creating FileCC");
HLOGC(cclog.Debug, log << "Creating FileCC");
}

bool checkTransArgs(SrtCongestion::TransAPI, SrtCongestion::TransDir, const char*, size_t, int, bool) ATR_OVERRIDE
Expand Down Expand Up @@ -325,7 +325,7 @@ class FileCC : public SrtCongestionControlBase
if (maxbw != 0)
{
m_maxSR = maxbw;
HLOGC(mglog.Debug, log << "FileCC: updated BW: " << m_maxSR);
HLOGC(cclog.Debug, log << "FileCC: updated BW: " << m_maxSR);
}
}

Expand Down Expand Up @@ -353,31 +353,31 @@ class FileCC : public SrtCongestionControlBase
if (m_parent->deliveryRate() > 0)
{
m_dPktSndPeriod = 1000000.0 / m_parent->deliveryRate();
HLOGC(mglog.Debug, log << "FileCC: UPD (slowstart:ENDED) wndsize="
HLOGC(cclog.Debug, log << "FileCC: UPD (slowstart:ENDED) wndsize="
<< m_dCWndSize << "/" << m_dMaxCWndSize
<< " sndperiod=" << m_dPktSndPeriod << "us = 1M/("
<< m_parent->deliveryRate() << " pkts/s)");
}
else
{
m_dPktSndPeriod = m_dCWndSize / (m_parent->RTT() + m_iRCInterval);
HLOGC(mglog.Debug, log << "FileCC: UPD (slowstart:ENDED) wndsize="
HLOGC(cclog.Debug, log << "FileCC: UPD (slowstart:ENDED) wndsize="
<< m_dCWndSize << "/" << m_dMaxCWndSize
<< " sndperiod=" << m_dPktSndPeriod << "us = wndsize/(RTT+RCIV) RTT="
<< m_parent->RTT() << " RCIV=" << m_iRCInterval);
}
}
else
{
HLOGC(mglog.Debug, log << "FileCC: UPD (slowstart:KEPT) wndsize="
HLOGC(cclog.Debug, log << "FileCC: UPD (slowstart:KEPT) wndsize="
<< m_dCWndSize << "/" << m_dMaxCWndSize
<< " sndperiod=" << m_dPktSndPeriod << "us");
}
}
else
{
m_dCWndSize = m_parent->deliveryRate() / 1000000.0 * (m_parent->RTT() + m_iRCInterval) + 16;
HLOGC(mglog.Debug, log << "FileCC: UPD (speed mode) wndsize="
HLOGC(cclog.Debug, log << "FileCC: UPD (speed mode) wndsize="
<< m_dCWndSize << "/" << m_dMaxCWndSize << " RTT = " << m_parent->RTT()
<< " sndperiod=" << m_dPktSndPeriod << "us. deliverRate = "
<< m_parent->deliveryRate() << " pkts/s)");
Expand Down Expand Up @@ -410,7 +410,7 @@ class FileCC : public SrtCongestionControlBase
inc = max(inc, 1.0 / m_parent->MSS());
}

HLOGC(mglog.Debug, log << "FileCC: UPD (slowstart:OFF) loss_bw=" << loss_bw
HLOGC(cclog.Debug, log << "FileCC: UPD (slowstart:OFF) loss_bw=" << loss_bw
<< " bandwidth=" << m_parent->bandwidth() << " inc=" << inc
<< " m_dPktSndPeriod=" << m_dPktSndPeriod
<< "->" << (m_dPktSndPeriod * m_iRCInterval) / (m_dPktSndPeriod * inc + m_iRCInterval));
Expand All @@ -436,7 +436,7 @@ class FileCC : public SrtCongestionControlBase
int udp_buffer_free = -1;
#endif

HLOGC(mglog.Debug, log << "FileCC: UPD (slowstart:"
HLOGC(cclog.Debug, log << "FileCC: UPD (slowstart:"
<< (m_bSlowStart ? "ON" : "OFF") << ") wndsize=" << m_dCWndSize
<< " sndperiod=" << m_dPktSndPeriod << "us BANDWIDTH USED:" << usedbw << " (limit: " << m_maxSR << ")"
" SYSTEM BUFFER LEFT: " << udp_buffer_free);
Expand All @@ -449,7 +449,7 @@ class FileCC : public SrtCongestionControlBase
if (m_dPktSndPeriod < minSP)
{
m_dPktSndPeriod = minSP;
HLOGC(mglog.Debug, log << "FileCC: BW limited to " << m_maxSR
HLOGC(cclog.Debug, log << "FileCC: BW limited to " << m_maxSR
<< " - SLOWDOWN sndperiod=" << m_dPktSndPeriod << "us");
}
}
Expand All @@ -467,7 +467,7 @@ class FileCC : public SrtCongestionControlBase
// is called with a nonempty loss list.
if (losslist_size == 0)
{
LOGC(mglog.Error, log << "IPE: FileCC: empty loss list!");
LOGC(cclog.Error, log << "IPE: FileCC: empty loss list!");
return;
}

Expand All @@ -478,31 +478,32 @@ class FileCC : public SrtCongestionControlBase
if (m_parent->deliveryRate() > 0)
{
m_dPktSndPeriod = 1000000.0 / m_parent->deliveryRate();
HLOGC(mglog.Debug, log << "FileCC: LOSS, SLOWSTART:OFF, sndperiod=" << m_dPktSndPeriod << "us AS mega/rate (rate="
HLOGC(cclog.Debug, log << "FileCC: LOSS, SLOWSTART:OFF, sndperiod=" << m_dPktSndPeriod << "us AS mega/rate (rate="
<< m_parent->deliveryRate() << ")");
}
else
{
m_dPktSndPeriod = m_dCWndSize / (m_parent->RTT() + m_iRCInterval);
HLOGC(mglog.Debug, log << "FileCC: LOSS, SLOWSTART:OFF, sndperiod=" << m_dPktSndPeriod << "us AS wndsize/(RTT+RCIV) (RTT="
HLOGC(cclog.Debug, log << "FileCC: LOSS, SLOWSTART:OFF, sndperiod=" << m_dPktSndPeriod << "us AS wndsize/(RTT+RCIV) (RTT="
<< m_parent->RTT() << " RCIV=" << m_iRCInterval << ")");
}

}

m_bLoss = true;

// TODO: const int pktsInFlight = CSeqNo::seqoff(m_iLastAck, m_parent->sndSeqNo());
const int pktsInFlight = m_parent->RTT() / m_dPktSndPeriod;
const int numPktsLost = m_parent->sndLossLength();
const int lost_pcent_x10 = pktsInFlight > 0 ? (numPktsLost * 1000) / pktsInFlight : 0;

HLOGC(mglog.Debug, log << "FileSmootherV2: LOSS: "
HLOGC(cclog.Debug, log << "FileCC: LOSS: "
<< "sent=" << CSeqNo::seqlen(m_iLastAck, m_parent->sndSeqNo()) << ", inFlight=" << pktsInFlight
<< ", lost=" << numPktsLost << " ("
<< lost_pcent_x10 / 10 << "." << lost_pcent_x10 % 10 << "\%)");
if (lost_pcent_x10 < 20) // 2.0%
{
HLOGC(mglog.Debug, log << "FileSmootherV2: LOSS: m_dLastDecPeriod=" << m_dLastDecPeriod << "->" << m_dPktSndPeriod);
HLOGC(cclog.Debug, log << "FileCC: LOSS: m_dLastDecPeriod=" << m_dLastDecPeriod << "->" << m_dPktSndPeriod);
m_dLastDecPeriod = m_dPktSndPeriod;
return;
}
Expand Down Expand Up @@ -531,7 +532,7 @@ class FileCC : public SrtCongestionControlBase
m_iDecRandom = (int)ceil(m_iAvgNAKNum * (double(rand()) / RAND_MAX));
if (m_iDecRandom < 1)
m_iDecRandom = 1;
HLOGC(mglog.Debug, log << "FileCC: LOSS:NEW lseqno=" << lossbegin
HLOGC(cclog.Debug, log << "FileCC: LOSS:NEW lseqno=" << lossbegin
<< ", lastsentseqno=" << m_iLastDecSeq
<< ", seqdiff=" << CSeqNo::seqoff(m_iLastDecSeq, lossbegin)
<< ", rand=" << m_iDecRandom
Expand All @@ -543,7 +544,7 @@ class FileCC : public SrtCongestionControlBase
// 0.875^5 = 0.51, rate should not be decreased by more than half within a congestion period
m_dPktSndPeriod = ceil(m_dPktSndPeriod * 1.03);
m_iLastDecSeq = m_parent->sndSeqNo();
HLOGC(mglog.Debug, log << "FileCC: LOSS:PERIOD lseqno=" << lossbegin
HLOGC(cclog.Debug, log << "FileCC: LOSS:PERIOD lseqno=" << lossbegin
<< ", lastsentseqno=" << m_iLastDecSeq
<< ", seqdiff=" << CSeqNo::seqoff(m_iLastDecSeq, lossbegin)
<< ", deccnt=" << m_iDecCount
Expand All @@ -552,7 +553,7 @@ class FileCC : public SrtCongestionControlBase
}
else
{
HLOGC(mglog.Debug, log << "FileCC: LOSS:STILL lseqno=" << lossbegin
HLOGC(cclog.Debug, log << "FileCC: LOSS:STILL lseqno=" << lossbegin
<< ", lastsentseqno=" << m_iLastDecSeq
<< ", seqdiff=" << CSeqNo::seqoff(m_iLastDecSeq, lossbegin)
<< ", deccnt=" << m_iDecCount
Expand All @@ -577,13 +578,13 @@ class FileCC : public SrtCongestionControlBase
if (m_parent->deliveryRate() > 0)
{
m_dPktSndPeriod = 1000000.0 / m_parent->deliveryRate();
HLOGC(mglog.Debug, log << "FileCC: CHKTIMER, SLOWSTART:OFF, sndperiod=" << m_dPktSndPeriod << "us AS mega/rate (rate="
HLOGC(cclog.Debug, log << "FileCC: CHKTIMER, SLOWSTART:OFF, sndperiod=" << m_dPktSndPeriod << "us AS mega/rate (rate="
<< m_parent->deliveryRate() << ")");
}
else
{
m_dPktSndPeriod = m_dCWndSize / (m_parent->RTT() + m_iRCInterval);
HLOGC(mglog.Debug, log << "FileCC: CHKTIMER, SLOWSTART:OFF, sndperiod=" << m_dPktSndPeriod << "us AS wndsize/(RTT+RCIV) (wndsize="
HLOGC(cclog.Debug, log << "FileCC: CHKTIMER, SLOWSTART:OFF, sndperiod=" << m_dPktSndPeriod << "us AS wndsize/(RTT+RCIV) (wndsize="
<< setprecision(6) << m_dCWndSize << " RTT=" << m_parent->RTT() << " RCIV=" << m_iRCInterval << ")");
}
}
Expand Down
2 changes: 2 additions & 0 deletions srtcore/core.cpp
View file
Expand Up @@ -94,6 +94,7 @@ struct AllFaOn
allfa.set(SRT_LOGFA_DATA, true);
allfa.set(SRT_LOGFA_TSBPD, true);
allfa.set(SRT_LOGFA_REXMIT, true);
allfa.set(SRT_LOGFA_CONGEST, true);
#if ENABLE_HAICRYPT_LOGGING
allfa.set(SRT_LOGFA_HAICRYPT, true);
#endif
Expand All @@ -116,6 +117,7 @@ Logger mglog(SRT_LOGFA_CONTROL, srt_logger_config, "SRT.c");
Logger dlog(SRT_LOGFA_DATA, srt_logger_config, "SRT.d");
Logger tslog(SRT_LOGFA_TSBPD, srt_logger_config, "SRT.t");
Logger rxlog(SRT_LOGFA_REXMIT, srt_logger_config, "SRT.r");
Logger cclog(SRT_LOGFA_CONGEST, srt_logger_config, "SRT.cc");

} // namespace srt_logging

Expand Down
3 changes: 2 additions & 1 deletion srtcore/core.h
View file
Expand Up @@ -83,7 +83,8 @@ extern Logger
mglog,
dlog,
tslog,
rxlog;
rxlog,
cclog;

}

Expand Down
1 change: 1 addition & 0 deletions srtcore/srt.h
View file
Expand Up @@ -503,6 +503,7 @@ enum SRT_REJECT_REASON
#define SRT_LOGFA_TSBPD 4
#define SRT_LOGFA_REXMIT 5
#define SRT_LOGFA_HAICRYPT 6
#define SRT_LOGFA_CONGEST 7

// To make a typical int32_t size, although still use std::bitset.
// C API will carry it over.
Expand Down

0 comments on commit 400994e

Please sign in to comment.