Introduce + use LOG/DEBUGP with frame number prefixing/printing

Let's make sure whenever we do have a frame number, we print it as
context in the related log line

Change-Id: I751d5ddb3322fce489bc241459738cbcc55c890b

2 files changed, 17 insertions, 20 deletions

diff --git a/src/osmo-bts-sysmo/l1_if.c b/src/osmo-bts-sysmo/l1_if.c
index 44ba3de7..cc1337bc 100644
--- a/src/osmo-bts-sysmo/l1_if.c
+++ b/src/osmo-bts-sysmo/l1_if.c
@@ -390,7 +390,7 @@ static int ph_data_req(struct gsm_bts_trx *trx, struct msgb *msg,
 		else
 			sapi = GsmL1_Sapi_Agch;
 	} else {
-		LOGP(DL1C, LOGL_NOTICE, "unknown prim %d op %d "
+		LOGPFN(DL1C, LOGL_NOTICE, u32Fn, "unknown prim %d op %d "
 			"chan_nr %d link_id %d\n", l1sap->oph.primitive,
 			l1sap->oph.operation, chan_nr, link_id);
 		msgb_free(l1msg);
@@ -453,7 +453,7 @@ static int ph_data_req(struct gsm_bts_trx *trx, struct msgb *msg,
 			memcpy(l1p->u.phDataReq.msgUnitParam.u8Buffer, msg->l2h,
 			       msgb_l2len(msg));
 		}
-		LOGP(DL1P, LOGL_DEBUG, "PH-DATA.req(%s)\n",
+		LOGPFN(DL1P, LOGL_DEBUG, u32Fn, "PH-DATA.req(%s)\n",
 		     osmo_hexdump(l1p->u.phDataReq.msgUnitParam.u8Buffer,
 					  l1p->u.phDataReq.msgUnitParam.u8Size));
 	} else {
@@ -465,7 +465,7 @@ static int ph_data_req(struct gsm_bts_trx *trx, struct msgb *msg,
 
 	/* send message to DSP's queue */
 	if (osmo_wqueue_enqueue(&fl1->write_q[MQ_L1_WRITE], l1msg) != 0) {
-		LOGP(DL1P, LOGL_ERROR, "MQ_L1_WRITE queue full. Dropping msg.\n");
+		LOGPFN(DL1P, LOGL_ERROR, u32Fn, "MQ_L1_WRITE queue full. Dropping msg.\n");
 		msgb_free(l1msg);
 	} else
 		dtx_int_signal(lchan);
@@ -834,8 +834,7 @@ static int handle_ph_readytosend_ind(struct femtol1_hdl *fl1,
 
 	gsm_fn2gsmtime(&g_time, rts_ind->u32Fn);
 
-	DEBUGP(DL1P, "Rx PH-RTS.ind %02u/%02u/%02u SAPI=%s\n",
-		g_time.t1, g_time.t2, g_time.t3,
+	DEBUGPGT(DL1P, &g_time, "Rx PH-RTS.ind SAPI=%s\n",
 		get_value_string(femtobts_l1sapi_names, rts_ind->sapi));
 
 	/* in all other cases, we need to allocate a new PH-DATA.ind
@@ -873,7 +872,7 @@ tx:
 
 	/* transmit */
 	if (osmo_wqueue_enqueue(&fl1->write_q[MQ_L1_WRITE], resp_msg) != 0) {
-		LOGP(DL1C, LOGL_ERROR, "MQ_L1_WRITE queue full. Dropping msg.\n");
+		LOGPGT(DL1C, LOGL_ERROR, &g_time, "MQ_L1_WRITE queue full. Dropping msg.\n");
 		msgb_free(resp_msg);
 	}
 
@@ -929,7 +928,7 @@ static int handle_ph_data_ind(struct femtol1_hdl *fl1, GsmL1_PhDataInd_t *data_i
 	chan_nr = chan_nr_by_sapi(&trx->ts[data_ind->u8Tn], data_ind->sapi,
 		data_ind->subCh, data_ind->u8Tn, data_ind->u32Fn);
 	if (!chan_nr) {
-		LOGP(DL1C, LOGL_ERROR, "PH-DATA-INDICATION for unknown sapi %s (%d)\n",
+		LOGPFN(DL1C, LOGL_ERROR, data_ind->u32Fn, "PH-DATA-INDICATION for unknown sapi %s (%d)\n",
 		     get_value_string(femtobts_l1sapi_names, data_ind->sapi), data_ind->sapi);
 		msgb_free(l1p_msg);
 		return ENOTSUP;
@@ -941,11 +940,9 @@ static int handle_ph_data_ind(struct femtol1_hdl *fl1, GsmL1_PhDataInd_t *data_i
 
 	gsm_fn2gsmtime(&g_time, fn);
 
-	DEBUGP(DL1P, "Rx PH-DATA.ind %s %s (hL2 %08x): %s\n",
-		get_value_string(femtobts_l1sapi_names, data_ind->sapi),
-		osmo_dump_gsmtime(&g_time), data_ind->hLayer2,
-		osmo_hexdump(data_ind->msgUnitParam.u8Buffer,
-			     data_ind->msgUnitParam.u8Size));
+	DEBUGPGT(DL1P, &g_time, "Rx PH-DATA.ind %s (hL2 %08x): %s\n",
+		get_value_string(femtobts_l1sapi_names, data_ind->sapi), data_ind->hLayer2,
+		osmo_hexdump(data_ind->msgUnitParam.u8Buffer, data_ind->msgUnitParam.u8Size));
 	dump_meas_res(LOGL_DEBUG, &data_ind->measParam);
 
 	/* check for TCH */
@@ -1018,7 +1015,7 @@ static int handle_ph_ra_ind(struct femtol1_hdl *fl1, GsmL1_PhRaInd_t *ra_ind,
 
 	if ((ra_ind->msgUnitParam.u8Size != 1) &&
 		(ra_ind->msgUnitParam.u8Size != 2)) {
-		LOGP(DL1C, LOGL_ERROR, "PH-RACH-INDICATION has %d bits\n",
+		LOGPFN(DL1C, LOGL_ERROR, ra_ind->u32Fn, "PH-RACH-INDICATION has %d bits\n",
 			ra_ind->sapi);
 		msgb_free(l1p_msg);
 		return 0;
diff --git a/src/osmo-bts-sysmo/tch.c b/src/osmo-bts-sysmo/tch.c
index b65628f0..4e6e2468 100644
--- a/src/osmo-bts-sysmo/tch.c
+++ b/src/osmo-bts-sysmo/tch.c
@@ -514,7 +514,7 @@ int l1if_tch_rx(struct gsm_bts_trx *trx, uint8_t chan_nr, struct msgb *l1p_msg)
 		return -EAGAIN;
 
 	if (data_ind->msgUnitParam.u8Size < 1) {
-		LOGP(DL1P, LOGL_DEBUG, "chan_nr %d Rx Payload size 0\n", chan_nr);
+		LOGPFN(DL1P, LOGL_DEBUG, data_ind->u32Fn, "chan_nr %d Rx Payload size 0\n", chan_nr);
 		/* Push empty payload to upper layers */
 		rmsg = msgb_alloc_headroom(256, 128, "L1P-to-RTP");
 		return add_l1sap_header(trx, rmsg, lchan, chan_nr, data_ind->u32Fn,
@@ -555,31 +555,31 @@ int l1if_tch_rx(struct gsm_bts_trx *trx, uint8_t chan_nr, struct msgb *l1p_msg)
 	case GsmL1_TchPlType_Amr_SidFirstP1:
 		if (lchan->type != GSM_LCHAN_TCH_H)
 			goto err_payload_match;
-		LOGP(DL1P, LOGL_DEBUG, "DTX: received SID_FIRST_P1 from L1 "
+		LOGPFN(DL1P, LOGL_DEBUG, data_ind->u32Fn, "DTX: received SID_FIRST_P1 from L1 "
 		     "(%d bytes)\n", payload_len);
 		break;
 	case GsmL1_TchPlType_Amr_SidFirstP2:
 		if (lchan->type != GSM_LCHAN_TCH_H)
 			goto err_payload_match;
-		LOGP(DL1P, LOGL_DEBUG, "DTX: received SID_FIRST_P2 from L1 "
+		LOGPFN(DL1P, LOGL_DEBUG, data_ind->u32Fn, "DTX: received SID_FIRST_P2 from L1 "
 		     "(%d bytes)\n", payload_len);
 		break;
 	case GsmL1_TchPlType_Amr_SidFirstInH:
 		if (lchan->type != GSM_LCHAN_TCH_H)
 			goto err_payload_match;
 		lchan->rtp_tx_marker = true;
-		LOGP(DL1P, LOGL_DEBUG, "DTX: received SID_FIRST_INH from L1 "
+		LOGPFN(DL1P, LOGL_DEBUG, data_ind->u32Fn, "DTX: received SID_FIRST_INH from L1 "
 		     "(%d bytes)\n", payload_len);
 		break;
 	case GsmL1_TchPlType_Amr_SidUpdateInH:
 		if (lchan->type != GSM_LCHAN_TCH_H)
 			goto err_payload_match;
 		lchan->rtp_tx_marker = true;
-		LOGP(DL1P, LOGL_DEBUG, "DTX: received SID_UPDATE_INH from L1 "
+		LOGPFN(DL1P, LOGL_DEBUG, data_ind->u32Fn, "DTX: received SID_UPDATE_INH from L1 "
 		     "(%d bytes)\n", payload_len);
 		break;
 	default:
-		LOGP(DL1P, LOGL_NOTICE, "%s Rx Payload Type %s is unsupported\n",
+		LOGPFN(DL1P, LOGL_NOTICE, data_ind->u32Fn, "%s Rx Payload Type %s is unsupported\n",
 			gsm_lchan_name(lchan),
 			get_value_string(femtobts_tch_pl_names, payload_type));
 		break;
@@ -619,7 +619,7 @@ int l1if_tch_rx(struct gsm_bts_trx *trx, uint8_t chan_nr, struct msgb *l1p_msg)
 	return 0;
 
 err_payload_match:
-	LOGP(DL1P, LOGL_ERROR, "%s Rx Payload Type %s incompatible with lchan\n",
+	LOGPFN(DL1P, LOGL_ERROR, data_ind->u32Fn, "%s Rx Payload Type %s incompatible with lchan\n",
 		gsm_lchan_name(lchan),
 		get_value_string(femtobts_tch_pl_names, payload_type));
 	return -EINVAL;