Change in ...osmo-bts[master]: bts-trx: trx_if.c: Introduce logging macro LOGPPHI

Harald Welte gerrit-no-reply at lists.osmocom.org
Tue Jun 4 16:36:25 UTC 2019


Harald Welte has submitted this change and it was merged. ( https://gerrit.osmocom.org/c/osmo-bts/+/14373 )

Change subject: bts-trx: trx_if.c: Introduce logging macro LOGPPHI
......................................................................

bts-trx: trx_if.c: Introduce logging macro LOGPPHI

This way we unify format. We take the chance to add related information
to some log messages which were not printing that information (and was
confusing when using more than one phy instance).

Change-Id: I5b17a01638ade9a6c41da73e550d5947fa92f568
---
M include/osmo-bts/phy_link.h
M src/osmo-bts-trx/l1_if.c
M src/osmo-bts-trx/trx_if.c
3 files changed, 38 insertions(+), 44 deletions(-)

Approvals:
  Jenkins Builder: Verified
  Harald Welte: Looks good to me, approved



diff --git a/include/osmo-bts/phy_link.h b/include/osmo-bts/phy_link.h
index 812f186..273103c 100644
--- a/include/osmo-bts/phy_link.h
+++ b/include/osmo-bts/phy_link.h
@@ -173,3 +173,5 @@
 }
 
 int bts_model_phy_link_open(struct phy_link *plink);
+
+#define LOGPPHI(pinst, section, lvl, fmt, args...) LOGP(section, lvl, "%s: " fmt, phy_instance_name(pinst), ##args)
diff --git a/src/osmo-bts-trx/l1_if.c b/src/osmo-bts-trx/l1_if.c
index 290ceee..e6e384a 100644
--- a/src/osmo-bts-trx/l1_if.c
+++ b/src/osmo-bts-trx/l1_if.c
@@ -159,20 +159,20 @@
 	enum gsm_phys_chan_config pchan;
 
 	if (tn >= TRX_NR_TS) {
-		LOGP(DL1C, LOGL_ERROR, "transceiver (%s) SETSLOT invalid param TN (%" PRIu8 ")\n",
-		     phy_instance_name(pinst), tn);
+		LOGPPHI(pinst, DL1C, LOGL_ERROR, "transceiver SETSLOT invalid param TN (%" PRIu8 ")\n",
+			tn);
 		return;
 	}
 
 	pchan = transceiver_chan_type_2_pchan(type);
 	if (pchan == GSM_PCHAN_UNKNOWN) {
-		LOGP(DL1C, LOGL_ERROR, "transceiver (%s) SETSLOT invalid param TS_TYPE (%" PRIu8 ")\n",
-		     phy_instance_name(pinst), type);
+		LOGPPHI(pinst, DL1C, LOGL_ERROR, "transceiver SETSLOT invalid param TS_TYPE (%" PRIu8 ")\n",
+			type);
 		return;
 	}
 
 	ts = &trx->ts[tn];
