laforge has submitted this change. (
https://gerrit.osmocom.org/c/libosmo-abis/+/36037?usp=email )
Change subject: input/ipaccess: Always log with context, if we have any
......................................................................
input/ipaccess: Always log with context, if we have any
Calling global LOGP/DEBUGP without giving any context (e.g. by using
LOGPIL, LOGPITS, ...) will leave the user wonder *which* line or
timeslot generated a certain log line. We should know better than that.
Change-Id: I5cd84c2d69c0db3be296cb5d9a62720f7b2c827e
---
M src/input/ipaccess.c
1 file changed, 71 insertions(+), 95 deletions(-)
Approvals:
pespin: Looks good to me, but someone else must approve
osmith: Looks good to me, but someone else must approve
Jenkins Builder: Verified
laforge: Looks good to me, approved
diff --git a/src/input/ipaccess.c b/src/input/ipaccess.c
index 7c91e70..9010f89 100644
--- a/src/input/ipaccess.c
+++ b/src/input/ipaccess.c
@@ -242,46 +242,40 @@
/* this is not an IPA control message, continue */
break;
default:
- LOGP(DLINP, LOGL_ERROR, "Unexpected return from "
- "ipa_ccm_rcvmsg_base "
- "(ret=%d)\n", ret);
+ LOGPITS(e1i_ts, DLINP, LOGL_ERROR, "Unexpected return from
ipa_ccm_rcvmsg_base (ret=%d)\n", ret);
goto err;
}
switch (msg_type) {
case IPAC_MSGT_ID_RESP:
- DEBUGP(DLMI, "ID_RESP ");
+ LOGPITS(e1i_ts, DLMI, LOGL_DEBUG, "ID_RESP ");
/* parse tags, search for Unit ID */
ret = ipa_ccm_id_resp_parse(&tlvp, (const uint8_t *)msg->l2h+1,
msgb_l2len(msg)-1);
DEBUGPC(DLMI, "\n");
if (ret < 0) {
- LOGP(DLINP, LOGL_ERROR, "IPA response message "
- "with malformed TLVs\n");
+ LOGPITS(e1i_ts, DLINP, LOGL_ERROR, "IPA response
message with malformed TLVs\n");
goto err;
}
if (!TLVP_PRESENT(&tlvp, IPAC_IDTAG_UNIT)) {
- LOGP(DLINP, LOGL_ERROR, "IPA response message "
- "without unit ID\n");
+ LOGPITS(e1i_ts, DLINP, LOGL_ERROR, "IPA response
message without unit ID\n");
goto err;
}
len = TLVP_LEN(&tlvp, IPAC_IDTAG_UNIT);
if (len < 1) {
- LOGP(DLINP, LOGL_ERROR, "IPA response message "
- "with too small unit ID\n");
+ LOGPITS(e1i_ts, DLINP, LOGL_ERROR, "IPA response
message with too small unit ID\n");
goto err;
}
unitid = (char *) TLVP_VAL(&tlvp, IPAC_IDTAG_UNIT);
unitid[len - 1] = '\0';
ret = ipa_parse_unitid(unitid, &unit_data);
if (ret) {
- LOGP(DLINP, LOGL_ERROR, "Failed to parse unit ID
'%s'\n", unitid);
+ LOGPITS(e1i_ts, DLINP, LOGL_ERROR, "Failed to parse
unit ID '%s'\n", unitid);
goto err;
}
if (!line->ops->sign_link_up) {
- LOGP(DLINP, LOGL_ERROR,
- "Unable to set signal link, closing socket.\n");
+ LOGPITS(e1i_ts, DLINP, LOGL_ERROR, "Unable to set
signal link, closing socket.\n");
goto err;
}
/* the BSC creates the new sign links at this stage. */
@@ -290,9 +284,7 @@
line->ops->sign_link_up(&unit_data, line,
E1INP_SIGN_OML);
if (sign_link == NULL) {
- LOGP(DLINP, LOGL_ERROR,
- "Unable to set signal link, "
- "closing socket.\n");
+ LOGPITS(e1i_ts, DLINP, LOGL_ERROR, "Unable to
set signal link, closing socket.\n");
goto err;
}
@@ -308,9 +300,7 @@
line->ops->sign_link_up(&unit_data, line,
E1INP_SIGN_RSL);
if (sign_link == NULL) {
- LOGP(DLINP, LOGL_ERROR,
- "Unable to set signal link, "
- "closing socket.\n");
+ LOGPIL(line, DLINP, LOGL_ERROR, "Unable to set
signal link, closing socket.\n");
goto err;
}
/* Finally, we know which OML link is associated with
@@ -319,10 +309,8 @@
/* this is a bugtrap, the BSC should be using the
* virtual E1 line used by OML for this RSL link. */
if (new_line == line) {
- LOGP(DLINP, LOGL_ERROR,
- "Fix your BSC, you should use the "
- "E1 line used by the OML link for "
- "your RSL link.\n");
+ LOGPIL(line, DLINP, LOGL_ERROR, "Fix your BSC,
you should use the "
+ "E1 line used by the OML link for your
RSL link.\n");
return 0;
}
e1inp_line_get2(new_line, "ipa_bfd");
@@ -345,8 +333,7 @@
ret = osmo_fd_register(newbfd);
if (ret < 0) {
- LOGP(DLINP, LOGL_ERROR,
- "could not register FD\n");
+ LOGPITS(ts, DLINP, LOGL_ERROR, "could not
register FD\n");
goto err;
}
snprintf(tcp_stat_name, sizeof(tcp_stat_name),
"site.%u.bts.%u.ipa-rsl.%u",
@@ -359,7 +346,7 @@
}
break;
default:
- LOGP(DLINP, LOGL_ERROR, "Unknown IPA message type\n");
+ LOGPIL(line, DLINP, LOGL_ERROR, "Unknown IPA message type\n");
goto err;
}
return 0;
@@ -392,14 +379,14 @@
if (ret < 0) {
if (ret == -EAGAIN)
return 0;
- LOGP(DLINP, LOGL_NOTICE, "Sign link problems, "
- "closing socket. Reason: %s\n", strerror(-ret));
+ LOGPITS(e1i_ts, DLINP, LOGL_NOTICE, "Sign link problems,
closing socket. Reason: %s\n",
+ strerror(-ret));
goto err;
} else if (ret == 0) {
- LOGP(DLINP, LOGL_NOTICE, "Sign link vanished, dead socket\n");
+ LOGPITS(e1i_ts, DLINP, LOGL_NOTICE, "Sign link vanished, dead
socket\n");
goto err;
}
- DEBUGP(DLMI, "RX %u: %s\n", ts_nr, osmo_hexdump(msgb_l2(msg),
msgb_l2len(msg)));
+ LOGPITS(e1i_ts, DLMI, LOGL_DEBUG, "RX %u: %s\n", ts_nr,
osmo_hexdump(msgb_l2(msg), msgb_l2len(msg)));
hh = (struct ipaccess_head *) msg->data;
if (hh->proto == IPAC_PROTO_IPACCESS) {
@@ -410,22 +397,20 @@
return ret != 0 ? -EBADF : 0;
} else if (e1i_ts->type == E1INP_TS_TYPE_NONE) {
/* this sign link is not know yet.. complain. */
- LOGP(DLINP, LOGL_ERROR, "Timeslot is not configured.\n");
+ LOGPITS(e1i_ts, DLINP, LOGL_ERROR, "Timeslot is not
configured.\n");
goto err_msg;
}
link = e1inp_lookup_sign_link(e1i_ts, hh->proto, 0);
if (!link) {
- LOGP(DLINP, LOGL_ERROR, "no matching signalling link for "
- "hh->proto=0x%02x\n", hh->proto);
+ LOGPITS(e1i_ts, DLINP, LOGL_ERROR, "no matching signalling link
for hh->proto=0x%02x\n", hh->proto);
goto err_msg;
}
msg->dst = link;
/* XXX better use e1inp_ts_rx? */
if (!e1i_ts->line->ops->sign_link) {
- LOGP(DLINP, LOGL_ERROR, "Fix your application, "
- "no action set for signalling messages.\n");
+ LOGPITS(e1i_ts, DLINP, LOGL_ERROR, "Fix your application, no
action set for signalling messages.\n");
goto err_msg;
}
rc = e1i_ts->line->ops->sign_link(msg);
@@ -434,8 +419,8 @@
* an error, that's too strict. BTW, the signalling layer is
* resposible for releasing the message.
*/
- LOGP(DLINP, LOGL_ERROR, "Bad signalling message,"
- " sign_link returned error: %s.\n", strerror(-rc));
+ LOGPITS(e1i_ts, DLINP, LOGL_ERROR, "Bad signalling message,
sign_link returned error: %s.\n",
+ strerror(-rc));
}
return rc;
@@ -610,10 +595,9 @@
val = 1;
ret = setsockopt(fd, SOL_SOCKET, SO_KEEPALIVE, &val,
sizeof(val));
if (ret < 0)
- LOGP(DLINP, LOGL_ERROR, "Failed to set keepalive: %s\n",
- strerror(errno));
+ LOGPIL(line, DLINP, LOGL_ERROR, "Failed to set
keepalive: %s\n", strerror(errno));
else
- LOGP(DLINP, LOGL_NOTICE, "Keepalive is set: %i\n", ret);
+ LOGPIL(line, DLINP, LOGL_NOTICE, "Keepalive is set:
%d\n", ret);
/* The following options are not portable! */
val = line->keepalive_idle_timeout > 0 ?
@@ -622,42 +606,34 @@
ret = setsockopt(fd, IPPROTO_TCP, TCP_KEEPIDLE,
&val, sizeof(val));
if (ret < 0)
- LOGP(DLINP, LOGL_ERROR,
- "Failed to set keepalive idle time: %s\n",
- strerror(errno));
+ LOGPIL(line, DLINP, LOGL_ERROR, "Failed to set
keepalive idle time: %s\n", strerror(errno));
val = line->keepalive_probe_interval > -1 ?
line->keepalive_probe_interval :
DEFAULT_TCP_KEEPALIVE_INTERVAL;
ret = setsockopt(fd, IPPROTO_TCP, TCP_KEEPINTVL,
&val, sizeof(val));
if (ret < 0)
- LOGP(DLINP, LOGL_ERROR,
- "Failed to set keepalive interval: %s\n",
- strerror(errno));
+ LOGPIL(line, DLINP, LOGL_ERROR, "Failed to set
keepalive interval: %s\n", strerror(errno));
val = line->keepalive_num_probes > 0 ?
line->keepalive_num_probes :
DEFAULT_TCP_KEEPALIVE_RETRY_COUNT;
ret = setsockopt(fd, IPPROTO_TCP, TCP_KEEPCNT,
&val, sizeof(val));
if (ret < 0)
- LOGP(DLINP, LOGL_ERROR,
- "Failed to set keepalive count: %s\n",
- strerror(errno));
+ LOGPIL(line, DLINP, LOGL_ERROR, "Failed to set
keepalive count: %s\n", strerror(errno));
val = 1000 * line->keepalive_num_probes *
line->keepalive_probe_interval +
line->keepalive_idle_timeout;
ret = setsockopt(fd, IPPROTO_TCP, TCP_USER_TIMEOUT,
&val, sizeof(val));
if (ret < 0)
- LOGP(DLINP, LOGL_ERROR,
- "Failed to set user timoeut: %s\n",
- strerror(errno));
+ LOGPIL(line, DLINP, LOGL_ERROR, "Failed to set user
timoeut: %s\n", strerror(errno));
}
val = 1;
ret = setsockopt(fd, IPPROTO_TCP, TCP_NODELAY, &val, sizeof(val));
if (ret < 0)
- LOGP(DLINP, LOGL_ERROR, "Failed to set TCP_NODELAY: %s\n",
strerror(errno));
+ LOGPIL(line, DLINP, LOGL_ERROR, "Failed to set TCP_NODELAY:
%s\n", strerror(errno));
}
/* callback of the OML listening filedescriptor */
@@ -689,7 +665,7 @@
osmo_fd_setup(bfd, fd, OSMO_FD_READ, ipaccess_fd_cb, line,
E1INP_SIGN_OML);
ret = osmo_fd_register(bfd);
if (ret < 0) {
- LOGP(DLINP, LOGL_ERROR, "could not register FD\n");
+ LOGPITS(e1i_ts, DLINP, LOGL_ERROR, "could not register FD\n");
goto err_line;
}
osmo_stats_tcp_osmo_fd_register(bfd, "ipa-oml");
@@ -699,8 +675,7 @@
/* Request ID. FIXME: request LOCATION, HW/SW VErsion, Unit Name, Serno
*/
ret = ipa_ccm_send_id_req(bfd->fd);
if (ret < 0) {
- LOGP(DLINP, LOGL_ERROR, "could not send ID REQ. Reason: %s\n",
- strerror(errno));
+ LOGPITS(e1i_ts, DLINP, LOGL_ERROR, "could not send ID REQ.
Reason: %s\n", strerror(errno));
goto err_socket;
}
return ret;
@@ -743,7 +718,7 @@
osmo_fd_setup(bfd, fd, OSMO_FD_READ, ipaccess_fd_cb, line,
E1INP_SIGN_RSL);
ret = osmo_fd_register(bfd);
if (ret < 0) {
- LOGP(DLINP, LOGL_ERROR, "could not register FD\n");
+ LOGPITS(e1i_ts, DLINP, LOGL_ERROR, "could not register FD\n");
goto err_line;
}
osmo_stats_tcp_osmo_fd_register(bfd, "ipa-rsl");
@@ -751,8 +726,7 @@
/* Request ID. FIXME: request LOCATION, HW/SW VErsion, Unit Name, Serno
*/
ret = ipa_ccm_send_id_req(bfd->fd);
if (ret < 0) {
- LOGP(DLINP, LOGL_ERROR, "could not send ID REQ. Reason: %s\n",
- strerror(errno));
+ LOGPITS(e1i_ts, DLINP, LOGL_ERROR, "could not send ID REQ.
Reason: %s\n", strerror(errno));
goto err_socket;
}
update_fd_settings(line, bfd->fd);
@@ -920,13 +894,13 @@
if (link->ofd->priv_nr >= E1INP_SIGN_RSL)
trx_nr = link->ofd->priv_nr - E1INP_SIGN_RSL;
- LOGP(DLINP, LOGL_NOTICE, "received ID_GET for unit ID
%u/%u/%u\n",
- dev->site_id, dev->bts_id, trx_nr);
+ LOGPIL(line, DLINP, LOGL_NOTICE, "received ID_GET for
unit ID %u/%u/%u\n",
+ dev->site_id, dev->bts_id, trx_nr);
rmsg = ipa_bts_id_resp(dev, data + 1, len - 1, trx_nr);
ret = ipa_send(link->ofd->fd, rmsg->data, rmsg->len);
if (ret != rmsg->len) {
- LOGP(DLINP, LOGL_ERROR, "cannot send ID_RESP "
- "message. Reason: %s\n", strerror(errno));
+ LOGPIL(line, DLINP, LOGL_ERROR, "cannot send
ID_RESP message. Reason: %s\n",
+ strerror(errno));
goto err_rmsg;
}
msgb_free(rmsg);
@@ -935,8 +909,8 @@
rmsg = ipa_bts_id_ack();
ret = ipa_send(link->ofd->fd, rmsg->data, rmsg->len);
if (ret != rmsg->len) {
- LOGP(DLINP, LOGL_ERROR, "cannot send ID_ACK "
- "message. Reason: %s\n", strerror(errno));
+ LOGPIL(line, DLINP, LOGL_ERROR, "cannot send
ID_ACK message. Reason: %s\n",
+ strerror(errno));
goto err_rmsg;
}
msgb_free(rmsg);
@@ -1001,15 +975,15 @@
OSMO_ASSERT(e1i_ts != NULL);
if (e1i_ts->type == E1INP_TS_TYPE_NONE) {
- LOGP(DLINP, LOGL_ERROR, "Signalling link not initialized.
Discarding."
- " port=%u msg_type=%u\n", link->port, msg_type);
+ LOGPITS(e1i_ts, DLINP, LOGL_ERROR, "Signalling link not
initialized. Discarding."
+ " port=%u msg_type=%u\n", link->port, msg_type);
goto err;
}
/* look up for some existing signaling link. */
sign_link = e1inp_lookup_sign_link(e1i_ts, hh->proto, 0);
if (sign_link == NULL) {
- LOGP(DLINP, LOGL_ERROR, "no matching signalling link for "
+ LOGPITS(e1i_ts, DLINP, LOGL_ERROR, "no matching signalling link
for "
"hh->proto=0x%02x\n", hh->proto);
goto err;
}
@@ -1017,7 +991,7 @@
/* XXX better use e1inp_ts_rx? */
if (!link->line->ops->sign_link) {
- LOGP(DLINP, LOGL_ERROR, "Fix your application, "
+ LOGPITS(e1i_ts, DLINP, LOGL_ERROR, "Fix your application, "
"no action set for signalling messages.\n");
goto err;
}
@@ -1043,7 +1017,7 @@
line->driver_data = talloc_zero(line, struct ipaccess_line);
if (!line->driver_data) {
- LOGP(DLINP, LOGL_ERROR, "ipaccess: OOM in line update\n");
+ LOGPIL(line, DLINP, LOGL_ERROR, "ipaccess: OOM in line
update\n");
return -ENOMEM;
}
il = line->driver_data;
@@ -1056,23 +1030,20 @@
struct ipa_server_link *oml_link, *rsl_link;
const char *ipa = e1inp_ipa_get_bind_addr();
- LOGP(DLINP, LOGL_NOTICE, "enabling ipaccess BSC mode on %s "
- "with OML %u and RSL %u TCP ports\n", ipa,
- IPA_TCP_PORT_OML, IPA_TCP_PORT_RSL);
+ LOGPIL(line, DLINP, LOGL_NOTICE, "enabling ipaccess BSC mode on
%s "
+ "with OML %u and RSL %u TCP ports\n", ipa,
IPA_TCP_PORT_OML, IPA_TCP_PORT_RSL);
oml_link = ipa_server_link_create(tall_ipa_ctx, line, ipa,
IPA_TCP_PORT_OML,
ipaccess_bsc_oml_cb, NULL);
if (oml_link == NULL) {
- LOGP(DLINP, LOGL_ERROR, "cannot create OML "
- "BSC link: %s\n", strerror(errno));
+ LOGPIL(line, DLINP, LOGL_ERROR, "cannot create OML BSC
link: %s\n", strerror(errno));
return -ENOMEM;
}
oml_link->dscp = g_e1inp_ipaccess_pars.oml.dscp;
oml_link->priority = g_e1inp_ipaccess_pars.oml.priority;
if (ipa_server_link_open(oml_link) < 0) {
- LOGP(DLINP, LOGL_ERROR, "cannot open OML BSC link:
%s\n",
- strerror(errno));
+ LOGPIL(line, DLINP, LOGL_ERROR, "cannot open OML BSC
link: %s\n", strerror(errno));
ipa_server_link_destroy(oml_link);
return -EIO;
}
@@ -1080,15 +1051,13 @@
IPA_TCP_PORT_RSL,
ipaccess_bsc_rsl_cb, NULL);
if (rsl_link == NULL) {
- LOGP(DLINP, LOGL_ERROR, "cannot create RSL "
- "BSC link: %s\n", strerror(errno));
+ LOGPIL(line, DLINP, LOGL_ERROR, "cannot create RSL BSC
link: %s\n", strerror(errno));
return -ENOMEM;
}
rsl_link->dscp = g_e1inp_ipaccess_pars.rsl.dscp;
rsl_link->priority = g_e1inp_ipaccess_pars.rsl.priority;
if (ipa_server_link_open(rsl_link) < 0) {
- LOGP(DLINP, LOGL_ERROR, "cannot open RSL BSC link:
%s\n",
- strerror(errno));
+ LOGPIL(line, DLINP, LOGL_ERROR, "cannot open RSL BSC
link: %s\n", strerror(errno));
ipa_server_link_destroy(rsl_link);
return -EIO;
}
@@ -1099,9 +1068,8 @@
struct ipa_client_conn *link;
struct e1inp_ts *e1i_ts = e1inp_line_ipa_oml_ts(line);
- LOGP(DLINP, LOGL_NOTICE, "enabling ipaccess BTS mode, "
- "OML connecting to %s:%u\n", line->ops->cfg.ipa.addr,
- IPA_TCP_PORT_OML);
+ LOGPITS(e1i_ts, DLINP, LOGL_NOTICE, "enabling ipaccess BTS
mode, "
+ "OML connecting to %s:%u\n", line->ops->cfg.ipa.addr,
IPA_TCP_PORT_OML);
/* Drop previous line */
if (il->ipa_cli[0]) {
@@ -1122,15 +1090,13 @@
ipaccess_bts_write_cb,
line);
if (link == NULL) {
- LOGP(DLINP, LOGL_ERROR, "cannot create OML "
- "BTS link: %s\n", strerror(errno));
+ LOGPITS(e1i_ts, DLINP, LOGL_ERROR, "cannot create OML
BTS link: %s\n", strerror(errno));
return -ENOMEM;
}
link->dscp = g_e1inp_ipaccess_pars.oml.dscp;
link->priority = g_e1inp_ipaccess_pars.oml.priority;
if (ipa_client_conn_open2(link, line->connect_timeout) < 0) {
- LOGP(DLINP, LOGL_ERROR, "cannot open OML BTS link:
%s\n",
- strerror(errno));
+ LOGPITS(e1i_ts, DLINP, LOGL_ERROR, "cannot open OML BTS
link: %s\n", strerror(errno));
ipa_client_conn_close(link);
ipa_client_conn_destroy(link);
return -EIO;
@@ -1166,7 +1132,7 @@
int rc;
if (E1INP_SIGN_RSL+trx_nr-1 >= NUM_E1_TS) {
- LOGP(DLINP, LOGL_ERROR, "cannot create RSL BTS link: "
+ LOGPITS(e1i_ts, DLINP, LOGL_ERROR, "cannot create RSL BTS link:
"
"trx_nr (%d) out of range\n", trx_nr);
return -EINVAL;
}
@@ -1189,15 +1155,13 @@
ipaccess_bts_write_cb,
line);
if (rsl_link == NULL) {
- LOGP(DLINP, LOGL_ERROR, "cannot create RSL "
- "BTS link: %s\n", strerror(errno));
+ LOGPITS(e1i_ts, DLINP, LOGL_ERROR, "cannot create RSL BTS link:
%s\n", strerror(errno));
return -ENOMEM;
}
rsl_link->dscp = g_e1inp_ipaccess_pars.rsl.dscp;
rsl_link->priority = g_e1inp_ipaccess_pars.rsl.priority;
if (ipa_client_conn_open2(rsl_link, line->connect_timeout) < 0) {
- LOGP(DLINP, LOGL_ERROR, "cannot open RSL BTS link: %s\n",
- strerror(errno));
+ LOGPITS(e1i_ts, DLINP, LOGL_ERROR, "cannot open RSL BTS link:
%s\n", strerror(errno));
ipa_client_conn_close(rsl_link);
ipa_client_conn_destroy(rsl_link);
return -EIO;
@@ -1215,8 +1179,7 @@
struct e1inp_ts *e1i_ts;
if (E1INP_SIGN_RSL+trx_nr-1 >= NUM_E1_TS) {
- LOGP(DLINP, LOGL_ERROR,
- "cannot close RSL BTS link: trx_nr (%d) out of range\n",
trx_nr);
+ LOGPIL(line, DLINP, LOGL_ERROR, "cannot close RSL BTS link:
trx_nr (%d) out of range\n", trx_nr);
return -EINVAL;
}
--
To view, visit https://gerrit.osmocom.org/c/libosmo-abis/+/36037?usp=email
To unsubscribe, or for help writing mail filters, visit
https://gerrit.osmocom.org/settings
Gerrit-Project: libosmo-abis
Gerrit-Branch: master
Gerrit-Change-Id: I5cd84c2d69c0db3be296cb5d9a62720f7b2c827e
Gerrit-Change-Number: 36037
Gerrit-PatchSet: 2
Gerrit-Owner: laforge <lafo...@osmocom.org>
Gerrit-Reviewer: Jenkins Builder
Gerrit-Reviewer: laforge <lafo...@osmocom.org>
Gerrit-Reviewer: osmith <osm...@sysmocom.de>
Gerrit-Reviewer: pespin <pes...@sysmocom.de>
Gerrit-MessageType: merged
