bts_nokia_site: Clean up logging

We don't want to fprintf directly, and we want to make sure to always
log as much context as possible.

Change-Id: I29ec935669175a08cb42e1666559b681c50a6e72
This commit is contained in:
Harald Welte 2020-07-04 11:55:24 +02:00
parent c66fd3d928
commit 56c7ecda0e
1 changed files with 37 additions and 53 deletions

View File

@ -59,7 +59,7 @@ static int dump_elements(uint8_t * data, int len) __attribute__((unused));
static void bootstrap_om_bts(struct gsm_bts *bts) static void bootstrap_om_bts(struct gsm_bts *bts)
{ {
LOGP(DNM, LOGL_NOTICE, "bootstrapping OML for BTS %u\n", bts->nr); LOG_BTS(bts, DNM, LOGL_NOTICE, "bootstrapping OML\n");
if (!bts->nokia.skip_reset) { if (!bts->nokia.skip_reset) {
if (!bts->nokia.did_reset) if (!bts->nokia.did_reset)
@ -72,8 +72,7 @@ static void bootstrap_om_bts(struct gsm_bts *bts)
static void bootstrap_om_trx(struct gsm_bts_trx *trx) static void bootstrap_om_trx(struct gsm_bts_trx *trx)
{ {
LOGP(DNM, LOGL_NOTICE, "bootstrapping OML for TRX %u/%u\n", LOG_TRX(trx, DNM, LOGL_NOTICE, "bootstrapping OML\n");
trx->bts->nr, trx->nr);
gsm_trx_all_ts_dispatch(trx, TS_EV_OML_READY, NULL); gsm_trx_all_ts_dispatch(trx, TS_EV_OML_READY, NULL);
} }
@ -762,7 +761,7 @@ static int make_fu_config(struct gsm_bts_trx *trx, uint8_t id,
/* set CA */ /* set CA */
if (generate_cell_chan_list(&fu_config[38], trx->bts) != 0) { if (generate_cell_chan_list(&fu_config[38], trx->bts) != 0) {
fprintf(stderr, "generate_cell_chan_list failed\n"); LOG_TRX(trx, DNM, LOGL_ERROR, "generate_cell_chan_list failed\n");
return 0; return 0;
} }
@ -810,8 +809,7 @@ static int make_fu_config(struct gsm_bts_trx *trx, uint8_t id,
chan_config = 11; chan_config = 11;
break; break;
default: default:
fprintf(stderr, LOG_TRX(trx, DNM, LOGL_ERROR, "unsupported channel config %s for timeslot %d\n",
"unsupported channel config %s for timeslot %d\n",
gsm_pchan_name(ts->pchan_from_config), i); gsm_pchan_name(ts->pchan_from_config), i);
return 0; return 0;
} }
@ -1000,17 +998,17 @@ void set_real_time(uint8_t * real_time)
build the configuration data build the configuration data
*/ */
static int make_bts_config(uint8_t bts_type, int n_trx, uint8_t * fu_config, static int make_bts_config(struct gsm_bts *bts, uint8_t bts_type, int n_trx, uint8_t * fu_config,
int need_hopping) int need_hopping)
{ {
/* is it an InSite BTS ? */ /* is it an InSite BTS ? */
if (bts_type == 0x0E || bts_type == 0x0F || bts_type == 0x10) { /* TODO */ if (bts_type == 0x0E || bts_type == 0x0F || bts_type == 0x10) { /* TODO */
if (n_trx != 1) { if (n_trx != 1) {
fprintf(stderr, "InSite has only one TRX\n"); LOG_BTS(bts, DNM, LOGL_ERROR, "InSite has only one TRX\n");
return 0; return 0;
} }
if (need_hopping != 0) { if (need_hopping != 0) {
fprintf(stderr, "InSite does not support hopping\n"); LOG_BTS(bts, DNM, LOGL_ERROR, "InSite does not support hopping\n");
return 0; return 0;
} }
memcpy(fu_config, bts_config_insite, sizeof(bts_config_insite)); memcpy(fu_config, bts_config_insite, sizeof(bts_config_insite));
@ -1090,7 +1088,7 @@ static int abis_nm_send(struct gsm_bts *bts, uint8_t msg_type, uint16_t ref,
noh->reference = htons(ref); noh->reference = htons(ref);
memcpy(noh->data, data, len_data); memcpy(noh->data, data, len_data);
DEBUGPC(DNM, "Sending %s\n", get_msg_type_name_string(msg_type)); LOG_BTS(bts, DNM, LOGL_DEBUG, "Sending %s\n", get_msg_type_name_string(msg_type));
return abis_nm_sendmsg(bts, msg); return abis_nm_sendmsg(bts, msg);
} }
@ -1165,7 +1163,7 @@ static int abis_nm_reset(struct gsm_bts *bts, uint16_t ref)
{ {
uint8_t *data = reset; uint8_t *data = reset;
int len_data = sizeof(reset); int len_data = sizeof(reset);
LOGP(DLINP, LOGL_INFO, "Nokia BTS reset timer: %d\n", bts->nokia.bts_reset_timer_cnf); LOG_BTS(bts, DLINP, LOGL_INFO, "Nokia BTS reset timer: %d\n", bts->nokia.bts_reset_timer_cnf);
return abis_nm_send(bts, NOKIA_MSG_RESET_REQ, ref, data, len_data); return abis_nm_send(bts, NOKIA_MSG_RESET_REQ, ref, data, len_data);
} }
@ -1252,7 +1250,7 @@ static int abis_nm_send_multi_segments(struct gsm_bts *bts, uint8_t msg_type,
memcpy(oh->data, data, len_to_send); memcpy(oh->data, data, len_to_send);
} }
DEBUGPC(DNM, "Sending multi-segment %d\n", seq); LOG_BTS(bts, DNM, LOGL_DEBUG, "Sending multi-segment %d\n", seq);
ret = abis_nm_sendmsg(bts, msg); ret = abis_nm_sendmsg(bts, msg);
if (ret < 0) if (ret < 0)
@ -1306,7 +1304,7 @@ static int abis_nm_send_config(struct gsm_bts *bts, uint8_t bts_type)
idx++; idx++;
} }
ret = make_bts_config(bts_type, idx, config + len, need_hopping); ret = make_bts_config(bts, bts_type, idx, config + len, need_hopping);
len += ret; len += ret;
#if 0 /* debugging */ #if 0 /* debugging */
@ -1502,8 +1500,8 @@ static void reset_timer_cb(void *_bts)
/* OML link */ /* OML link */
line = e1inp_line_find(e1_link->e1_nr); line = e1inp_line_find(e1_link->e1_nr);
if (!line) { if (!line) {
LOGP(DLINP, LOGL_ERROR, "BTS %u OML link referring to non-existing E1 line %u\n", LOG_BTS(bts, DLINP, LOGL_ERROR, "BTS OML link referring to non-existing E1 line %u\n",
bts->nr, e1_link->e1_nr); e1_link->e1_nr);
return; return;
} }
@ -1555,18 +1553,17 @@ static int abis_nm_rcvmsg_fom(struct msgb *mb)
int len_data; int len_data;
if (bts->nokia.wait_reset) { if (bts->nokia.wait_reset) {
LOGP(DNM, LOGL_INFO, LOG_BTS(bts, DNM, LOGL_INFO, "Ignoring message while waiting for reset: %s\n", msgb_hexdump(mb));
"Ignore message while waiting for reset\n");
return ret; return ret;
} }
if (oh->length < sizeof(struct abis_om_nokia_hdr)) { if (oh->length < sizeof(struct abis_om_nokia_hdr)) {
LOGP(DNM, LOGL_ERROR, "Message too short\n"); LOG_BTS(bts, DNM, LOGL_ERROR, "Message too short: %s\n", msgb_hexdump(mb));
return -EINVAL; return -EINVAL;
} }
len_data = oh->length - sizeof(struct abis_om_nokia_hdr); len_data = oh->length - sizeof(struct abis_om_nokia_hdr);
LOGP(DNM, LOGL_INFO, "(0x%02X) %s\n", mt, get_msg_type_name_string(mt)); LOG_BTS(bts, DNM, LOGL_INFO, "Rx (0x%02X) %s\n", mt, get_msg_type_name_string(mt));
#if 0 /* debugging */ #if 0 /* debugging */
dump_elements(noh->data, len_data); dump_elements(noh->data, len_data);
#endif #endif
@ -1576,11 +1573,10 @@ static int abis_nm_rcvmsg_fom(struct msgb *mb)
if (find_element(noh->data, len_data, if (find_element(noh->data, len_data,
NOKIA_EI_BTS_TYPE, &bts->nokia.bts_type, NOKIA_EI_BTS_TYPE, &bts->nokia.bts_type,
sizeof(uint8_t)) == sizeof(uint8_t)) sizeof(uint8_t)) == sizeof(uint8_t))
LOGP(DNM, LOGL_INFO, "BTS type = %d (%s)\n", LOG_BTS(bts, DNM, LOGL_INFO, "Rx BTS type = %d (%s)\n", bts->nokia.bts_type,
bts->nokia.bts_type, get_bts_type_string(bts->nokia.bts_type));
get_bts_type_string(bts->nokia.bts_type));
else else
LOGP(DNM, LOGL_ERROR, "BTS type not found\n"); LOG_BTS(bts, DNM, LOGL_ERROR, "BTS type not found in NOKIA_MSG_OMU_STARTED\n");
/* send START_DOWNLOAD_REQ */ /* send START_DOWNLOAD_REQ */
abis_nm_download_req(bts, ref); abis_nm_download_req(bts, ref);
break; break;
@ -1598,14 +1594,13 @@ static int abis_nm_rcvmsg_fom(struct msgb *mb)
if (find_element if (find_element
(noh->data, len_data, NOKIA_EI_ACK, &ack, (noh->data, len_data, NOKIA_EI_ACK, &ack,
sizeof(uint8_t)) == sizeof(uint8_t)) { sizeof(uint8_t)) == sizeof(uint8_t)) {
LOGP(DNM, LOGL_INFO, "ACK = %d\n", ack); LOG_BTS(bts, DNM, LOGL_INFO, "Rx ACK = %u\n", ack);
if (ack != 1) { if (ack != 1) {
LOGP(DNM, LOGL_ERROR, "No ACK received (%d)\n", LOG_BTS(bts, DNM, LOGL_ERROR, "Rx No ACK (%u): don't know how to proceed\n", ack);
ack);
/* TODO: properly handle failures (NACK) */ /* TODO: properly handle failures (NACK) */
} }
} else } else
LOGP(DNM, LOGL_ERROR, "ACK not found\n"); LOG_BTS(bts, DNM, LOGL_ERROR, "Rx MSG_ACK but no EI_ACK found: %s\n", msgb_hexdump(mb));
/* TODO: the assumption for the following is that no NACK was received */ /* TODO: the assumption for the following is that no NACK was received */
@ -1647,11 +1642,8 @@ static int abis_nm_rcvmsg_fom(struct msgb *mb)
/* RSL Link */ /* RSL Link */
line = e1inp_line_find(e1_link->e1_nr); line = e1inp_line_find(e1_link->e1_nr);
if (!line) { if (!line) {
LOGP(DLINP, LOGL_ERROR, LOG_BTS(bts, DLINP, LOGL_ERROR, "RSL link referring to "
"TRX (%u/%u) RSL link referring " "non-existing E1 line %u\n", e1_link->e1_nr);
"to non-existing E1 line %u\n",
sign_link->trx->bts->nr, sign_link->trx->nr,
e1_link->e1_nr);
return -ENOMEM; return -ENOMEM;
} }
/* start TRX */ /* start TRX */
@ -1681,21 +1673,17 @@ static int abis_nm_rcvmsg_fom(struct msgb *mb)
sizeof(info)); sizeof(info));
if (str_len > 0) { if (str_len > 0) {
info[str_len] = 0; info[str_len] = 0;
LOGP(DNM, LOGL_INFO, "ALARM Severity %s (%d) : %s\n", LOG_BTS(bts, DNM, LOGL_NOTICE, "Rx ALARM Severity %s (%d) : %s\n",
get_severity_string(severity), severity, info); get_severity_string(severity), severity, info);
} else { /* nothing found, try details */ } else { /* nothing found, try details */
str_len = str_len =
find_element(noh->data, len_data, find_element(noh->data, len_data, NOKIA_EI_ALARM_DETAIL, info, sizeof(info));
NOKIA_EI_ALARM_DETAIL, info,
sizeof(info));
if (str_len > 0) { if (str_len > 0) {
uint16_t code; uint16_t code;
info[str_len] = 0; info[str_len] = 0;
code = (info[0] << 8) + info[1]; code = (info[0] << 8) + info[1];
LOGP(DNM, LOGL_INFO, LOG_BTS(bts, DNM, LOGL_NOTICE, "Rx ALARM Severity %s (%d), code 0x%X : %s\n",
"ALARM Severity %s (%d), code 0x%X : %s\n", get_severity_string(severity), severity, code, info + 2);
get_severity_string(severity), severity,
code, info + 2);
} }
} }
/* send ACK */ /* send ACK */
@ -1712,41 +1700,37 @@ static int abis_nm_rcvmsg_fom(struct msgb *mb)
int abis_nokia_rcvmsg(struct msgb *msg) int abis_nokia_rcvmsg(struct msgb *msg)
{ {
struct e1inp_sign_link *sign_link = (struct e1inp_sign_link *)msg->dst;
struct gsm_bts *bts = sign_link->trx->bts;
struct abis_om_hdr *oh = msgb_l2(msg); struct abis_om_hdr *oh = msgb_l2(msg);
int rc = 0; int rc = 0;
/* Various consistency checks */ /* Various consistency checks */
if (oh->placement != ABIS_OM_PLACEMENT_ONLY) { if (oh->placement != ABIS_OM_PLACEMENT_ONLY) {
LOGP(DNM, LOGL_ERROR, "ABIS OML placement 0x%x not supported\n", LOG_BTS(bts, DNM, LOGL_ERROR, "Rx ABIS OML placement 0x%x not supported\n", oh->placement);
oh->placement);
if (oh->placement != ABIS_OM_PLACEMENT_FIRST) if (oh->placement != ABIS_OM_PLACEMENT_FIRST)
return -EINVAL; return -EINVAL;
} }
if (oh->sequence != 0) { if (oh->sequence != 0) {
LOGP(DNM, LOGL_ERROR, "ABIS OML sequence 0x%x != 0x00\n", LOG_BTS(bts, DNM, LOGL_ERROR, "Rx ABIS OML sequence 0x%x != 0x00\n", oh->sequence);
oh->sequence);
return -EINVAL; return -EINVAL;
} }
msg->l3h = (unsigned char *)oh + sizeof(*oh); msg->l3h = (unsigned char *)oh + sizeof(*oh);
switch (oh->mdisc) { switch (oh->mdisc) {
case ABIS_OM_MDISC_FOM: case ABIS_OM_MDISC_FOM:
LOGP(DNM, LOGL_INFO, "ABIS_OM_MDISC_FOM\n"); LOG_BTS(bts, DNM, LOGL_INFO, "Rx ABIS_OM_MDISC_FOM\n");
rc = abis_nm_rcvmsg_fom(msg); rc = abis_nm_rcvmsg_fom(msg);
break; break;
case ABIS_OM_MDISC_MANUF: case ABIS_OM_MDISC_MANUF:
LOGP(DNM, LOGL_INFO, "ABIS_OM_MDISC_MANUF\n"); LOG_BTS(bts, DNM, LOGL_INFO, "Rx ABIS_OM_MDISC_MANUF: ignoring\n");
break; break;
case ABIS_OM_MDISC_MMI: case ABIS_OM_MDISC_MMI:
case ABIS_OM_MDISC_TRAU: case ABIS_OM_MDISC_TRAU:
LOGP(DNM, LOGL_ERROR, LOG_BTS(bts, DNM, LOGL_ERROR, "Rx unimplemented ABIS OML message discriminator 0x%x\n", oh->mdisc);
"unimplemented ABIS OML message discriminator 0x%x\n",
oh->mdisc);
break; break;
default: default:
LOGP(DNM, LOGL_ERROR, LOG_BTS(bts, DNM, LOGL_ERROR, "Rx unknown ABIS OML message discriminator 0x%x\n", oh->mdisc);
"unknown ABIS OML message discriminator 0x%x\n",
oh->mdisc);
return -EINVAL; return -EINVAL;
} }