-	LOGP(DL1C, LOGL_DEBUG, "%s l1if_setslot_cb(as_pchan=%s),"
+	LOGPPHI(pinst, DL1C, LOGL_DEBUG, "%s l1if_setslot_cb(as_pchan=%s),"
 	     " calling cb_ts_connected(rc=%d)\n",
 	     gsm_ts_name(ts), gsm_pchan_name(pchan), rc);
 	cb_ts_connected(ts, rc);
diff --git a/src/osmo-bts-trx/trx_if.c b/src/osmo-bts-trx/trx_if.c
index ec879c7..2805260 100644
--- a/src/osmo-bts-trx/trx_if.c
+++ b/src/osmo-bts-trx/trx_if.c
@@ -155,7 +155,7 @@
 	len = snprintf(buf, sizeof(buf), "CMD %s%s%s", tcm->cmd, tcm->params_len ? " ":"", tcm->params);
 	OSMO_ASSERT(len < sizeof(buf));
 
-	LOGP(DTRX, LOGL_DEBUG, "Sending control '%s' to %s\n", buf, phy_instance_name(l1h->phy_inst));
+	LOGPPHI(l1h->phy_inst, DTRX, LOGL_DEBUG, "Sending control '%s'\n", buf);
 	/* send command */
 	send(l1h->trx_ofd_ctrl.fd, buf, len+1, 0);
 
@@ -173,8 +173,7 @@
 	OSMO_ASSERT(!llist_empty(&l1h->trx_ctrl_list));
 	tcm = llist_entry(l1h->trx_ctrl_list.next, struct trx_ctrl_msg, list);
 
-	LOGP(DTRX, LOGL_NOTICE, "No satisfactory response from transceiver for %s (CMD %s%s%s)\n",
-		phy_instance_name(l1h->phy_inst),
+	LOGPPHI(l1h->phy_inst, DTRX, LOGL_NOTICE, "No satisfactory response from transceiver(CMD %s%s%s)\n",
 		tcm->cmd, tcm->params_len ? " ":"", tcm->params);
 
 	trx_ctrl_send(l1h);
@@ -208,8 +207,8 @@
 
 	if (!transceiver_available &&
 	    !(!strcmp(cmd, "POWEROFF") || !strcmp(cmd, "POWERON"))) {
-		LOGP(DTRX, LOGL_ERROR, "CTRL %s ignored: No clock from "
-		     "transceiver, please fix!\n", cmd);
+		LOGPPHI(l1h->phy_inst, DTRX, LOGL_ERROR, "CTRL %s ignored: No clock from "
+			"transceiver, please fix!\n", cmd);
 		return -EIO;
 	}
 
@@ -241,7 +240,7 @@
 
 	if (!pending ||
 	    !(strcmp(tcm->cmd, prev->cmd) == 0 && strcmp(tcm->params, prev->params) == 0)) {
-		LOGP(DTRX, LOGL_INFO, "Enqueuing TRX control command 'CMD %s%s%s'\n",
+		LOGPPHI(l1h->phy_inst, DTRX, LOGL_INFO, "Enqueuing TRX control command 'CMD %s%s%s'\n",
 			tcm->cmd, tcm->params_len ? " ":"", tcm->params);
 		llist_add_tail(&tcm->list, &l1h->trx_ctrl_list);
 	}
@@ -449,14 +448,13 @@
 	unsigned int tn, ts_type;
 
 	if (rsp->status)
-		LOGP(DTRX, LOGL_ERROR, "transceiver (%s) SETSLOT failed with status %d\n",
-		     phy_instance_name(pinst), rsp->status);
+		LOGPPHI(pinst, DTRX, LOGL_ERROR, "transceiver SETSLOT failed with status %d\n",
+			rsp->status);
 
 	/* Since message was already validated against CMD we sent, we know format
 	 * of params is: "<TN> <TS_TYPE>" */
 	if (sscanf(rsp->params, "%u %u", &tn, &ts_type) < 2) {
-		LOGP(DTRX, LOGL_ERROR, "transceiver (%s) SETSLOT unable to parse params\n",
-		     phy_instance_name(pinst));
+		LOGPPHI(pinst, DTRX, LOGL_ERROR, "transceiver SETSLOT unable to parse params\n");
 		return -EINVAL;
 	}
 
@@ -481,9 +479,9 @@
 				phy_link_state_set(pinst->phy_link, PHY_LINK_CONNECTED);
 			return 0;
 		} else {
-			LOGP(DTRX, LOGL_NOTICE,
-			     "transceiver (%s) rejected POWERON command (%d), re-trying in a few seconds\n",
-			     phy_instance_name(pinst), rsp->status);
+			LOGPPHI(l1h->phy_inst, DTRX, LOGL_NOTICE,
+				"transceiver rejected POWERON command (%d), re-trying in a few seconds\n",
+				rsp->status);
 			if (pinst->phy_link->state != PHY_LINK_SHUTDOWN)
 				phy_link_state_set(pinst->phy_link, PHY_LINK_SHUTDOWN);
 			return 5;
@@ -493,10 +491,10 @@
 	}
 
 	if (rsp->status) {
-		LOGP(DTRX, critical ? LOGL_FATAL : LOGL_NOTICE,
-		     "transceiver (%s) rejected TRX command with response: '%s%s%s %d'\n",
-		     phy_instance_name(pinst), rsp->cmd, rsp->params[0] != '\0' ? " ":"",
-		     rsp->params, rsp->status);
+		LOGPPHI(l1h->phy_inst, DTRX, critical ? LOGL_FATAL : LOGL_NOTICE,
+			"transceiver rejected TRX command with response: '%s%s%s %d'\n",
+			rsp->cmd, rsp->params[0] != '\0' ? " ":"",
+			rsp->params, rsp->status);
 		if (critical)
 			return -EINVAL;
 	}
@@ -521,7 +519,7 @@
 	if (parse_rsp(buf, len, &rsp) < 0)
 		return 0;
 
-	LOGP(DTRX, LOGL_INFO, "Response message: '%s'\n", buf);
+	LOGPPHI(l1h->phy_inst, DTRX, LOGL_INFO, "Response message: '%s'\n", buf);
 
 	/* abort timer and send next message, if any */
 	if (osmo_timer_pending(&l1h->trx_ctrl_timer))
@@ -531,12 +529,11 @@
 	if (llist_empty(&l1h->trx_ctrl_list)) {
 		/* RSP from a retransmission, skip it */
 		if (l1h->last_acked && cmd_matches_rsp(l1h->last_acked, &rsp)) {
-			LOGP(DTRX, LOGL_NOTICE, "Discarding duplicated RSP "
+			LOGPPHI(l1h->phy_inst, DTRX, LOGL_NOTICE, "Discarding duplicated RSP "
 				"from old CMD '%s'\n", buf);
 			return 0;
 		}
-		LOGP(DTRX, LOGL_NOTICE, "Response message without "
-			"command\n");
+		LOGPPHI(l1h->phy_inst, DTRX, LOGL_NOTICE, "Response message without command\n");
 		return -EINVAL;
 	}
 	tcm = llist_entry(l1h->trx_ctrl_list.next, struct trx_ctrl_msg,
@@ -546,11 +543,11 @@
 	if (!cmd_matches_rsp(tcm, &rsp)) {
 		/* RSP from a retransmission, skip it */
 		if (l1h->last_acked && cmd_matches_rsp(l1h->last_acked, &rsp)) {
-			LOGP(DTRX, LOGL_NOTICE, "Discarding duplicated RSP "
+			LOGPPHI(l1h->phy_inst, DTRX, LOGL_NOTICE, "Discarding duplicated RSP "
 				"from old CMD '%s'\n", buf);
 			return 0;
 		}
-		LOGP(DTRX, (tcm->critical) ? LOGL_FATAL : LOGL_NOTICE,
+		LOGPPHI(l1h->phy_inst, DTRX, (tcm->critical) ? LOGL_FATAL : LOGL_NOTICE,
 			"Response message '%s' does not match command "
 			"message 'CMD %s%s%s'\n",
 			buf, tcm->cmd, tcm->params_len ? " ":"", tcm->params);
@@ -609,7 +606,7 @@
 		burst_len = EGPRS_BURST_LEN;
 	/* Accept bursts ending with 2 bytes of padding (OpenBTS compatible trx) or without them: */
 	} else if (len != GSM_BURST_LEN + 10 && len != GSM_BURST_LEN + 8) {
-		LOGP(DTRX, LOGL_NOTICE, "Got data message with invalid lenght "
+		LOGPPHI(l1h->phy_inst, DTRX, LOGL_NOTICE, "Got data message with invalid lenght "
 			"'%d'\n", len);
 		return -EINVAL;
 	}
@@ -627,15 +624,15 @@
 	}
 
 	if (tn >= 8) {
-		LOGP(DTRX, LOGL_ERROR, "Illegal TS %d\n", tn);
+		LOGPPHI(l1h->phy_inst, DTRX, LOGL_ERROR, "Illegal TS %d\n", tn);
 		return -EINVAL;
 	}
 	if (fn >= GSM_HYPERFRAME) {
-		LOGP(DTRX, LOGL_ERROR, "Illegal FN %u\n", fn);
+		LOGPPHI(l1h->phy_inst, DTRX, LOGL_ERROR, "Illegal FN %u\n", fn);
 		return -EINVAL;
 	}
 
-	LOGP(DTRX, LOGL_DEBUG, "RX burst tn=%u fn=%u rssi=%d toa256=%d\n",
+	LOGPPHI(l1h->phy_inst, DTRX, LOGL_DEBUG, "RX burst tn=%u fn=%u rssi=%d toa256=%d\n",
 		tn, fn, rssi, toa256);
 
 #ifdef TOA_RSSI_DEBUG
@@ -667,11 +664,11 @@
 	uint8_t buf[TRX_MAX_BURST_LEN];
 
 	if ((nbits != GSM_BURST_LEN) && (nbits != EGPRS_BURST_LEN)) {
-		LOGP(DTRX, LOGL_ERROR, "Tx burst length %u invalid\n", nbits);
+		LOGPPHI(l1h->phy_inst, DTRX, LOGL_ERROR, "Tx burst length %u invalid\n", nbits);
 		return -1;
 	}
 
-	LOGP(DTRX, LOGL_DEBUG, "TX burst tn=%u fn=%u pwr=%u\n", tn, fn, pwr);
+	LOGPPHI(l1h->phy_inst, DTRX, LOGL_DEBUG, "TX burst tn=%u fn=%u pwr=%u\n", tn, fn, pwr);
 
 	buf[0] = tn;
 	buf[1] = (fn >> 24) & 0xff;
@@ -688,7 +685,7 @@
 	if (transceiver_available && llist_empty(&l1h->trx_ctrl_list)) {
 		send(l1h->trx_ofd_data.fd, buf, nbits + 6, 0);
 	} else
-		LOGP(DTRX, LOGL_ERROR, "Ignoring TX data, transceiver offline.\n");
+		LOGPPHI(l1h->phy_inst, DTRX, LOGL_ERROR, "Ignoring TX data, transceiver offline.\n");
 
 	return 0;
 }
@@ -716,9 +713,7 @@
 /*! close the TRX for given handle (data + control socket) */
 void trx_if_close(struct trx_l1h *l1h)
 {
-	struct phy_instance *pinst = l1h->phy_inst;
-	LOGP(DTRX, LOGL_NOTICE, "Close transceiver for %s\n",
-		phy_instance_name(pinst));
+	LOGPPHI(l1h->phy_inst, DTRX, LOGL_NOTICE, "Close transceiver\n");
 
 	trx_if_flush(l1h);
 
@@ -749,8 +744,7 @@
 	struct phy_link *plink = pinst->phy_link;
 	int rc;
 
-	LOGP(DTRX, LOGL_NOTICE, "Open transceiver for %s\n",
-		phy_instance_name(pinst));
+	LOGPPHI(l1h->phy_inst, DTRX, LOGL_NOTICE, "Open transceiver\n");
 
 	/* initialize ctrl queue */
 	INIT_LLIST_HEAD(&l1h->trx_ctrl_list);
@@ -806,15 +800,13 @@
 
 	rc = trx_sched_init(&l1h->l1s, pinst->trx);
 	if (rc < 0) {
-		LOGP(DL1C, LOGL_FATAL, "Cannot initialize scheduler for phy "
-		     "instance %d\n", pinst->num);
+		LOGPPHI(l1h->phy_inst, DL1C, LOGL_FATAL, "Cannot initialize scheduler\n");
 		return -EIO;
 	}
 
 	rc = trx_if_open(l1h);
 	if (rc < 0) {
-		LOGP(DL1C, LOGL_FATAL, "Cannot open TRX interface for phy "
-		     "instance %d\n", pinst->num);
+		LOGPPHI(l1h->phy_inst, DL1C, LOGL_FATAL, "Cannot open TRX interface\n");
 		trx_phy_inst_close(pinst);
 		return -EIO;
 	}

-- 
To view, visit https://gerrit.osmocom.org/c/osmo-bts/+/14373
To unsubscribe, or for help writing mail filters, visit https://gerrit.osmocom.org/settings

Gerrit-Project: osmo-bts
Gerrit-Branch: master
Gerrit-Change-Id: I5b17a01638ade9a6c41da73e550d5947fa92f568
Gerrit-Change-Number: 14373
Gerrit-PatchSet: 2
Gerrit-Owner: pespin <pespin at sysmocom.de>
Gerrit-Reviewer: Harald Welte <laforge at gnumonks.org>
Gerrit-Reviewer: Jenkins Builder
Gerrit-MessageType: merged
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.osmocom.org/pipermail/gerrit-log/attachments/20190604/d605ab02/attachment.html>


More information about the gerrit-log mailing list