<p>pespin <strong>submitted</strong> this change.</p><p><a href="https://gerrit.osmocom.org/c/osmo-trx/+/19205">View Change</a></p><div style="white-space:pre-wrap">Approvals:
fixeria: Looks good to me, but someone else must approve
daniel: Looks good to me, approved
Jenkins Builder: Verified
</div><pre style="font-family: monospace,monospace; white-space: pre-wrap;">Introduce rate counters to detect issues in received Dl bursts from TRXD<br><br>This ones together with rate counters already available in lower layers<br>allows to understand better the source of the problem with stalled tx<br>bursts.<br><br>Change-Id: Ia34f7e7d780ad1e12f24638a07f05fe91f2afea5<br>---<br>M CommonLibs/osmo_signal.h<br>M CommonLibs/trx_rate_ctr.cpp<br>M CommonLibs/trx_rate_ctr.h<br>M CommonLibs/trx_vty.c<br>M Transceiver52M/Transceiver.cpp<br>M Transceiver52M/Transceiver.h<br>6 files changed, 80 insertions(+), 10 deletions(-)<br><br></pre><pre style="font-family: monospace,monospace; white-space: pre-wrap;"><span>diff --git a/CommonLibs/osmo_signal.h b/CommonLibs/osmo_signal.h</span><br><span>index de17b1d..5cd90c6 100644</span><br><span>--- a/CommonLibs/osmo_signal.h</span><br><span>+++ b/CommonLibs/osmo_signal.h</span><br><span>@@ -61,4 +61,7 @@</span><br><span> struct trx_counters {</span><br><span> size_t chan;</span><br><span> unsigned int tx_stale_bursts; /* Amount of Tx bursts dropped to to arriving too late from TRXD */</span><br><span style="color: hsl(120, 100%, 40%);">+ unsigned int tx_trxd_fn_repeated;</span><br><span style="color: hsl(120, 100%, 40%);">+ unsigned int tx_trxd_fn_outoforder;</span><br><span style="color: hsl(120, 100%, 40%);">+ unsigned int tx_trxd_fn_skipped;</span><br><span> };</span><br><span>diff --git a/CommonLibs/trx_rate_ctr.cpp b/CommonLibs/trx_rate_ctr.cpp</span><br><span>index 6391a38..8b2597d 100644</span><br><span>--- a/CommonLibs/trx_rate_ctr.cpp</span><br><span>+++ b/CommonLibs/trx_rate_ctr.cpp</span><br><span>@@ -103,6 +103,9 @@</span><br><span> { TRX_CTR_DEV_TX_DROP_EV, "tx_drop_events" },</span><br><span> { TRX_CTR_DEV_TX_DROP_SMPL, "tx_drop_samples" },</span><br><span> { TRX_CTR_TRX_TX_STALE_BURSTS, "tx_stale_bursts" },</span><br><span style="color: hsl(120, 100%, 40%);">+ { TRX_CTR_TRX_TRXD_FN_REPEATED, "tx_trxd_fn_repeated" },</span><br><span style="color: hsl(120, 100%, 40%);">+ { TRX_CTR_TRX_TRXD_FN_OUTOFORDER, "tx_trxd_fn_outoforder" },</span><br><span style="color: hsl(120, 100%, 40%);">+ { TRX_CTR_TRX_TRXD_FN_SKIPPED, "tx_trxd_fn_skipped" },</span><br><span> { 0, NULL }</span><br><span> };</span><br><span> </span><br><span>@@ -114,6 +117,9 @@</span><br><span> [TRX_CTR_DEV_TX_DROP_EV] = { "device:tx_drop_events", "Number of times Tx samples were dropped by HW" },</span><br><span> [TRX_CTR_DEV_TX_DROP_SMPL] = { "device:tx_drop_samples", "Number of Tx samples dropped by HW" },</span><br><span> [TRX_CTR_TRX_TX_STALE_BURSTS] = { "trx:tx_stale_bursts", "Number of Tx burts dropped by TRX due to arriving too late" },</span><br><span style="color: hsl(120, 100%, 40%);">+ [TRX_CTR_TRX_TRXD_FN_REPEATED] = { "trx:tx_trxd_fn_repeated", "Number of Tx burts received from TRXD with repeated FN" },</span><br><span style="color: hsl(120, 100%, 40%);">+ [TRX_CTR_TRX_TRXD_FN_OUTOFORDER] = { "trx:tx_trxd_fn_outoforder","Number of Tx burts received from TRXD with a past FN" },</span><br><span style="color: hsl(120, 100%, 40%);">+ [TRX_CTR_TRX_TRXD_FN_SKIPPED] = { "trx:tx_trxd_fn_skipped", "Number of Tx burts potentially skipped due to FN jumps" },</span><br><span> };</span><br><span> </span><br><span> static const struct rate_ctr_group_desc trx_chan_ctr_group_desc = {</span><br><span>@@ -166,6 +172,12 @@</span><br><span> LOGCHAN(chan, DMAIN, INFO) << "rate_ctr update";</span><br><span> ctr = &rate_ctrs[chan]->ctr[TRX_CTR_TRX_TX_STALE_BURSTS];</span><br><span> rate_ctr_add(ctr, trx_ctrs_pending[chan].tx_stale_bursts - ctr->current);</span><br><span style="color: hsl(120, 100%, 40%);">+ ctr = &rate_ctrs[chan]->ctr[TRX_CTR_TRX_TRXD_FN_REPEATED];</span><br><span style="color: hsl(120, 100%, 40%);">+ rate_ctr_add(ctr, trx_ctrs_pending[chan].tx_trxd_fn_repeated - ctr->current);</span><br><span style="color: hsl(120, 100%, 40%);">+ ctr = &rate_ctrs[chan]->ctr[TRX_CTR_TRX_TRXD_FN_OUTOFORDER];</span><br><span style="color: hsl(120, 100%, 40%);">+ rate_ctr_add(ctr, trx_ctrs_pending[chan].tx_trxd_fn_outoforder - ctr->current);</span><br><span style="color: hsl(120, 100%, 40%);">+ ctr = &rate_ctrs[chan]->ctr[TRX_CTR_TRX_TRXD_FN_SKIPPED];</span><br><span style="color: hsl(120, 100%, 40%);">+ rate_ctr_add(ctr, trx_ctrs_pending[chan].tx_trxd_fn_skipped - ctr->current);</span><br><span> /* Mark as done */</span><br><span> trx_ctrs_pending[chan].chan = PENDING_CHAN_NONE;</span><br><span> }</span><br><span>diff --git a/CommonLibs/trx_rate_ctr.h b/CommonLibs/trx_rate_ctr.h</span><br><span>index 588ac2f..cef3c21 100644</span><br><span>--- a/CommonLibs/trx_rate_ctr.h</span><br><span>+++ b/CommonLibs/trx_rate_ctr.h</span><br><span>@@ -11,6 +11,9 @@</span><br><span> TRX_CTR_DEV_TX_DROP_EV,</span><br><span> TRX_CTR_DEV_TX_DROP_SMPL,</span><br><span> TRX_CTR_TRX_TX_STALE_BURSTS,</span><br><span style="color: hsl(120, 100%, 40%);">+ TRX_CTR_TRX_TRXD_FN_REPEATED,</span><br><span style="color: hsl(120, 100%, 40%);">+ TRX_CTR_TRX_TRXD_FN_OUTOFORDER,</span><br><span style="color: hsl(120, 100%, 40%);">+ TRX_CTR_TRX_TRXD_FN_SKIPPED,</span><br><span> };</span><br><span> </span><br><span> struct ctr_threshold {</span><br><span>diff --git a/CommonLibs/trx_vty.c b/CommonLibs/trx_vty.c</span><br><span>index f085d09..941a435 100644</span><br><span>--- a/CommonLibs/trx_vty.c</span><br><span>+++ b/CommonLibs/trx_vty.c</span><br><span>@@ -390,7 +390,7 @@</span><br><span> return -1;</span><br><span> }</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">-#define THRESHOLD_ARGS "(rx_overruns|tx_underruns|rx_drop_events|rx_drop_samples|tx_drop_events|tx_drop_samples|tx_stale_bursts)"</span><br><span style="color: hsl(120, 100%, 40%);">+#define THRESHOLD_ARGS "(rx_overruns|tx_underruns|rx_drop_events|rx_drop_samples|tx_drop_events|tx_drop_samples|tx_stale_bursts|tx_trxd_fn_repeated|tx_trxd_fn_outoforder|tx_trxd_fn_skipped)"</span><br><span> #define THRESHOLD_STR_VAL(s) "Set threshold value for rate_ctr device:" OSMO_STRINGIFY_VAL(s) "\n"</span><br><span> #define THRESHOLD_STRS \</span><br><span> THRESHOLD_STR_VAL(rx_overruns) \</span><br><span>@@ -399,7 +399,11 @@</span><br><span> THRESHOLD_STR_VAL(rx_drop_samples) \</span><br><span> THRESHOLD_STR_VAL(tx_drop_events) \</span><br><span> THRESHOLD_STR_VAL(tx_drop_samples) \</span><br><span style="color: hsl(0, 100%, 40%);">- THRESHOLD_STR_VAL(tx_stale_bursts)</span><br><span style="color: hsl(120, 100%, 40%);">+ THRESHOLD_STR_VAL(tx_stale_bursts) \</span><br><span style="color: hsl(120, 100%, 40%);">+ THRESHOLD_STR_VAL(tx_trxd_fn_repeated) \</span><br><span style="color: hsl(120, 100%, 40%);">+ THRESHOLD_STR_VAL(tx_trxd_fn_outoforder) \</span><br><span style="color: hsl(120, 100%, 40%);">+ THRESHOLD_STR_VAL(tx_trxd_fn_skipped) \</span><br><span style="color: hsl(120, 100%, 40%);">+ ""</span><br><span> #define INTV_ARGS "(per-second|per-minute|per-hour|per-day)"</span><br><span> #define INTV_STR_VAL(s) "Threshold value sampled " OSMO_STRINGIFY_VAL(s) "\n"</span><br><span> #define INTV_STRS \</span><br><span>diff --git a/Transceiver52M/Transceiver.cpp b/Transceiver52M/Transceiver.cpp</span><br><span>index 2ae5eda..d45a28b 100644</span><br><span>--- a/Transceiver52M/Transceiver.cpp</span><br><span>+++ b/Transceiver52M/Transceiver.cpp</span><br><span>@@ -52,6 +52,14 @@</span><br><span> /* Number of running values use in noise average */</span><br><span> #define NOISE_CNT 20</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+static void dispatch_trx_rate_ctr_change(TransceiverState *state, unsigned int chan) {</span><br><span style="color: hsl(120, 100%, 40%);">+ thread_enable_cancel(false);</span><br><span style="color: hsl(120, 100%, 40%);">+ state->ctrs.chan = chan;</span><br><span style="color: hsl(120, 100%, 40%);">+ osmo_signal_dispatch(SS_DEVICE, S_TRX_COUNTER_CHANGE, &state->ctrs);</span><br><span style="color: hsl(120, 100%, 40%);">+ thread_enable_cancel(true);</span><br><span style="color: hsl(120, 100%, 40%);">+}</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> TransceiverState::TransceiverState()</span><br><span> : mRetrans(false), mNoiseLev(0.0), mNoises(NOISE_CNT), mPower(0.0)</span><br><span> {</span><br><span>@@ -87,6 +95,8 @@</span><br><span> if ((sps != 1) && (sps != 4))</span><br><span> return false;</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+ mFiller = filler;</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> for (size_t n = 0; n < 8; n++) {</span><br><span> for (size_t i = 0; i < 102; i++) {</span><br><span> switch (filler) {</span><br><span>@@ -437,12 +447,8 @@</span><br><span> delete burst;</span><br><span> }</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- if (stale_bursts_changed) {</span><br><span style="color: hsl(0, 100%, 40%);">- thread_enable_cancel(false);</span><br><span style="color: hsl(0, 100%, 40%);">- state->ctrs.chan = i;</span><br><span style="color: hsl(0, 100%, 40%);">- osmo_signal_dispatch(SS_DEVICE, S_TRX_COUNTER_CHANGE, &state->ctrs);</span><br><span style="color: hsl(0, 100%, 40%);">- thread_enable_cancel(true);</span><br><span style="color: hsl(0, 100%, 40%);">- }</span><br><span style="color: hsl(120, 100%, 40%);">+ if (stale_bursts_changed)</span><br><span style="color: hsl(120, 100%, 40%);">+ dispatch_trx_rate_ctr_change(state, i);</span><br><span> </span><br><span> TN = nowTime.TN();</span><br><span> modFN = nowTime.FN() % state->fillerModulus[TN];</span><br><span>@@ -1001,6 +1007,7 @@</span><br><span> struct trxd_hdr_v01_dl *dl;</span><br><span> char buffer[sizeof(*dl) + EDGE_BURST_NBITS];</span><br><span> uint32_t fn;</span><br><span style="color: hsl(120, 100%, 40%);">+ uint8_t tn;</span><br><span> </span><br><span> // check data socket</span><br><span> msgLen = read(mDataSockets[chan], buffer, sizeof(buffer));</span><br><span>@@ -1029,6 +1036,7 @@</span><br><span> </span><br><span> /* Convert TDMA FN to the host endianness */</span><br><span> fn = osmo_load32be(&dl->common.fn);</span><br><span style="color: hsl(120, 100%, 40%);">+ tn = dl->common.tn;</span><br><span> </span><br><span> /* Make sure we support the received header format */</span><br><span> switch (dl->common.version) {</span><br><span>@@ -1044,14 +1052,49 @@</span><br><span> LOGCHAN(chan, DTRXDDL, DEBUG) << "Rx TRXD message (hdr_ver=" << unsigned(dl->common.version)</span><br><span> << "): fn=" << fn << ", tn=" << unsigned(dl->common.tn) << ", burst_len=" << burstLen;</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+ TransceiverState *state = &mStates[chan];</span><br><span style="color: hsl(120, 100%, 40%);">+ GSM::Time currTime = GSM::Time(fn, tn);</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ /* Verify proper FN order in DL stream */</span><br><span style="color: hsl(120, 100%, 40%);">+ if (state->first_dl_fn_rcv[tn]) {</span><br><span style="color: hsl(120, 100%, 40%);">+ int32_t delta = GSM::FNDelta(currTime.FN(), state->last_dl_time_rcv[tn].FN());</span><br><span style="color: hsl(120, 100%, 40%);">+ if (delta == 1) {</span><br><span style="color: hsl(120, 100%, 40%);">+ /* usual expected scenario, continue code flow */</span><br><span style="color: hsl(120, 100%, 40%);">+ } else if (delta == 0) {</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGCHAN(chan, DTRXDDL, NOTICE) << "Rx TRXD msg with repeated FN " << currTime;</span><br><span style="color: hsl(120, 100%, 40%);">+ state->ctrs.tx_trxd_fn_repeated++;</span><br><span style="color: hsl(120, 100%, 40%);">+ dispatch_trx_rate_ctr_change(state, chan);</span><br><span style="color: hsl(120, 100%, 40%);">+ return true;</span><br><span style="color: hsl(120, 100%, 40%);">+ } else if (delta < 0) {</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGCHAN(chan, DTRXDDL, NOTICE) << "Rx TRXD msg with previous FN " << currTime</span><br><span style="color: hsl(120, 100%, 40%);">+ << " vs last " << state->last_dl_time_rcv[tn];</span><br><span style="color: hsl(120, 100%, 40%);">+ state->ctrs.tx_trxd_fn_outoforder++;</span><br><span style="color: hsl(120, 100%, 40%);">+ dispatch_trx_rate_ctr_change(state, chan);</span><br><span style="color: hsl(120, 100%, 40%);">+ /* Allow adding radio vector below, since it gets sorted in the queue */</span><br><span style="color: hsl(120, 100%, 40%);">+ } else if (chan == 0 && state->mFiller == FILLER_ZERO) {</span><br><span style="color: hsl(120, 100%, 40%);">+ /* delta > 1. Some FN was lost in the middle. We can only easily rely</span><br><span style="color: hsl(120, 100%, 40%);">+ * on consecutive FNs in TRX0 since it must transmit continuously in all</span><br><span style="color: hsl(120, 100%, 40%);">+ * setups. Also, osmo-trx supports optionally filling empty bursts on</span><br><span style="color: hsl(120, 100%, 40%);">+ * its own. In that case bts-trx is not obliged to submit all bursts. */</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGCHAN(chan, DTRXDDL, NOTICE) << "Rx TRXD msg with future FN " << currTime</span><br><span style="color: hsl(120, 100%, 40%);">+ << " vs last " << state->last_dl_time_rcv[tn]</span><br><span style="color: hsl(120, 100%, 40%);">+ << ", " << delta - 1 << " FN lost";</span><br><span style="color: hsl(120, 100%, 40%);">+ state->ctrs.tx_trxd_fn_skipped += delta - 1;</span><br><span style="color: hsl(120, 100%, 40%);">+ dispatch_trx_rate_ctr_change(state, chan);</span><br><span style="color: hsl(120, 100%, 40%);">+ }</span><br><span style="color: hsl(120, 100%, 40%);">+ if (delta > 0)</span><br><span style="color: hsl(120, 100%, 40%);">+ state->last_dl_time_rcv[tn] = currTime;</span><br><span style="color: hsl(120, 100%, 40%);">+ } else { /* Initial check, simply store state */</span><br><span style="color: hsl(120, 100%, 40%);">+ state->first_dl_fn_rcv[tn] = true;</span><br><span style="color: hsl(120, 100%, 40%);">+ state->last_dl_time_rcv[tn] = currTime;</span><br><span style="color: hsl(120, 100%, 40%);">+ }</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> BitVector newBurst(burstLen);</span><br><span> BitVector::iterator itr = newBurst.begin();</span><br><span> uint8_t *bufferItr = dl->soft_bits;</span><br><span> while (itr < newBurst.end())</span><br><span> *itr++ = *bufferItr++;</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- GSM::Time currTime = GSM::Time(fn, dl->common.tn);</span><br><span style="color: hsl(0, 100%, 40%);">-</span><br><span> addRadioVector(chan, newBurst, dl->tx_att, currTime);</span><br><span> </span><br><span> return true;</span><br><span>diff --git a/Transceiver52M/Transceiver.h b/Transceiver52M/Transceiver.h</span><br><span>index 7ce5fa2..39298aa 100644</span><br><span>--- a/Transceiver52M/Transceiver.h</span><br><span>+++ b/Transceiver52M/Transceiver.h</span><br><span>@@ -63,6 +63,7 @@</span><br><span> /* The filler table */</span><br><span> signalVector *fillerTable[102][8];</span><br><span> int fillerModulus[8];</span><br><span style="color: hsl(120, 100%, 40%);">+ FillerType mFiller;</span><br><span> bool mRetrans;</span><br><span> </span><br><span> /* Most recent channel estimate of all timeslots */</span><br><span>@@ -86,6 +87,10 @@</span><br><span> </span><br><span> /* counters */</span><br><span> struct trx_counters ctrs;</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ /* Used to keep track of lost and out of order frames */</span><br><span style="color: hsl(120, 100%, 40%);">+ bool first_dl_fn_rcv[8];</span><br><span style="color: hsl(120, 100%, 40%);">+ GSM::Time last_dl_time_rcv[8];</span><br><span> };</span><br><span> </span><br><span> /** The Transceiver class, responsible for physical layer of basestation */</span><br><span></span><br></pre><p>To view, visit <a href="https://gerrit.osmocom.org/c/osmo-trx/+/19205">change 19205</a>. To unsubscribe, or for help writing mail filters, visit <a href="https://gerrit.osmocom.org/settings">settings</a>.</p><div itemscope itemtype="http://schema.org/EmailMessage"><div itemscope itemprop="action" itemtype="http://schema.org/ViewAction"><link itemprop="url" href="https://gerrit.osmocom.org/c/osmo-trx/+/19205"/><meta itemprop="name" content="View Change"/></div></div>
<div style="display:none"> Gerrit-Project: osmo-trx </div>
<div style="display:none"> Gerrit-Branch: master </div>
<div style="display:none"> Gerrit-Change-Id: Ia34f7e7d780ad1e12f24638a07f05fe91f2afea5 </div>
<div style="display:none"> Gerrit-Change-Number: 19205 </div>
<div style="display:none"> Gerrit-PatchSet: 4 </div>
<div style="display:none"> Gerrit-Owner: pespin <pespin@sysmocom.de> </div>
<div style="display:none"> Gerrit-Reviewer: Jenkins Builder </div>
<div style="display:none"> Gerrit-Reviewer: daniel <dwillmann@sysmocom.de> </div>
<div style="display:none"> Gerrit-Reviewer: fixeria <vyanitskiy@sysmocom.de> </div>
<div style="display:none"> Gerrit-Reviewer: laforge <laforge@osmocom.org> </div>
<div style="display:none"> Gerrit-Reviewer: pespin <pespin@sysmocom.de> </div>
<div style="display:none"> Gerrit-MessageType: merged </div>