<p>fixeria <strong>submitted</strong> this change.</p><p><a href="https://gerrit.osmocom.org/c/osmo-bsc/+/20148">View Change</a></p><div style="white-space:pre-wrap">Approvals:
Jenkins Builder: Verified
laforge: Looks good to me, but someone else must approve
pespin: Looks good to me, approved
</div><pre style="font-family: monospace,monospace; white-space: pre-wrap;">abis_nm: enrich debug messages with contextual info<br><br>Change-Id: I68f64e6cae061a49733c4885ba383d2b9b4cfca9<br>---<br>M src/osmo-bsc/abis_nm.c<br>1 file changed, 44 insertions(+), 41 deletions(-)<br><br></pre><pre style="font-family: monospace,monospace; white-space: pre-wrap;"><span>diff --git a/src/osmo-bsc/abis_nm.c b/src/osmo-bsc/abis_nm.c</span><br><span>index 9db49b7..b377c4a 100644</span><br><span>--- a/src/osmo-bsc/abis_nm.c</span><br><span>+++ b/src/osmo-bsc/abis_nm.c</span><br><span>@@ -56,6 +56,12 @@</span><br><span> #define OM_HEADROOM_SIZE 128</span><br><span> #define IPACC_SEGMENT_SIZE 245</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+#define LOGPMO(mo, ss, lvl, fmt, args ...) \</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGP(ss, lvl, "OC=%s(%02x) INST=(%02x,%02x,%02x): " fmt, \</span><br><span style="color: hsl(120, 100%, 40%);">+ get_value_string(abis_nm_obj_class_names, (mo)->obj_class), \</span><br><span style="color: hsl(120, 100%, 40%);">+ (mo)->obj_class, (mo)->obj_inst.bts_nr, (mo)->obj_inst.trx_nr, \</span><br><span style="color: hsl(120, 100%, 40%);">+ (mo)->obj_inst.ts_nr, ## args)</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> int abis_nm_tlv_parse(struct tlv_parsed *tp, struct gsm_bts *bts, const uint8_t *buf, int len)</span><br><span> {</span><br><span> if (!bts->model)</span><br><span>@@ -313,7 +319,7 @@</span><br><span> enum abis_nm_pcause_type pcause = p_val[0];</span><br><span> enum abis_mm_event_causes cause = osmo_load16be(p_val + 1);</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- LOGP(DNM, LOGL_ERROR, "BTS %u: Failure Event Report: ", bts->nr);</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGPMO(&bts->mo, DNM, LOGL_ERROR, "Failure Event Report: ");</span><br><span> if (type)</span><br><span> LOGPC(DNM, LOGL_ERROR, "Type=%s, ", type);</span><br><span> if (severity)</span><br><span>@@ -343,10 +349,10 @@</span><br><span> switch (cause) {</span><br><span> case OSMO_EVT_PCU_VERS:</span><br><span> if (text) {</span><br><span style="color: hsl(0, 100%, 40%);">- LOGP(DNM, LOGL_NOTICE, "BTS %u reported connected PCU version %s\n", bts->nr, text);</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGPMO(&bts->mo, DNM, LOGL_NOTICE, "Reported connected PCU version %s\n", text);</span><br><span> osmo_strlcpy(bts->pcu_version, text, sizeof(bts->pcu_version));</span><br><span> } else {</span><br><span style="color: hsl(0, 100%, 40%);">- LOGP(DNM, LOGL_ERROR, "BTS %u reported PCU disconnection.\n", bts->nr);</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGPMO(&bts->mo, DNM, LOGL_ERROR, "Reported PCU disconnection.\n");</span><br><span> bts->pcu_version[0] = '\0';</span><br><span> }</span><br><span> break;</span><br><span>@@ -523,10 +529,10 @@</span><br><span> {</span><br><span> switch (id) {</span><br><span> case BTS_TYPE_VARIANT:</span><br><span style="color: hsl(0, 100%, 40%);">- LOGP(DNM, LOGL_NOTICE, "BTS%u reported variant: %s\n", bts->nr, val);</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGPMO(&bts->mo, DNM, LOGL_NOTICE, "Reported variant: %s\n", val);</span><br><span> break;</span><br><span> case BTS_SUB_MODEL:</span><br><span style="color: hsl(0, 100%, 40%);">- LOGP(DNM, LOGL_NOTICE, "BTS%u reported submodel: %s\n", bts->nr, val);</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGPMO(&bts->mo, DNM, LOGL_NOTICE, "Reported submodel: %s\n", val);</span><br><span> break;</span><br><span> default:</span><br><span> return false;</span><br><span>@@ -574,27 +580,25 @@</span><br><span> </span><br><span> /* log potential BTS feature vector overflow */</span><br><span> if (len > sizeof(bts->_features_data)) {</span><br><span style="color: hsl(0, 100%, 40%);">- LOGP(DNM, LOGL_NOTICE, "BTS%u Get Attributes Response: feature vector is truncated "</span><br><span style="color: hsl(0, 100%, 40%);">- "(from %u to %zu bytes)\n", bts->nr, len, sizeof(bts->_features_data));</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGPMO(&bts->mo, DNM, LOGL_NOTICE, "Get Attributes Response: feature vector is truncated "</span><br><span style="color: hsl(120, 100%, 40%);">+ "(from %u to %zu bytes)\n", len, sizeof(bts->_features_data));</span><br><span> len = sizeof(bts->_features_data);</span><br><span> }</span><br><span> </span><br><span> /* check that max. expected BTS attribute is above given feature vector length */</span><br><span> if (len > OSMO_BYTES_FOR_BITS(_NUM_BTS_FEAT)) {</span><br><span style="color: hsl(0, 100%, 40%);">- LOGP(DNM, LOGL_NOTICE, "BTS%u Get Attributes Response: reported unexpectedly long (%u bytes) "</span><br><span style="color: hsl(0, 100%, 40%);">- "feature vector - most likely it was compiled against newer BSC headers. "</span><br><span style="color: hsl(0, 100%, 40%);">- "Consider upgrading your BSC to later version.\n",</span><br><span style="color: hsl(0, 100%, 40%);">- bts->nr, len);</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGPMO(&bts->mo, DNM, LOGL_NOTICE, "Get Attributes Response: reported unexpectedly long (%u bytes) "</span><br><span style="color: hsl(120, 100%, 40%);">+ "feature vector - most likely it was compiled against newer BSC headers. "</span><br><span style="color: hsl(120, 100%, 40%);">+ "Consider upgrading your BSC to later version.\n", len);</span><br><span> }</span><br><span> </span><br><span> memcpy(bts->_features_data, TLVP_VAL(tp, NM_ATT_MANUF_ID), len);</span><br><span> </span><br><span> for (i = 0; i < _NUM_BTS_FEAT; i++) {</span><br><span> if (osmo_bts_has_feature(&bts->features, i) != osmo_bts_has_feature(&bts->model->features, i)) {</span><br><span style="color: hsl(0, 100%, 40%);">- LOGP(DNM, LOGL_NOTICE, "BTS%u feature '%s' reported via OML does not match statically "</span><br><span style="color: hsl(0, 100%, 40%);">- "set feature: %u != %u. Please fix.\n", bts->nr,</span><br><span style="color: hsl(0, 100%, 40%);">- get_value_string(osmo_bts_features_descs, i),</span><br><span style="color: hsl(0, 100%, 40%);">- osmo_bts_has_feature(&bts->features, i), osmo_bts_has_feature(&bts->model->features, i));</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGPMO(&bts->mo, DNM, LOGL_NOTICE, "Feature '%s' reported via OML does not match statically "</span><br><span style="color: hsl(120, 100%, 40%);">+ "set feature: %u != %u. Please fix.\n", get_value_string(osmo_bts_features_descs, i),</span><br><span style="color: hsl(120, 100%, 40%);">+ osmo_bts_has_feature(&bts->features, i), osmo_bts_has_feature(&bts->model->features, i));</span><br><span> }</span><br><span> }</span><br><span> }</span><br><span>@@ -1028,17 +1032,17 @@</span><br><span> {</span><br><span> int rc;</span><br><span> struct e1inp_sign_link *sign_link = mb->dst;</span><br><span style="color: hsl(0, 100%, 40%);">- int bts_type = sign_link->trx->bts->type;</span><br><span style="color: hsl(120, 100%, 40%);">+ struct gsm_bts *bts = sign_link->trx->bts;</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- switch (bts_type) {</span><br><span style="color: hsl(120, 100%, 40%);">+ switch (bts->type) {</span><br><span> case GSM_BTS_TYPE_NANOBTS:</span><br><span> case GSM_BTS_TYPE_OSMOBTS:</span><br><span> rc = abis_nm_rx_ipacc(mb);</span><br><span style="color: hsl(0, 100%, 40%);">- abis_nm_queue_send_next(sign_link->trx->bts);</span><br><span style="color: hsl(120, 100%, 40%);">+ abis_nm_queue_send_next(bts);</span><br><span> break;</span><br><span> default:</span><br><span style="color: hsl(0, 100%, 40%);">- LOGP(DNM, LOGL_ERROR, "don't know how to parse OML for this "</span><br><span style="color: hsl(0, 100%, 40%);">- "BTS type (%s)\n", btstype2str(bts_type));</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGPMO(&bts->mo, DNM, LOGL_ERROR, "don't know how to parse OML for this "</span><br><span style="color: hsl(120, 100%, 40%);">+ "BTS type (%s)\n", btstype2str(bts->type));</span><br><span> rc = 0;</span><br><span> break;</span><br><span> }</span><br><span>@@ -1183,7 +1187,7 @@</span><br><span> msgb_tlv_put(msg, NM_ATT_FILE_VERSION, sw->file_version_len,</span><br><span> sw->file_version);</span><br><span> } else {</span><br><span style="color: hsl(0, 100%, 40%);">- LOGP(DNM, LOGL_ERROR, "Please implement this for the BTS.\n");</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGPMO(&sw->bts->mo, DNM, LOGL_ERROR, "Please implement this for the BTS.\n");</span><br><span> }</span><br><span> }</span><br><span> </span><br><span>@@ -1281,7 +1285,7 @@</span><br><span> break;</span><br><span> }</span><br><span> default:</span><br><span style="color: hsl(0, 100%, 40%);">- LOGP(DNM, LOGL_ERROR, "sw_load_segment needs implementation for the BTS.\n");</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGPMO(&sw->bts->mo, DNM, LOGL_ERROR, "sw_load_segment needs implementation for the BTS.\n");</span><br><span> /* FIXME: Other BTS types */</span><br><span> return -1;</span><br><span> }</span><br><span>@@ -1338,18 +1342,19 @@</span><br><span> </span><br><span> static int parse_sdp_header(struct abis_nm_sw *sw)</span><br><span> {</span><br><span style="color: hsl(120, 100%, 40%);">+ const struct gsm_abis_mo *mo = &sw->bts->mo;</span><br><span> struct sdp_firmware firmware_header;</span><br><span> int rc;</span><br><span> struct stat stat;</span><br><span> </span><br><span> rc = read(sw->fd, &firmware_header, sizeof(firmware_header));</span><br><span> if (rc != sizeof(firmware_header)) {</span><br><span style="color: hsl(0, 100%, 40%);">- LOGP(DNM, LOGL_ERROR, "Could not read SDP file header.\n");</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGPMO(mo, DNM, LOGL_ERROR, "Could not read SDP file header.\n");</span><br><span> return -1;</span><br><span> }</span><br><span> </span><br><span> if (strncmp(firmware_header.magic, " SDP", 4) != 0) {</span><br><span style="color: hsl(0, 100%, 40%);">- LOGP(DNM, LOGL_ERROR, "The magic number1 is wrong.\n");</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGPMO(mo, DNM, LOGL_ERROR, "The magic number1 is wrong.\n");</span><br><span> return -1;</span><br><span> }</span><br><span> </span><br><span>@@ -1357,28 +1362,27 @@</span><br><span> firmware_header.more_magic[1] != 0x02 ||</span><br><span> firmware_header.more_magic[2] != 0x00 ||</span><br><span> firmware_header.more_magic[3] != 0x00) {</span><br><span style="color: hsl(0, 100%, 40%);">- LOGP(DNM, LOGL_ERROR, "The more magic number is wrong.\n");</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGPMO(mo, DNM, LOGL_ERROR, "The more magic number is wrong.\n");</span><br><span> return -1;</span><br><span> }</span><br><span> </span><br><span> </span><br><span> if (fstat(sw->fd, &stat) == -1) {</span><br><span style="color: hsl(0, 100%, 40%);">- LOGP(DNM, LOGL_ERROR, "Could not stat the file.\n");</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGPMO(mo, DNM, LOGL_ERROR, "Could not stat the file.\n");</span><br><span> return -1;</span><br><span> }</span><br><span> </span><br><span> if (ntohl(firmware_header.file_length) != stat.st_size) {</span><br><span style="color: hsl(0, 100%, 40%);">- LOGP(DNM, LOGL_ERROR, "The filesizes do not match.\n");</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGPMO(mo, DNM, LOGL_ERROR, "The filesizes do not match.\n");</span><br><span> return -1;</span><br><span> }</span><br><span> </span><br><span> /* go back to the start as we checked the whole filesize.. */</span><br><span> lseek(sw->fd, 0l, SEEK_SET);</span><br><span style="color: hsl(0, 100%, 40%);">- LOGP(DNM, LOGL_NOTICE, "The ipaccess SDP header is not fully understood."</span><br><span style="color: hsl(0, 100%, 40%);">- " There might be checksums in the file that are not"</span><br><span style="color: hsl(0, 100%, 40%);">- " verified and incomplete firmware might be flashed."</span><br><span style="color: hsl(0, 100%, 40%);">- " There is absolutely no WARRANTY that flashing will"</span><br><span style="color: hsl(0, 100%, 40%);">- " work.\n");</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGPMO(mo, DNM, LOGL_NOTICE, "The ipaccess SDP header is not fully understood. "</span><br><span style="color: hsl(120, 100%, 40%);">+ "There might be checksums in the file that are not verified and incomplete "</span><br><span style="color: hsl(120, 100%, 40%);">+ "firmware might be flashed. There is absolutely no WARRANTY that "</span><br><span style="color: hsl(120, 100%, 40%);">+ "flashing will work.\n");</span><br><span> return 0;</span><br><span> }</span><br><span> </span><br><span>@@ -1620,7 +1624,7 @@</span><br><span> struct abis_nm_sw *sw = &g_sw;</span><br><span> int rc;</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- DEBUGP(DNM, "Software Load (BTS %u, File \"%s\")\n", bts->nr, fname);</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGPMO(&bts->mo, DNM, LOGL_DEBUG, "Software Load (file \"%s\")\n", fname);</span><br><span> </span><br><span> if (sw->state != SW_STATE_NONE)</span><br><span> return -EBUSY;</span><br><span>@@ -1643,7 +1647,7 @@</span><br><span> break;</span><br><span> case GSM_BTS_TYPE_UNKNOWN:</span><br><span> default:</span><br><span style="color: hsl(0, 100%, 40%);">- LOGP(DNM, LOGL_ERROR, "Software Load not properly implemented.\n");</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGPMO(&bts->mo, DNM, LOGL_ERROR, "Software Load not properly implemented.\n");</span><br><span> return -1;</span><br><span> break;</span><br><span> }</span><br><span>@@ -1688,7 +1692,7 @@</span><br><span> struct abis_nm_sw *sw = &g_sw;</span><br><span> int rc;</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- DEBUGP(DNM, "Activating Software (BTS %u, File \"%s\")\n", bts->nr, fname);</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGPMO(&bts->mo, DNM, LOGL_DEBUG, "Activating Software (file \"%s\")\n", fname);</span><br><span> </span><br><span> if (sw->state != SW_STATE_NONE)</span><br><span> return -EBUSY;</span><br><span>@@ -1785,9 +1789,8 @@</span><br><span> ch = (struct abis_nm_channel *) msgb_put(msg, sizeof(*ch));</span><br><span> fill_nm_channel(ch, e1_port, e1_timeslot, e1_subslot);</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- DEBUGP(DNM, "CONNECT TERR TRAF Um=%s E1=(%u,%u,%u)\n",</span><br><span style="color: hsl(0, 100%, 40%);">- gsm_ts_name(ts),</span><br><span style="color: hsl(0, 100%, 40%);">- e1_port, e1_timeslot, e1_subslot);</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGPMO(&ts->mo, DNM, LOGL_DEBUG, "CONNECT TERR TRAF E1=(%u,%u,%u)\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ e1_port, e1_timeslot, e1_subslot);</span><br><span> </span><br><span> return abis_nm_sendmsg(bts, msg);</span><br><span> }</span><br><span>@@ -1809,8 +1812,8 @@</span><br><span> struct msgb *msg;</span><br><span> </span><br><span> if (bts->type != GSM_BTS_TYPE_OSMOBTS && bts->type != GSM_BTS_TYPE_NANOBTS) {</span><br><span style="color: hsl(0, 100%, 40%);">- LOGP(DNM, LOGL_NOTICE, "Getting attributes from BTS%d type %s is not supported.\n",</span><br><span style="color: hsl(0, 100%, 40%);">- bts->nr, btstype2str(bts->type));</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGPMO(&bts->mo, DNM, LOGL_NOTICE, "Getting attributes from BTS "</span><br><span style="color: hsl(120, 100%, 40%);">+ "type %s is not supported.\n", btstype2str(bts->type));</span><br><span> return -EINVAL;</span><br><span> }</span><br><span> </span><br><span>@@ -1832,7 +1835,7 @@</span><br><span> struct msgb *msg = nm_msgb_alloc();</span><br><span> uint8_t *cur;</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- LOG_BTS(bts, DNM, LOGL_DEBUG, "Set BTS Attr\n");</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGPMO(&bts->mo, DNM, LOGL_DEBUG, "Set BTS Attr\n");</span><br><span> </span><br><span> oh = (struct abis_om_hdr *) msgb_put(msg, ABIS_OM_FOM_HDR_SIZE);</span><br><span> fill_om_fom_hdr(oh, attr_len, NM_MT_SET_BTS_ATTR, NM_OC_BTS, bts->bts_nr, 0xff, 0xff);</span><br><span></span><br></pre><p>To view, visit <a href="https://gerrit.osmocom.org/c/osmo-bsc/+/20148">change 20148</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-bsc/+/20148"/><meta itemprop="name" content="View Change"/></div></div>
<div style="display:none"> Gerrit-Project: osmo-bsc </div>
<div style="display:none"> Gerrit-Branch: master </div>
<div style="display:none"> Gerrit-Change-Id: I68f64e6cae061a49733c4885ba383d2b9b4cfca9 </div>
<div style="display:none"> Gerrit-Change-Number: 20148 </div>
<div style="display:none"> Gerrit-PatchSet: 2 </div>
<div style="display:none"> Gerrit-Owner: fixeria <vyanitskiy@sysmocom.de> </div>
<div style="display:none"> Gerrit-Reviewer: Jenkins Builder </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>