<p>pespin has uploaded this change for <strong>review</strong>.</p><p><a href="https://gerrit.osmocom.org/c/osmo-pcu/+/20243">View Change</a></p><pre style="font-family: monospace,monospace; white-space: pre-wrap;">tbf: Don't log rlcmac_diag() output in separate lines<br><br>Output of all diag in different lines is really confusing, since the<br>user reads a timeout ocurred and then later in another line something<br>like "Downlink ACK was received" while no GSMTAP message shows any ACK.<br><br>Change-Id: I6a7d79c16c930f0712bc73b308409ececb1946ba<br>---<br>M src/tbf.cpp<br>M src/tbf.h<br>M tests/tbf/TbfTest.err<br>3 files changed, 31 insertions(+), 22 deletions(-)<br><br></pre><pre style="font-family: monospace,monospace; white-space: pre-wrap;">git pull ssh://gerrit.osmocom.org:29418/osmo-pcu refs/changes/43/20243/1</pre><pre style="font-family: monospace,monospace; white-space: pre-wrap;"><span>diff --git a/src/tbf.cpp b/src/tbf.cpp</span><br><span>index 0447edc..9545511 100644</span><br><span>--- a/src/tbf.cpp</span><br><span>+++ b/src/tbf.cpp</span><br><span>@@ -20,6 +20,7 @@</span><br><span> */</span><br><span> </span><br><span> #include <new></span><br><span style="color: hsl(120, 100%, 40%);">+#include <sstream></span><br><span> </span><br><span> #include <bts.h></span><br><span> #include <tbf.h></span><br><span>@@ -647,8 +648,13 @@</span><br><span> LOGPTBF(tbf, LOGL_NOTICE, "%s timeout expired, freeing TBF\n",</span><br><span> get_value_string(tbf_timers_names, t));</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- if (run_diag)</span><br><span style="color: hsl(0, 100%, 40%);">- tbf->rlcmac_diag();</span><br><span style="color: hsl(120, 100%, 40%);">+ if (run_diag) {</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGPTBF(tbf, LOGL_NOTICE, "%s timeout expired, freeing TBF: %s\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ get_value_string(tbf_timers_names, t), tbf->rlcmac_diag().c_str());</span><br><span style="color: hsl(120, 100%, 40%);">+ } else {</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGPTBF(tbf, LOGL_NOTICE, "%s timeout expired, freeing TBF\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ get_value_string(tbf_timers_names, t));</span><br><span style="color: hsl(120, 100%, 40%);">+ }</span><br><span> </span><br><span> tbf_free(tbf);</span><br><span> }</span><br><span>@@ -816,8 +822,9 @@</span><br><span> </span><br><span> if (ul_tbf && ul_tbf->handle_ctrl_ack()) {</span><br><span> if (!ul_tbf->ctrl_ack_to_toggle()) {</span><br><span style="color: hsl(0, 100%, 40%);">- LOGPTBF(this, LOGL_NOTICE, "Timeout for polling PACKET CONTROL ACK for PACKET UPLINK ACK\n");</span><br><span style="color: hsl(0, 100%, 40%);">- rlcmac_diag();</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGPTBF(this, LOGL_NOTICE,</span><br><span style="color: hsl(120, 100%, 40%);">+ "Timeout for polling PACKET CONTROL ACK for PACKET UPLINK ACK: %s\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ rlcmac_diag().c_str());</span><br><span> }</span><br><span> bts->do_rate_ctr_inc(CTR_RLC_ACK_TIMEDOUT);</span><br><span> bts->do_rate_ctr_inc(CTR_PUAN_POLL_TIMEDOUT);</span><br><span>@@ -835,8 +842,8 @@</span><br><span> } else if (ul_ass_state == GPRS_RLCMAC_UL_ASS_WAIT_ACK) {</span><br><span> if (!(state_flags & (1 << GPRS_RLCMAC_FLAG_TO_UL_ASS))) {</span><br><span> LOGPTBF(this, LOGL_NOTICE,</span><br><span style="color: hsl(0, 100%, 40%);">- "Timeout for polling PACKET CONTROL ACK for PACKET UPLINK ASSIGNMENT.\n");</span><br><span style="color: hsl(0, 100%, 40%);">- rlcmac_diag();</span><br><span style="color: hsl(120, 100%, 40%);">+ "Timeout for polling PACKET CONTROL ACK for PACKET UPLINK ASSIGNMENT: %s\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ rlcmac_diag().c_str());</span><br><span> state_flags |= (1 << GPRS_RLCMAC_FLAG_TO_UL_ASS);</span><br><span> }</span><br><span> ul_ass_state = GPRS_RLCMAC_UL_ASS_NONE;</span><br><span>@@ -854,8 +861,8 @@</span><br><span> } else if (dl_ass_state == GPRS_RLCMAC_DL_ASS_WAIT_ACK) {</span><br><span> if (!(state_flags & (1 << GPRS_RLCMAC_FLAG_TO_DL_ASS))) {</span><br><span> LOGPTBF(this, LOGL_NOTICE,</span><br><span style="color: hsl(0, 100%, 40%);">- "Timeout for polling PACKET CONTROL ACK for PACKET DOWNLINK ASSIGNMENT.\n");</span><br><span style="color: hsl(0, 100%, 40%);">- rlcmac_diag();</span><br><span style="color: hsl(120, 100%, 40%);">+ "Timeout for polling PACKET CONTROL ACK for PACKET DOWNLINK ASSIGNMENT: %s\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ rlcmac_diag().c_str());</span><br><span> state_flags |= (1 << GPRS_RLCMAC_FLAG_TO_DL_ASS);</span><br><span> }</span><br><span> dl_ass_state = GPRS_RLCMAC_DL_ASS_NONE;</span><br><span>@@ -875,8 +882,8 @@</span><br><span> </span><br><span> if (!(dl_tbf->state_flags & (1 << GPRS_RLCMAC_FLAG_TO_DL_ACK))) {</span><br><span> LOGPTBF(this, LOGL_NOTICE,</span><br><span style="color: hsl(0, 100%, 40%);">- "Timeout for polling PACKET DOWNLINK ACK.\n");</span><br><span style="color: hsl(0, 100%, 40%);">- dl_tbf->rlcmac_diag();</span><br><span style="color: hsl(120, 100%, 40%);">+ "Timeout for polling PACKET DOWNLINK ACK: %s\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ dl_tbf->rlcmac_diag().c_str());</span><br><span> dl_tbf->state_flags |= (1 << GPRS_RLCMAC_FLAG_TO_DL_ACK);</span><br><span> }</span><br><span> </span><br><span>@@ -1169,22 +1176,24 @@</span><br><span> }</span><br><span> }</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">-int gprs_rlcmac_tbf::rlcmac_diag()</span><br><span style="color: hsl(120, 100%, 40%);">+std::string gprs_rlcmac_tbf::rlcmac_diag()</span><br><span> {</span><br><span style="color: hsl(120, 100%, 40%);">+ std::ostringstream os;</span><br><span style="color: hsl(120, 100%, 40%);">+ os << "|";</span><br><span> if ((state_flags & (1 << GPRS_RLCMAC_FLAG_CCCH)))</span><br><span style="color: hsl(0, 100%, 40%);">- LOGPTBF(this, LOGL_NOTICE, "Assignment was on CCCH\n");</span><br><span style="color: hsl(120, 100%, 40%);">+ os << "Assignment was on CCCH|";</span><br><span> if ((state_flags & (1 << GPRS_RLCMAC_FLAG_PACCH)))</span><br><span style="color: hsl(0, 100%, 40%);">- LOGPTBF(this, LOGL_NOTICE, "Assignment was on PACCH\n");</span><br><span style="color: hsl(120, 100%, 40%);">+ os << "Assignment was on PACCH|";</span><br><span> if ((state_flags & (1 << GPRS_RLCMAC_FLAG_UL_DATA)))</span><br><span style="color: hsl(0, 100%, 40%);">- LOGPTBF(this, LOGL_NOTICE, "Uplink data was received\n");</span><br><span style="color: hsl(120, 100%, 40%);">+ os << "Uplink data was received|";</span><br><span> else if (direction == GPRS_RLCMAC_UL_TBF)</span><br><span style="color: hsl(0, 100%, 40%);">- LOGPTBF(this, LOGL_NOTICE, "No uplink data received yet\n");</span><br><span style="color: hsl(120, 100%, 40%);">+ os << "No uplink data received yet|";</span><br><span> if ((state_flags & (1 << GPRS_RLCMAC_FLAG_DL_ACK)))</span><br><span style="color: hsl(0, 100%, 40%);">- LOGPTBF(this, LOGL_NOTICE, "Downlink ACK was received\n");</span><br><span style="color: hsl(120, 100%, 40%);">+ os << "Downlink ACK was received|";</span><br><span> else if (direction == GPRS_RLCMAC_DL_TBF)</span><br><span style="color: hsl(0, 100%, 40%);">- LOGPTBF(this, LOGL_NOTICE, "No downlink ACK received yet\n");</span><br><span style="color: hsl(120, 100%, 40%);">+ os << "No downlink ACK received yet|";</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- return 0;</span><br><span style="color: hsl(120, 100%, 40%);">+ return os.str();</span><br><span> }</span><br><span> </span><br><span> struct msgb *gprs_rlcmac_tbf::create_dl_ass(uint32_t fn, uint8_t ts)</span><br><span>diff --git a/src/tbf.h b/src/tbf.h</span><br><span>index 528bee3..99aba67 100644</span><br><span>--- a/src/tbf.h</span><br><span>+++ b/src/tbf.h</span><br><span>@@ -20,6 +20,8 @@</span><br><span> </span><br><span> #ifdef __cplusplus</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+#include <string></span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> #include "llc.h"</span><br><span> #include "rlc.h"</span><br><span> #include "cxx_linuxlist.h"</span><br><span>@@ -212,7 +214,7 @@</span><br><span> </span><br><span> uint8_t tsc() const;</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- int rlcmac_diag();</span><br><span style="color: hsl(120, 100%, 40%);">+ std::string rlcmac_diag();</span><br><span> </span><br><span> bool n_inc(enum tbf_counters n);</span><br><span> void n_reset(enum tbf_counters n);</span><br><span>diff --git a/tests/tbf/TbfTest.err b/tests/tbf/TbfTest.err</span><br><span>index 681e7a3..ce23802 100644</span><br><span>--- a/tests/tbf/TbfTest.err</span><br><span>+++ b/tests/tbf/TbfTest.err</span><br><span>@@ -1725,9 +1725,7 @@</span><br><span> Searching for first unallocated TFI: TRX=0</span><br><span> Found TFI=1.</span><br><span> TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=FINISHED) poll timeout for FN=2654292, TS=7 (curr FN 2654335)</span><br><span style="color: hsl(0, 100%, 40%);">-TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=FINISHED) Timeout for polling PACKET DOWNLINK ACK.</span><br><span style="color: hsl(0, 100%, 40%);">-TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=FINISHED) Assignment was on PACCH</span><br><span style="color: hsl(0, 100%, 40%);">-TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=FINISHED) No downlink ACK received yet</span><br><span style="color: hsl(120, 100%, 40%);">+TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=FINISHED) Timeout for polling PACKET DOWNLINK ACK: |Assignment was on PACCH|No downlink ACK received yet|</span><br><span> +++++++++++++++++++++++++ RX : Uplink Control Block +++++++++++++++++++++++++</span><br><span> ------------------------- RX : Uplink Control Block -------------------------</span><br><span> Creating MS object, TLLI = 0x00000000</span><br><span></span><br></pre><p>To view, visit <a href="https://gerrit.osmocom.org/c/osmo-pcu/+/20243">change 20243</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-pcu/+/20243"/><meta itemprop="name" content="View Change"/></div></div>
<div style="display:none"> Gerrit-Project: osmo-pcu </div>
<div style="display:none"> Gerrit-Branch: master </div>
<div style="display:none"> Gerrit-Change-Id: I6a7d79c16c930f0712bc73b308409ececb1946ba </div>
<div style="display:none"> Gerrit-Change-Number: 20243 </div>
<div style="display:none"> Gerrit-PatchSet: 1 </div>
<div style="display:none"> Gerrit-Owner: pespin <pespin@sysmocom.de> </div>
<div style="display:none"> Gerrit-MessageType: newchange </div>