[PATCH] osmo-bts[master]: Introduce + use LOG/DEBUGP with frame number prefixing/printing
Hello Jenkins Builder,
I'd like you to reexamine a change. Please visit
https://gerrit.osmocom.org/6676
to look at the new patch set (#2).
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
---
M include/osmo-bts/logging.h
M src/common/l1sap.c
M src/osmo-bts-litecell15/l1_if.c
M src/osmo-bts-litecell15/tch.c
M src/osmo-bts-octphy/l1_if.c
M src/osmo-bts-octphy/l1_tch.c
M src/osmo-bts-sysmo/l1_if.c
M src/osmo-bts-sysmo/tch.c
M src/osmo-bts-virtual/l1_if.c
9 files changed, 118 insertions(+), 125 deletions(-)
git pull ssh://gerrit.osmocom.org:29418/osmo-bts refs/changes/76/6676/2
diff --git a/include/osmo-bts/logging.h b/include/osmo-bts/logging.h
index b1b44d5..68f379c 100644
--- a/include/osmo-bts/logging.h
+++ b/include/osmo-bts/logging.h
@@ -27,4 +27,16 @@
int bts_log_init(const char *category_mask);
+/* LOGP with gsm_time prefix */
+#define LOGPGT(ss, lvl, gt, fmt, args...) \
+ LOGP(ss, lvl, "%s " fmt, osmo_dump_gsmtime(gt), ## args)
+#define DEBUGPGT(ss, gt, fmt, args...) \
+ LOGP(ss, LOGL_DEBUG, "%s " fmt, osmo_dump_gsmtime(gt), ## args)
+
+/* LOGP with frame number prefix */
+#define LOGPFN(ss, lvl, fn, fmt, args...) \
+ LOGP(ss, lvl, "%s " fmt, gsm_fn_as_gsmtime_str(fn), ## args)
+#define DEBUGPFN(ss, fn, fmt, args...) \
+ LOGP(ss, LOGL_DEBUG, "%s " fmt, gsm_fn_as_gsmtime_str(fn), ## args)
+
#endif /* _LOGGING_H */
diff --git a/src/common/l1sap.c b/src/common/l1sap.c
index 1deee83..01b454c 100644
--- a/src/common/l1sap.c
+++ b/src/common/l1sap.c
@@ -451,13 +451,13 @@
struct gsm_bts_role_bts *btsb = bts->role;
int frames_expired;
- DEBUGP(DL1P, "MPH_INFO time ind %u\n", info_time_ind->fn);
+ DEBUGPFN(DL1P, info_time_ind->fn, "Rx MPH_INFO time ind\n");
/* Calculate and check frame difference */
frames_expired = info_time_ind->fn - btsb->gsm_time.fn;
if (frames_expired > 1) {
if (btsb->gsm_time.fn)
- LOGP(DL1P, LOGL_ERROR,
+ LOGPFN(DL1P, LOGL_ERROR, info_time_ind->fn,
"Invalid condition detected: Frame difference is
%"PRIu32"-%"PRIu32"=%d > 1!\n",
info_time_ind->fn, btsb->gsm_time.fn,
frames_expired);
}
@@ -506,12 +506,13 @@
lchan = get_active_lchan_by_chan_nr(trx, info_meas_ind->chan_nr);
if (!lchan) {
- LOGP(DL1P, LOGL_ERROR, "No lchan for MPH INFO MEAS IND
(chan_nr=%u)\n",
-info_meas_ind->chan_nr);
+ LOGPFN(DL1P, LOGL_ERROR, info_meas_ind->fn,
+ "No lchan for MPH INFO MEAS IND (chan_nr=%u)\n",
info_meas_ind->chan_nr);
return 0;
}
- DEBUGP(DL1P, "%s MPH_INFO meas ind, ta_offs_qbits=%d, ber10k=%d,
inv_rssi=%u\n",
+ DEBUGPFN(DL1P, info_meas_ind->fn,
+ "%s MPH_INFO meas ind, ta_offs_qbits=%d, ber10k=%d,
inv_rssi=%u\n",
gsm_lchan_name(lchan), info_meas_ind->ta_offs_qbits,
info_meas_ind->ber10k, info_meas_ind->inv_rssi);
@@ -546,9 +547,9 @@
switch (info->type) {
case PRIM_INFO_TIME:
if (trx != trx->bts->c0) {
- LOGP(DL1P, LOGL_NOTICE, "BTS model is sending us "
-"PRIM_INFO_TIME for TRX %u, please fix it\n",
-trx->nr);
+ LOGPFN(DL1P, LOGL_NOTICE, info->u.time_ind.fn,
+ "BTS model is sending us PRIM_INFO_TIME for TRX
%u, please fix it\n",
+ trx->nr);
rc = -1;
} else
rc = l1sap_info_time_ind(trx->bts, l1sap,
@@ -654,14 +655,14 @@
/* de-queue response message (loopback) */
loop_msg = msgb_dequeue(&lchan->dl_tch_queue);
if (!loop_msg) {
- LOGP(DL1P, LOGL_NOTICE, "%s %s: no looped PDTCH message,
sending empty\n",
-gsm_lchan_name(lchan), osmo_dump_gsmtime(tm));
+ LOGPGT(DL1P, LOGL_NOTICE, tm, "%s: no looped PDTCH message,
sending empty\n",
+gsm_lchan_name(lchan));
/* empty downlink message */
p = msgb_put(msg, GSM_MACBLOCK_LEN);
memset(p, 0, GSM_MACBLOCK_LEN);
} else {
- LOGP(DL1P, LOGL_NOTICE, "%s %s: looped PDTCH message of %u
bytes\n",
-gsm_lchan_name(lchan), osmo_dump_gsmtime(tm),
msgb_l2len(loop_msg));
+ LOGPGT(DL1P, LOGL_NOTICE, tm, "%s: looped PDTCH message of %u
bytes\n",
+gsm_lchan_name(lchan), msgb_l2len(loop_msg));
/* copy over data from queued response message */
p = msgb_put(msg, msgb_l2len(loop_msg));
memcpy(p, msgb_l2(loo
[PATCH] osmo-bts[master]: Introduce + use LOG/DEBUGP with frame number prefixing/printing
Review at https://gerrit.osmocom.org/6676
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
---
M include/osmo-bts/logging.h
M src/common/l1sap.c
M src/osmo-bts-litecell15/l1_if.c
M src/osmo-bts-litecell15/tch.c
M src/osmo-bts-octphy/l1_if.c
M src/osmo-bts-octphy/l1_tch.c
M src/osmo-bts-sysmo/l1_if.c
M src/osmo-bts-sysmo/tch.c
M src/osmo-bts-virtual/l1_if.c
9 files changed, 118 insertions(+), 125 deletions(-)
git pull ssh://gerrit.osmocom.org:29418/osmo-bts refs/changes/76/6676/1
diff --git a/include/osmo-bts/logging.h b/include/osmo-bts/logging.h
index b1b44d5..68f379c 100644
--- a/include/osmo-bts/logging.h
+++ b/include/osmo-bts/logging.h
@@ -27,4 +27,16 @@
int bts_log_init(const char *category_mask);
+/* LOGP with gsm_time prefix */
+#define LOGPGT(ss, lvl, gt, fmt, args...) \
+ LOGP(ss, lvl, "%s " fmt, osmo_dump_gsmtime(gt), ## args)
+#define DEBUGPGT(ss, gt, fmt, args...) \
+ LOGP(ss, LOGL_DEBUG, "%s " fmt, osmo_dump_gsmtime(gt), ## args)
+
+/* LOGP with frame number prefix */
+#define LOGPFN(ss, lvl, fn, fmt, args...) \
+ LOGP(ss, lvl, "%s " fmt, gsm_fn_as_gsmtime_str(fn), ## args)
+#define DEBUGPFN(ss, fn, fmt, args...) \
+ LOGP(ss, LOGL_DEBUG, "%s " fmt, gsm_fn_as_gsmtime_str(fn), ## args)
+
#endif /* _LOGGING_H */
diff --git a/src/common/l1sap.c b/src/common/l1sap.c
index 1deee83..01b454c 100644
--- a/src/common/l1sap.c
+++ b/src/common/l1sap.c
@@ -451,13 +451,13 @@
struct gsm_bts_role_bts *btsb = bts->role;
int frames_expired;
- DEBUGP(DL1P, "MPH_INFO time ind %u\n", info_time_ind->fn);
+ DEBUGPFN(DL1P, info_time_ind->fn, "Rx MPH_INFO time ind\n");
/* Calculate and check frame difference */
frames_expired = info_time_ind->fn - btsb->gsm_time.fn;
if (frames_expired > 1) {
if (btsb->gsm_time.fn)
- LOGP(DL1P, LOGL_ERROR,
+ LOGPFN(DL1P, LOGL_ERROR, info_time_ind->fn,
"Invalid condition detected: Frame difference is
%"PRIu32"-%"PRIu32"=%d > 1!\n",
info_time_ind->fn, btsb->gsm_time.fn,
frames_expired);
}
@@ -506,12 +506,13 @@
lchan = get_active_lchan_by_chan_nr(trx, info_meas_ind->chan_nr);
if (!lchan) {
- LOGP(DL1P, LOGL_ERROR, "No lchan for MPH INFO MEAS IND
(chan_nr=%u)\n",
-info_meas_ind->chan_nr);
+ LOGPFN(DL1P, LOGL_ERROR, info_meas_ind->fn,
+ "No lchan for MPH INFO MEAS IND (chan_nr=%u)\n",
info_meas_ind->chan_nr);
return 0;
}
- DEBUGP(DL1P, "%s MPH_INFO meas ind, ta_offs_qbits=%d, ber10k=%d,
inv_rssi=%u\n",
+ DEBUGPFN(DL1P, info_meas_ind->fn,
+ "%s MPH_INFO meas ind, ta_offs_qbits=%d, ber10k=%d,
inv_rssi=%u\n",
gsm_lchan_name(lchan), info_meas_ind->ta_offs_qbits,
info_meas_ind->ber10k, info_meas_ind->inv_rssi);
@@ -546,9 +547,9 @@
switch (info->type) {
case PRIM_INFO_TIME:
if (trx != trx->bts->c0) {
- LOGP(DL1P, LOGL_NOTICE, "BTS model is sending us "
-"PRIM_INFO_TIME for TRX %u, please fix it\n",
-trx->nr);
+ LOGPFN(DL1P, LOGL_NOTICE, info->u.time_ind.fn,
+ "BTS model is sending us PRIM_INFO_TIME for TRX
%u, please fix it\n",
+ trx->nr);
rc = -1;
} else
rc = l1sap_info_time_ind(trx->bts, l1sap,
@@ -654,14 +655,14 @@
/* de-queue response message (loopback) */
loop_msg = msgb_dequeue(&lchan->dl_tch_queue);
if (!loop_msg) {
- LOGP(DL1P, LOGL_NOTICE, "%s %s: no looped PDTCH message,
sending empty\n",
-gsm_lchan_name(lchan), osmo_dump_gsmtime(tm));
+ LOGPGT(DL1P, LOGL_NOTICE, tm, "%s: no looped PDTCH message,
sending empty\n",
+gsm_lchan_name(lchan));
/* empty downlink message */
p = msgb_put(msg, GSM_MACBLOCK_LEN);
memset(p, 0, GSM_MACBLOCK_LEN);
} else {
- LOGP(DL1P, LOGL_NOTICE, "%s %s: looped PDTCH message of %u
bytes\n",
-gsm_lchan_name(lchan), osmo_dump_gsmtime(tm),
msgb_l2len(loop_msg));
+ LOGPGT(DL1P, LOGL_NOTICE, tm, "%s: looped PDTCH message of %u
bytes\n",
+gsm_lchan_name(lchan), msgb_l2len(loop_msg));
/* copy over data from queued response message */
p = msgb_put(msg, msgb_l2len(loop_msg));
memcpy(p, msgb_l2(loop_msg), msgb_l2len(loop_msg));
@@ -693,13 +694,11 @@
gsm_fn2gsmtime(&g_time, fn);
- D
