23 Jul
2022
23 Jul
'22
1:14 p.m.
fixeria has uploaded this change for review. (
https://gerrit.osmocom.org/c/osmocom-bb/+/28744 )
Change subject: trxcon: append trxcon_fsm prefix to l1sched logging
......................................................................
trxcon: append trxcon_fsm prefix to l1sched logging
Change-Id: I26da1a506b02502a3a6a887533c35fb09c13c429
Related: OS#5599, OS#3761
---
M src/host/trxcon/include/osmocom/bb/l1sched/Makefile.am
M src/host/trxcon/include/osmocom/bb/l1sched/l1sched.h
A src/host/trxcon/include/osmocom/bb/l1sched/logging.h
M src/host/trxcon/src/sched_clck.c
M src/host/trxcon/src/sched_lchan_common.c
M src/host/trxcon/src/sched_lchan_pdtch.c
M src/host/trxcon/src/sched_lchan_rach.c
M src/host/trxcon/src/sched_lchan_sch.c
M src/host/trxcon/src/sched_lchan_tchf.c
M src/host/trxcon/src/sched_lchan_tchh.c
M src/host/trxcon/src/sched_lchan_xcch.c
M src/host/trxcon/src/sched_mframe.c
M src/host/trxcon/src/sched_prim.c
M src/host/trxcon/src/sched_trx.c
M src/host/trxcon/src/trxcon.c
15 files changed, 248 insertions(+), 201 deletions(-)
git pull ssh://gerrit.osmocom.org:29418/osmocom-bb refs/changes/44/28744/1
diff --git a/src/host/trxcon/include/osmocom/bb/l1sched/Makefile.am
b/src/host/trxcon/include/osmocom/bb/l1sched/Makefile.am
index 295cc6b..76f54a7 100644
--- a/src/host/trxcon/include/osmocom/bb/l1sched/Makefile.am
+++ b/src/host/trxcon/include/osmocom/bb/l1sched/Makefile.am
@@ -1,3 +1,4 @@
noinst_HEADERS = \
l1sched.h \
+ logging.h \
$(NULL)
diff --git a/src/host/trxcon/include/osmocom/bb/l1sched/l1sched.h
b/src/host/trxcon/include/osmocom/bb/l1sched/l1sched.h
index 2969410..60cd63f 100644
--- a/src/host/trxcon/include/osmocom/bb/l1sched/l1sched.h
+++ b/src/host/trxcon/include/osmocom/bb/l1sched/l1sched.h
@@ -346,6 +346,16 @@
uint8_t offset;
};
+/*! Scheduler configuration */
+struct l1sched_cfg {
+ /*! Logging context callback (returns prefix for messages) */
+ const char *(*log_ctx_cb)(const struct l1sched_state *sched);
+ /*! Logging category for common messages */
+ int log_cat_common;
+ /*! Logging category for data messages */
+ int log_cat_data;
+};
+
/*! One scheduler instance */
struct l1sched_state {
/*! Clock state */
@@ -366,6 +376,8 @@
struct l1sched_ts *ts[TRX_TS_COUNT];
/*! BSIC value learned from SCH bursts */
uint8_t bsic;
+ /*! Scheduler configuration */
+ struct l1sched_cfg cfg;
/*! Some private data */
void *priv;
};
@@ -375,7 +387,8 @@
enum gsm_phys_chan_config config, int tn);
/* Scheduler management functions */
-struct l1sched_state *l1sched_alloc(void *ctx, uint32_t fn_advance, void *priv);
+struct l1sched_state *l1sched_alloc(void *ctx, const struct l1sched_cfg *cfg,
+ uint32_t fn_advance, void *priv);
void l1sched_reset(struct l1sched_state *sched, bool reset_clock);
void l1sched_free(struct l1sched_state *sched);
diff --git a/src/host/trxcon/include/osmocom/bb/l1sched/logging.h
b/src/host/trxcon/include/osmocom/bb/l1sched/logging.h
new file mode 100644
index 0000000..d2d8ebf
--- /dev/null
+++ b/src/host/trxcon/include/osmocom/bb/l1sched/logging.h
@@ -0,0 +1,31 @@
+#pragma once
+
+/* Messages using l1sched_state as the context */
+#define LOGP_SCHED_CAT(sched, cat, level, fmt, args...) \
+ LOGP((sched)->cfg.log_cat_##cat, level, "%s" fmt, \
+ (sched)->cfg.log_ctx_cb(sched), ## args)
+
+/* Common messages using l1sched_state as the context */
+#define LOGP_SCHEDC(sched, level, fmt, args...) \
+ LOGP_SCHED_CAT(sched, common, level, fmt, ## args)
+
+/* Data messages using l1sched_state as the context */
+#define LOGP_SCHEDD(sched, level, fmt, args...) \
+ LOGP_SCHED_CAT(sched, common, level, fmt, ## args)
+
+
+#define LOGP_LCHAN_NAME_ARGS(lchan) \
+ (lchan)->ts->index, l1sched_lchan_desc[(lchan)->type].name
+
+/* Messages using l1sched_lchan_state as the context */
+#define LOGP_LCHAN_CAT(lchan, cat, level, fmt, args...) \
+ LOGP_SCHED_CAT((lchan)->ts->sched, cat, level, "TS%u-%s " fmt, \
+ LOGP_LCHAN_NAME_ARGS(lchan), ## args)
+
+/* Common messages using l1sched_lchan_state as the context */
+#define LOGP_LCHANC(lchan, level, fmt, args...) \
+ LOGP_LCHAN_CAT(lchan, common, level, fmt, ## args)
+
+/* Data messages using l1sched_lchan_state as the context */
+#define LOGP_LCHAND(lchan, level, fmt, args...) \
+ LOGP_LCHAN_CAT(lchan, data, level, fmt, ## args)
diff --git a/src/host/trxcon/src/sched_clck.c b/src/host/trxcon/src/sched_clck.c
index 27e8eb9..a3d75fc 100644
--- a/src/host/trxcon/src/sched_clck.c
+++ b/src/host/trxcon/src/sched_clck.c
@@ -30,13 +30,14 @@
#include <inttypes.h>
#include <string.h>
+#include <osmocom/core/logging.h>
#include <osmocom/core/talloc.h>
#include <osmocom/core/msgb.h>
#include <osmocom/core/timer.h>
#include <osmocom/core/timer_compat.h>
#include <osmocom/bb/l1sched/l1sched.h>
-#include <osmocom/bb/trxcon/logging.h>
+#include <osmocom/bb/l1sched/logging.h>
#define MAX_FN_SKEW 50
#define TRX_LOSS_FRAMES 400
@@ -50,7 +51,7 @@
/* Check if transceiver is still alive */
if (sched->fn_counter_lost++ == TRX_LOSS_FRAMES) {
- LOGP(DSCH, LOGL_DEBUG, "No more clock from transceiver\n");
+ LOGP_SCHEDC(sched, LOGL_DEBUG, "No more clock from transceiver\n");
sched->clck_state = L1SCHED_CLCK_ST_WAIT;
return;
@@ -65,8 +66,8 @@
/* If someone played with clock, or if the process stalled */
if (elapsed_us > GSM_TDMA_FN_DURATION_uS * MAX_FN_SKEW || elapsed_us < 0) {
- LOGP(DSCH, LOGL_NOTICE, "PC clock skew: "
- "elapsed uS %" PRId64 "\n", elapsed_us);
+ LOGP_SCHEDC(sched, LOGL_NOTICE, "PC clock skew: "
+ "elapsed uS %" PRId64 "\n", elapsed_us);
sched->clck_state = L1SCHED_CLCK_ST_WAIT;
@@ -123,13 +124,13 @@
if (sched->clck_state == L1SCHED_CLCK_ST_WAIT) {
l1sched_clck_correct(sched, &tv_now, fn);
- LOGP(DSCH, LOGL_DEBUG, "Initial clock received: fn=%u\n", fn);
+ LOGP_SCHEDC(sched, LOGL_DEBUG, "Initial clock received: fn=%u\n", fn);
sched->clck_state = L1SCHED_CLCK_ST_OK;
return 0;
}
- LOGP(DSCH, LOGL_NOTICE, "Clock indication: fn=%u\n", fn);
+ LOGP_SCHEDC(sched, LOGL_NOTICE, "Clock indication: fn=%u\n", fn);
osmo_timer_del(&sched->clock_timer);
@@ -143,15 +144,15 @@
/* Check for max clock skew */
if (elapsed_fn > MAX_FN_SKEW || elapsed_fn < -MAX_FN_SKEW) {
- LOGP(DSCH, LOGL_NOTICE, "GSM clock skew: old fn=%u, "
- "new fn=%u\n", sched->fn_counter_proc, fn);
+ LOGP_SCHEDC(sched, LOGL_NOTICE, "GSM clock skew: old fn=%u, "
+ "new fn=%u\n", sched->fn_counter_proc, fn);
l1sched_clck_correct(sched, &tv_now, fn);
return 0;
}
- LOGP(DSCH, LOGL_INFO, "GSM clock jitter: %" PRId64 "\n",
- elapsed_fn * GSM_TDMA_FN_DURATION_uS - elapsed_us);
+ LOGP_SCHEDC(sched, LOGL_INFO, "GSM clock jitter: %" PRId64 "\n",
+ elapsed_fn * GSM_TDMA_FN_DURATION_uS - elapsed_us);
/* Too many frames have been processed already */
if (elapsed_fn < 0) {
diff --git a/src/host/trxcon/src/sched_lchan_common.c
b/src/host/trxcon/src/sched_lchan_common.c
index 5d5ef6d..6fe5b2e 100644
--- a/src/host/trxcon/src/sched_lchan_common.c
+++ b/src/host/trxcon/src/sched_lchan_common.c
@@ -36,7 +36,7 @@
#include <osmocom/gsm/protocol/gsm_08_58.h>
#include <osmocom/bb/l1sched/l1sched.h>
-#include <osmocom/bb/trxcon/logging.h>
+#include <osmocom/bb/l1sched/logging.h>
/* GSM 05.02 Chapter 5.2.3 Normal Burst (NB) */
const uint8_t l1sched_nb_training_bits[8][26] = {
@@ -122,10 +122,10 @@
/* FIXME: AMR is not implemented yet */
return 0;
case GSM48_CMODE_SIGN:
- LOGP(DSCH, LOGL_ERROR, "BFI is not allowed in signalling mode\n");
+ LOGP_LCHAND(lchan, LOGL_ERROR, "BFI is not allowed in signalling mode\n");
return 0;
default:
- LOGP(DSCH, LOGL_ERROR, "Invalid TCH mode: %u\n", lchan->tch_mode);
+ LOGP_LCHAND(lchan, LOGL_ERROR, "Invalid TCH mode: %u\n",
lchan->tch_mode);
return 0;
}
}
diff --git a/src/host/trxcon/src/sched_lchan_pdtch.c
b/src/host/trxcon/src/sched_lchan_pdtch.c
index 9cad53a..0ef4573 100644
--- a/src/host/trxcon/src/sched_lchan_pdtch.c
+++ b/src/host/trxcon/src/sched_lchan_pdtch.c
@@ -31,25 +31,22 @@
#include <osmocom/coding/gsm0503_coding.h>
#include <osmocom/bb/l1sched/l1sched.h>
-#include <osmocom/bb/trxcon/logging.h>
+#include <osmocom/bb/l1sched/logging.h>
int rx_pdtch_fn(struct l1sched_lchan_state *lchan,
uint32_t fn, uint8_t bid, const sbit_t *bits,
const struct l1sched_meas_set *meas)
{
- const struct l1sched_lchan_desc *lchan_desc;
uint8_t l2[GPRS_L2_MAX_LEN], *mask;
int n_errors, n_bits_total, rc;
sbit_t *buffer, *offset;
size_t l2_len;
/* Set up pointers */
- lchan_desc = &l1sched_lchan_desc[lchan->type];
mask = &lchan->rx_burst_mask;
buffer = lchan->rx_bursts;
- LOGP(DSCHD, LOGL_DEBUG, "Packet data received on %s: "
- "fn=%u ts=%u bid=%u\n", lchan_desc->name, fn, lchan->ts->index,
bid);
+ LOGP_LCHAND(lchan, LOGL_DEBUG, "Packet data received: fn=%u bid=%u\n", fn,
bid);
/* Align to the first burst of a block */
if (*mask == 0x00 && bid != 0)
@@ -75,12 +72,11 @@
/* Check for complete set of bursts */
if ((*mask & 0xf) != 0xf) {
- LOGP(DSCHD, LOGL_ERROR, "Received incomplete (%s) data frame at "
- "fn=%u (%u/%u) for %s\n",
- l1sched_burst_mask2str(mask, 4), lchan->meas_avg.fn,
- lchan->meas_avg.fn % lchan->ts->mf_layout->period,
- lchan->ts->mf_layout->period,
- lchan_desc->name);
+ LOGP_LCHAND(lchan, LOGL_ERROR,
+ "Received incomplete (%s) packet data at fn=%u (%u/%u)\n",
+ l1sched_burst_mask2str(mask, 4), lchan->meas_avg.fn,
+ lchan->meas_avg.fn % lchan->ts->mf_layout->period,
+ lchan->ts->mf_layout->period);
/* NOTE: do not abort here, give it a try. Maybe we're lucky ;) */
}
@@ -91,8 +87,9 @@
rc = gsm0503_pdtch_decode(l2, buffer,
NULL, &n_errors, &n_bits_total);
if (rc < 0) {
- LOGP(DSCHD, LOGL_ERROR, "Received bad %s frame (rc=%d, ber=%d/%d) at
fn=%u\n",
- lchan_desc->name, rc, n_errors, n_bits_total, lchan->meas_avg.fn);
+ LOGP_LCHAND(lchan, LOGL_ERROR,
+ "Received bad frame (rc=%d, ber=%d/%d) at fn=%u\n",
+ rc, n_errors, n_bits_total, lchan->meas_avg.fn);
}
/* Determine L2 length */
@@ -108,14 +105,12 @@
int tx_pdtch_fn(struct l1sched_lchan_state *lchan,
struct l1sched_burst_req *br)
{
- const struct l1sched_lchan_desc *lchan_desc;
ubit_t *buffer, *offset;
const uint8_t *tsc;
uint8_t *mask;
int rc;
/* Set up pointers */
- lchan_desc = &l1sched_lchan_desc[lchan->type];
mask = &lchan->tx_burst_mask;
buffer = lchan->tx_bursts;
@@ -131,9 +126,9 @@
rc = gsm0503_pdtch_encode(buffer, lchan->prim->payload,
lchan->prim->payload_len);
if (rc < 0) {
- LOGP(DSCHD, LOGL_ERROR, "Failed to encode L2 payload (len=%zu): %s\n",
- lchan->prim->payload_len, osmo_hexdump(lchan->prim->payload,
- lchan->prim->payload_len));
+ LOGP_LCHAND(lchan, LOGL_ERROR, "Failed to encode L2 payload (len=%zu):
%s\n",
+ lchan->prim->payload_len, osmo_hexdump(lchan->prim->payload,
+ lchan->prim->payload_len));
/* Forget this primitive */
l1sched_prim_drop(lchan);
@@ -159,8 +154,7 @@
memset(br->burst + 145, 0, 3); /* TB */
br->burst_len = GSM_BURST_LEN;
- LOGP(DSCHD, LOGL_DEBUG, "Scheduled %s fn=%u ts=%u burst=%u\n",
- lchan_desc->name, br->fn, lchan->ts->index, br->bid);
+ LOGP_LCHAND(lchan, LOGL_DEBUG, "Scheduled at fn=%u burst=%u\n", br->fn,
br->bid);
/* If we have sent the last (4/4) burst */
if ((*mask & 0x0f) == 0x0f) {
diff --git a/src/host/trxcon/src/sched_lchan_rach.c
b/src/host/trxcon/src/sched_lchan_rach.c
index e5944c6..e7422b2 100644
--- a/src/host/trxcon/src/sched_lchan_rach.c
+++ b/src/host/trxcon/src/sched_lchan_rach.c
@@ -31,7 +31,7 @@
#include <osmocom/coding/gsm0503_coding.h>
#include <osmocom/bb/l1sched/l1sched.h>
-#include <osmocom/bb/trxcon/logging.h>
+#include <osmocom/bb/l1sched/logging.h>
/* 3GPP TS 05.02, section 5.2.7 "Access burst (AB)" */
#define RACH_EXT_TAIL_BITS_LEN 8
@@ -88,8 +88,9 @@
if (L1SCHED_PRIM_IS_RACH11(lchan->prim)) {
/* Check requested synch. sequence */
if (rach->synch_seq >= RACH_SYNCH_SEQ_NUM) {
- LOGP(DSCHD, LOGL_ERROR, "Unknown RACH synch. sequence=0x%02x\n",
- rach->synch_seq);
+ LOGP_LCHAND(lchan, LOGL_ERROR,
+ "Unknown RACH synch. sequence=0x%02x\n",
+ rach->synch_seq);
/* Forget this primitive */
l1sched_prim_drop(lchan);
@@ -99,8 +100,9 @@
/* Encode extended (11-bit) payload */
rc = gsm0503_rach_ext_encode(payload, rach->ra, bsic, true);
if (rc) {
- LOGP(DSCHD, LOGL_ERROR, "Could not encode extended RACH burst "
- "(ra=%u bsic=%u)\n", rach->ra, bsic);
+ LOGP_LCHAND(lchan, LOGL_ERROR,
+ "Could not encode extended RACH burst (ra=%u bsic=%u)\n",
+ rach->ra, bsic);
/* Forget this primitive */
l1sched_prim_drop(lchan);
@@ -112,16 +114,18 @@
/* Encode regular (8-bit) payload */
rc = gsm0503_rach_ext_encode(payload, rach->ra, bsic, false);
if (rc) {
- LOGP(DSCHD, LOGL_ERROR, "Could not encode RACH burst "
- "(ra=%u bsic=%u)\n", rach->ra, bsic);
+ LOGP_LCHAND(lchan, LOGL_ERROR,
+ "Could not encode RACH burst (ra=%u bsic=%u)\n",
+ rach->ra, bsic);
/* Forget this primitive */
l1sched_prim_drop(lchan);
return rc;
}
} else {
- LOGP(DSCHD, LOGL_ERROR, "Primitive has unexpected "
- "type=0x%02x\n", lchan->prim->type);
+ LOGP_LCHAND(lchan, LOGL_ERROR,
+ "Primitive has unexpected type=0x%02x\n",
+ lchan->prim->type);
l1sched_prim_drop(lchan);
return -EINVAL;
}
@@ -143,10 +147,9 @@
memset(burst_ptr, 0, br->burst + GSM_BURST_LEN - burst_ptr);
br->burst_len = GSM_BURST_LEN;
- LOGP(DSCHD, LOGL_NOTICE, "Scheduled %s RACH (%s) on fn=%u, tn=%u,
lchan=%s\n",
- L1SCHED_PRIM_IS_RACH11(lchan->prim) ? "extended (11-bit)" : "regular
(8-bit)",
- get_value_string(rach_synch_seq_names, rach->synch_seq), br->fn,
- lchan->ts->index, l1sched_lchan_desc[lchan->type].name);
+ LOGP_LCHAND(lchan, LOGL_NOTICE, "Scheduled %s RACH (%s) at fn=%u\n",
+ L1SCHED_PRIM_IS_RACH11(lchan->prim) ? "extended (11-bit)" :
"regular (8-bit)",
+ get_value_string(rach_synch_seq_names, rach->synch_seq), br->fn);
/* Confirm RACH request */
l1sched_handle_data_cnf(lchan, br->fn, L1SCHED_DT_OTHER);
diff --git a/src/host/trxcon/src/sched_lchan_sch.c
b/src/host/trxcon/src/sched_lchan_sch.c
index 235e64c..c61e134 100644
--- a/src/host/trxcon/src/sched_lchan_sch.c
+++ b/src/host/trxcon/src/sched_lchan_sch.c
@@ -33,7 +33,7 @@
#include <osmocom/coding/gsm0503_coding.h>
#include <osmocom/bb/l1sched/l1sched.h>
-#include <osmocom/bb/trxcon/logging.h>
+#include <osmocom/bb/l1sched/logging.h>
static void decode_sb(struct gsm_time *time, uint8_t *bsic, uint8_t *sb_info)
{
@@ -78,20 +78,21 @@
/* Attempt to decode */
rc = gsm0503_sch_decode(sb_info, payload);
if (rc) {
- LOGP(DSCHD, LOGL_ERROR, "Received bad SCH burst at fn=%u\n", fn);
+ LOGP_LCHAND(lchan, LOGL_ERROR, "Received bad SCH burst at fn=%u\n", fn);
return rc;
}
/* Decode BSIC and TDMA frame number */
decode_sb(&time, &bsic, sb_info);
- LOGP(DSCHD, LOGL_DEBUG, "Received SCH: bsic=%u, fn=%u, sched_fn=%u\n",
+ LOGP_LCHAND(lchan, LOGL_DEBUG, "Received SCH: bsic=%u, fn=%u, sched_fn=%u\n",
bsic, time.fn, lchan->ts->sched->fn_counter_proc);
/* Check if decoded frame number matches */
if (time.fn != fn) {
- LOGP(DSCHD, LOGL_ERROR, "Decoded fn=%u does not match "
- "fn=%u provided by scheduler\n", time.fn, fn);
+ LOGP_LCHAND(lchan, LOGL_ERROR,
+ "Decoded fn=%u does not match fn=%u provided by scheduler\n",
+ time.fn, fn);
return -EINVAL;
}
diff --git a/src/host/trxcon/src/sched_lchan_tchf.c
b/src/host/trxcon/src/sched_lchan_tchf.c
index 8349193..1a1b93d 100644
--- a/src/host/trxcon/src/sched_lchan_tchf.c
+++ b/src/host/trxcon/src/sched_lchan_tchf.c
@@ -33,25 +33,22 @@
#include <osmocom/codec/codec.h>
#include <osmocom/bb/l1sched/l1sched.h>
-#include <osmocom/bb/trxcon/logging.h>
+#include <osmocom/bb/l1sched/logging.h>
int rx_tchf_fn(struct l1sched_lchan_state *lchan,
uint32_t fn, uint8_t bid, const sbit_t *bits,
const struct l1sched_meas_set *meas)
{
- const struct l1sched_lchan_desc *lchan_desc;
int n_errors = -1, n_bits_total, rc;
sbit_t *buffer, *offset;
uint8_t l2[128], *mask;
size_t l2_len;
/* Set up pointers */
- lchan_desc = &l1sched_lchan_desc[lchan->type];
mask = &lchan->rx_burst_mask;
buffer = lchan->rx_bursts;
- LOGP(DSCHD, LOGL_DEBUG, "Traffic received on %s: fn=%u ts=%u bid=%u\n",
- lchan_desc->name, fn, lchan->ts->index, bid);
+ LOGP_LCHAND(lchan, LOGL_DEBUG, "Traffic received: fn=%u bid=%u\n", fn, bid);
/* Align to the first burst of a block */
if (*mask == 0x00 && bid != 0)
@@ -77,12 +74,11 @@
/* Check for complete set of bursts */
if ((*mask & 0xff) != 0xff) {
- LOGP(DSCHD, LOGL_ERROR, "Received incomplete (%s) traffic frame at "
- "fn=%u (%u/%u) for %s\n",
- l1sched_burst_mask2str(mask, 8), lchan->meas_avg.fn,
- lchan->meas_avg.fn % lchan->ts->mf_layout->period,
- lchan->ts->mf_layout->period,
- lchan_desc->name);
+ LOGP_LCHAND(lchan, LOGL_ERROR,
+ "Received incomplete (%s) traffic frame at fn=%u (%u/%u)\n",
+ l1sched_burst_mask2str(mask, 8), lchan->meas_avg.fn,
+ lchan->meas_avg.fn % lchan->ts->mf_layout->period,
+ lchan->ts->mf_layout->period);
/* NOTE: do not abort here, give it a try. Maybe we're lucky ;) */
}
@@ -105,10 +101,10 @@
* TODO: AMR requires a dedicated loop,
* which will be implemented later...
*/
- LOGP(DSCHD, LOGL_ERROR, "AMR isn't supported yet\n");
+ LOGP_LCHAND(lchan, LOGL_ERROR, "AMR isn't supported yet\n");
return -ENOTSUP;
default:
- LOGP(DSCHD, LOGL_ERROR, "Invalid TCH mode: %u\n", lchan->tch_mode);
+ LOGP_LCHAND(lchan, LOGL_ERROR, "Invalid TCH mode: %u\n",
lchan->tch_mode);
return -EINVAL;
}
@@ -117,8 +113,9 @@
/* Check decoding result */
if (rc < 4) {
- LOGP(DSCHD, LOGL_ERROR, "Received bad %s frame (rc=%d, ber=%d/%d) at
fn=%u\n",
- lchan_desc->name, rc, n_errors, n_bits_total, lchan->meas_avg.fn);
+ LOGP_LCHAND(lchan, LOGL_ERROR,
+ "Received bad frame (rc=%d, ber=%d/%d) at fn=%u\n",
+ rc, n_errors, n_bits_total, lchan->meas_avg.fn);
/* Send BFI */
goto bfi;
@@ -171,7 +168,6 @@
int tx_tchf_fn(struct l1sched_lchan_state *lchan,
struct l1sched_burst_req *br)
{
- const struct l1sched_lchan_desc *lchan_desc;
ubit_t *buffer, *offset;
const uint8_t *tsc;
uint8_t *mask;
@@ -179,7 +175,6 @@
int rc;
/* Set up pointers */
- lchan_desc = &l1sched_lchan_desc[lchan->type];
mask = &lchan->tx_burst_mask;
buffer = lchan->tx_bursts;
@@ -205,16 +200,17 @@
* TODO: AMR requires a dedicated loop,
* which will be implemented later...
*/
- LOGP(DSCHD, LOGL_ERROR, "AMR isn't supported yet, "
- "dropping frame...\n");
+ LOGP_LCHAND(lchan, LOGL_ERROR,
+ "AMR isn't supported yet, dropping frame...\n");
/* Forget this primitive */
l1sched_prim_drop(lchan);
return -ENOTSUP;
default:
- LOGP(DSCHD, LOGL_ERROR, "Invalid TCH mode: %u, "
- "dropping frame...\n", lchan->tch_mode);
+ LOGP_LCHAND(lchan, LOGL_ERROR,
+ "Invalid TCH mode: %u, dropping frame...\n",
+ lchan->tch_mode);
/* Forget this primitive */
l1sched_prim_drop(lchan);
@@ -226,9 +222,9 @@
if (lchan->prim->payload_len == GSM_MACBLOCK_LEN) {
l2_len = GSM_MACBLOCK_LEN; /* FACCH */
} else if (lchan->prim->payload_len != l2_len) {
- LOGP(DSCHD, LOGL_ERROR, "Primitive has odd length %zu "
- "(expected %zu for TCH or %u for FACCH), so dropping...\n",
- lchan->prim->payload_len, l2_len, GSM_MACBLOCK_LEN);
+ LOGP_LCHAND(lchan, LOGL_ERROR, "Primitive has odd length %zu "
+ "(expected %zu for TCH or %u for FACCH), so dropping...\n",
+ lchan->prim->payload_len, l2_len, GSM_MACBLOCK_LEN);
l1sched_prim_drop(lchan);
return -EINVAL;
@@ -240,9 +236,9 @@
/* Encode payload */
rc = gsm0503_tch_fr_encode(buffer, lchan->prim->payload, l2_len, 1);
if (rc) {
- LOGP(DSCHD, LOGL_ERROR, "Failed to encode L2 payload (len=%zu): %s\n",
- lchan->prim->payload_len, osmo_hexdump(lchan->prim->payload,
- lchan->prim->payload_len));
+ LOGP_LCHAND(lchan, LOGL_ERROR, "Failed to encode L2 payload (len=%zu):
%s\n",
+ lchan->prim->payload_len, osmo_hexdump(lchan->prim->payload,
+ lchan->prim->payload_len));
/* Forget this primitive */
l1sched_prim_drop(lchan);
@@ -268,8 +264,7 @@
memset(br->burst + 145, 0, 3); /* TB */
br->burst_len = GSM_BURST_LEN;
- LOGP(DSCHD, LOGL_DEBUG, "Scheduled %s fn=%u ts=%u burst=%u\n",
- lchan_desc->name, br->fn, lchan->ts->index, br->bid);
+ LOGP_LCHAND(lchan, LOGL_DEBUG, "Scheduled fn=%u burst=%u\n", br->fn,
br->bid);
/* If we have sent the last (4/4) burst */
if (*mask == 0x0f) {
diff --git a/src/host/trxcon/src/sched_lchan_tchh.c
b/src/host/trxcon/src/sched_lchan_tchh.c
index de9c047..b0bc566 100644
--- a/src/host/trxcon/src/sched_lchan_tchh.c
+++ b/src/host/trxcon/src/sched_lchan_tchh.c
@@ -36,7 +36,7 @@
#include <osmocom/codec/codec.h>
#include <osmocom/bb/l1sched/l1sched.h>
-#include <osmocom/bb/trxcon/logging.h>
+#include <osmocom/bb/l1sched/logging.h>
static const uint8_t tch_h0_traffic_block_map[3][4] = {
/* B0(0,2,4,6), B1(4,6,8,10), B2(8,10,0,2) */
@@ -182,10 +182,11 @@
BLOCK_FIRST_FN(tch_h1_traffic_block_map);
}
- LOGP(DSCHD, LOGL_ERROR, "Failed to calculate TDMA "
- "frame number of the first burst of %s block, "
- "using the current fn=%u\n", facch ?
- "FACCH/H" : "TCH/H", last_fn);
+#if 0
+ LOGP_LCHAND(lchan, LOGL_ERROR,
+ "Failed to calculate TDMA frame number of the first burst of %s block, "
+ "using the current fn=%u\n", facch ? "FACCH/H" :
"TCH/H", last_fn);
+#endif
/* Couldn't calculate the first fn, return the last */
return last_fn;
@@ -195,19 +196,16 @@
uint32_t fn, uint8_t bid, const sbit_t *bits,
const struct l1sched_meas_set *meas)
{
- const struct l1sched_lchan_desc *lchan_desc;
int n_errors = -1, n_bits_total, rc;
sbit_t *buffer, *offset;
uint8_t l2[128], *mask;
size_t l2_len;
/* Set up pointers */
- lchan_desc = &l1sched_lchan_desc[lchan->type];
mask = &lchan->rx_burst_mask;
buffer = lchan->rx_bursts;
- LOGP(DSCHD, LOGL_DEBUG, "Traffic received on %s: fn=%u ts=%u bid=%u\n",
- lchan_desc->name, fn, lchan->ts->index, bid);
+ LOGP_LCHAND(lchan, LOGL_DEBUG, "Traffic received: fn=%u bid=%u\n", fn, bid);
if (*mask == 0x00) {
/* Align to the first burst */
@@ -268,10 +266,10 @@
* TODO: AMR requires a dedicated loop,
* which will be implemented later...
*/
- LOGP(DSCHD, LOGL_ERROR, "AMR isn't supported yet\n");
+ LOGP_LCHAND(lchan, LOGL_ERROR, "AMR isn't supported yet\n");
return -ENOTSUP;
default:
- LOGP(DSCHD, LOGL_ERROR, "Invalid TCH mode: %u\n", lchan->tch_mode);
+ LOGP_LCHAND(lchan, LOGL_ERROR, "Invalid TCH mode: %u\n",
lchan->tch_mode);
return -EINVAL;
}
@@ -287,8 +285,9 @@
/* Calculate AVG of the measurements (assuming 4 bursts) */
l1sched_lchan_meas_avg(lchan, 4);
- LOGP(DSCHD, LOGL_ERROR, "Received bad %s frame (rc=%d, ber=%d/%d) at
fn=%u\n",
- lchan_desc->name, rc, n_errors, n_bits_total, lchan->meas_avg.fn);
+ LOGP_LCHAND(lchan, LOGL_ERROR,
+ "Received bad frame (rc=%d, ber=%d/%d) at fn=%u\n",
+ rc, n_errors, n_bits_total, lchan->meas_avg.fn);
/* Send BFI */
goto bfi;
@@ -360,7 +359,6 @@
int tx_tchh_fn(struct l1sched_lchan_state *lchan,
struct l1sched_burst_req *br)
{
- const struct l1sched_lchan_desc *lchan_desc;
ubit_t *buffer, *offset;
const uint8_t *tsc;
uint8_t *mask;
@@ -368,7 +366,6 @@
int rc;
/* Set up pointers */
- lchan_desc = &l1sched_lchan_desc[lchan->type];
mask = &lchan->tx_burst_mask;
buffer = lchan->tx_bursts;
@@ -409,15 +406,16 @@
* TODO: AMR requires a dedicated loop,
* which will be implemented later...
*/
- LOGP(DSCHD, LOGL_ERROR, "AMR isn't supported yet, "
- "dropping frame...\n");
+ LOGP_LCHAND(lchan, LOGL_ERROR,
+ "AMR isn't supported yet, dropping frame...\n");
/* Forget this primitive */
l1sched_prim_drop(lchan);
return -ENOTSUP;
default:
- LOGP(DSCHD, LOGL_ERROR, "Invalid TCH mode: %u, "
- "dropping frame...\n", lchan->tch_mode);
+ LOGP_LCHAND(lchan, LOGL_ERROR,
+ "Invalid TCH mode: %u, dropping frame...\n",
+ lchan->tch_mode);
/* Forget this primitive */
l1sched_prim_drop(lchan);
@@ -428,9 +426,9 @@
if (L1SCHED_PRIM_IS_FACCH(lchan->prim)) {
l2_len = GSM_MACBLOCK_LEN; /* FACCH */
} else if (lchan->prim->payload_len != l2_len) {
- LOGP(DSCHD, LOGL_ERROR, "Primitive has odd length %zu "
- "(expected %zu for TCH or %u for FACCH), so dropping...\n",
- lchan->prim->payload_len, l2_len, GSM_MACBLOCK_LEN);
+ LOGP_LCHAND(lchan, LOGL_ERROR, "Primitive has odd length %zu "
+ "(expected %zu for TCH or %u for FACCH), so dropping...\n",
+ lchan->prim->payload_len, l2_len, GSM_MACBLOCK_LEN);
/* Forget this primitive */
l1sched_prim_drop(lchan);
@@ -440,9 +438,9 @@
/* Encode the payload */
rc = gsm0503_tch_hr_encode(buffer, lchan->prim->payload, l2_len);
if (rc) {
- LOGP(DSCHD, LOGL_ERROR, "Failed to encode L2 payload (len=%zu): %s\n",
- lchan->prim->payload_len, osmo_hexdump(lchan->prim->payload,
- lchan->prim->payload_len));
+ LOGP_LCHAND(lchan, LOGL_ERROR, "Failed to encode L2 payload (len=%zu):
%s\n",
+ lchan->prim->payload_len, osmo_hexdump(lchan->prim->payload,
+ lchan->prim->payload_len));
/* Forget this primitive */
l1sched_prim_drop(lchan);
@@ -471,8 +469,7 @@
memset(br->burst + 145, 0, 3); /* TB */
br->burst_len = GSM_BURST_LEN;
- LOGP(DSCHD, LOGL_DEBUG, "Scheduled %s fn=%u ts=%u burst=%u\n",
- lchan_desc->name, br->fn, lchan->ts->index, br->bid);
+ LOGP_LCHAND(lchan, LOGL_DEBUG, "Scheduled fn=%u burst=%u\n", br->fn,
br->bid);
/* In case of a FACCH/H frame, one block less */
if (lchan->ul_facch_blocks)
diff --git a/src/host/trxcon/src/sched_lchan_xcch.c
b/src/host/trxcon/src/sched_lchan_xcch.c
index e677764..0d24866 100644
--- a/src/host/trxcon/src/sched_lchan_xcch.c
+++ b/src/host/trxcon/src/sched_lchan_xcch.c
@@ -31,24 +31,21 @@
#include <osmocom/coding/gsm0503_coding.h>
#include <osmocom/bb/l1sched/l1sched.h>
-#include <osmocom/bb/trxcon/logging.h>
+#include <osmocom/bb/l1sched/logging.h>
int rx_data_fn(struct l1sched_lchan_state *lchan,
uint32_t fn, uint8_t bid, const sbit_t *bits,
const struct l1sched_meas_set *meas)
{
- const struct l1sched_lchan_desc *lchan_desc;
uint8_t l2[GSM_MACBLOCK_LEN], *mask;
int n_errors, n_bits_total, rc;
sbit_t *buffer, *offset;
/* Set up pointers */
- lchan_desc = &l1sched_lchan_desc[lchan->type];
mask = &lchan->rx_burst_mask;
buffer = lchan->rx_bursts;
- LOGP(DSCHD, LOGL_DEBUG, "Data received on %s: fn=%u ts=%u bid=%u\n",
- lchan_desc->name, fn, lchan->ts->index, bid);
+ LOGP_LCHAND(lchan, LOGL_DEBUG, "Data received: fn=%u bid=%u\n", fn, bid);
/* Align to the first burst of a block */
if (*mask == 0x00 && bid != 0)
@@ -74,12 +71,11 @@
/* Check for complete set of bursts */
if ((*mask & 0xf) != 0xf) {
- LOGP(DSCHD, LOGL_ERROR, "Received incomplete (%s) data frame at "
- "fn=%u (%u/%u) for %s\n",
- l1sched_burst_mask2str(mask, 4), lchan->meas_avg.fn,
- lchan->meas_avg.fn % lchan->ts->mf_layout->period,
- lchan->ts->mf_layout->period,
- lchan_desc->name);
+ LOGP_LCHAND(lchan, LOGL_ERROR,
+ "Received incomplete (%s) data frame at fn=%u (%u/%u)\n",
+ l1sched_burst_mask2str(mask, 4), lchan->meas_avg.fn,
+ lchan->meas_avg.fn % lchan->ts->mf_layout->period,
+ lchan->ts->mf_layout->period);
/* NOTE: xCCH has an insane amount of redundancy for error
* correction, so even just 2 valid bursts might be enough
* to reconstruct some L2 frames. This is why we do not
@@ -92,8 +88,9 @@
/* Attempt to decode */
rc = gsm0503_xcch_decode(l2, buffer, &n_errors, &n_bits_total);
if (rc) {
- LOGP(DSCHD, LOGL_ERROR, "Received bad %s frame (rc=%d, ber=%d/%d) at
fn=%u\n",
- lchan_desc->name, rc, n_errors, n_bits_total, lchan->meas_avg.fn);
+ LOGP_LCHAND(lchan, LOGL_ERROR,
+ "Received bad frame (rc=%d, ber=%d/%d) at fn=%u\n",
+ rc, n_errors, n_bits_total, lchan->meas_avg.fn);
}
/* Send a L2 frame to the higher layers */
@@ -105,14 +102,12 @@
int tx_data_fn(struct l1sched_lchan_state *lchan,
struct l1sched_burst_req *br)
{
- const struct l1sched_lchan_desc *lchan_desc;
ubit_t *buffer, *offset;
const uint8_t *tsc;
uint8_t *mask;
int rc;
/* Set up pointers */
- lchan_desc = &l1sched_lchan_desc[lchan->type];
mask = &lchan->tx_burst_mask;
buffer = lchan->tx_bursts;
@@ -126,8 +121,9 @@
/* Check the prim payload length */
if (lchan->prim->payload_len != GSM_MACBLOCK_LEN) {
- LOGP(DSCHD, LOGL_ERROR, "Primitive has odd length %zu (expected %u), "
- "so dropping...\n", lchan->prim->payload_len, GSM_MACBLOCK_LEN);
+ LOGP_LCHAND(lchan, LOGL_ERROR,
+ "Primitive has odd length %zu (expected %u), so dropping...\n",
+ lchan->prim->payload_len, GSM_MACBLOCK_LEN);
l1sched_prim_drop(lchan);
return -EINVAL;
@@ -136,9 +132,9 @@
/* Encode payload */
rc = gsm0503_xcch_encode(buffer, lchan->prim->payload);
if (rc) {
- LOGP(DSCHD, LOGL_ERROR, "Failed to encode L2 payload (len=%zu): %s\n",
- lchan->prim->payload_len, osmo_hexdump(lchan->prim->payload,
- lchan->prim->payload_len));
+ LOGP_LCHAND(lchan, LOGL_ERROR, "Failed to encode L2 payload (len=%zu):
%s\n",
+ lchan->prim->payload_len, osmo_hexdump(lchan->prim->payload,
+ lchan->prim->payload_len));
/* Forget this primitive */
l1sched_prim_drop(lchan);
@@ -164,8 +160,7 @@
memset(br->burst + 145, 0, 3); /* TB */
br->burst_len = GSM_BURST_LEN;
- LOGP(DSCHD, LOGL_DEBUG, "Scheduled %s fn=%u ts=%u burst=%u\n",
- lchan_desc->name, br->fn, lchan->ts->index, br->bid);
+ LOGP_LCHAND(lchan, LOGL_DEBUG, "Scheduled fn=%u burst=%u\n", br->fn,
br->bid);
/* If we have sent the last (4/4) burst */
if ((*mask & 0x0f) == 0x0f) {
diff --git a/src/host/trxcon/src/sched_mframe.c b/src/host/trxcon/src/sched_mframe.c
index e8aa439..90b7763 100644
--- a/src/host/trxcon/src/sched_mframe.c
+++ b/src/host/trxcon/src/sched_mframe.c
@@ -26,6 +26,7 @@
#include <osmocom/gsm/gsm_utils.h>
#include <osmocom/bb/l1sched/l1sched.h>
+#include <osmocom/bb/l1sched/logging.h>
/* Non-combined CCCH */
static const struct l1sched_tdma_frame frame_bcch[51] = {
diff --git a/src/host/trxcon/src/sched_prim.c b/src/host/trxcon/src/sched_prim.c
index 0b1b0df..33d48de 100644
--- a/src/host/trxcon/src/sched_prim.c
+++ b/src/host/trxcon/src/sched_prim.c
@@ -31,7 +31,7 @@
#include <osmocom/gsm/protocol/gsm_04_08.h>
#include <osmocom/bb/l1sched/l1sched.h>
-#include <osmocom/bb/trxcon/logging.h>
+#include <osmocom/bb/l1sched/logging.h>
/**
* Initializes a new primitive by allocating memory
@@ -54,17 +54,16 @@
/* Determine lchan type */
lchan_type = l1sched_chan_nr2lchan_type(chan_nr, link_id);
if (!lchan_type) {
- LOGP(DSCH, LOGL_ERROR, "Couldn't determine lchan type "
- "for chan_nr=%02x and link_id=%02x\n", chan_nr, link_id);
+ /* TODO: use proper logging context */
+ LOGP(DLGLOBAL, LOGL_ERROR, "Couldn't determine lchan type "
+ "for chan_nr=%02x and link_id=%02x\n", chan_nr, link_id);
return NULL;
}
/* Allocate a new primitive */
prim = talloc_zero_size(ctx, sizeof(*prim) + pl_len);
- if (prim == NULL) {
- LOGP(DSCH, LOGL_ERROR, "Failed to allocate memory\n");
+ if (prim == NULL)
return NULL;
- }
/* Init primitive header */
prim->payload_len = pl_len;
@@ -100,7 +99,7 @@
/* Check whether required timeslot is allocated and configured */
ts = sched->ts[tn];
if (ts == NULL || ts->mf_layout == NULL) {
- LOGP(DSCH, LOGL_ERROR, "Timeslot %u isn't configured\n", tn);
+ LOGP_SCHEDC(sched, LOGL_ERROR, "Timeslot %u isn't configured\n", tn);
return NULL;
}
@@ -196,15 +195,15 @@
/* Inform about the cache usage count */
if (cached && lchan->sacch.mr_cache_usage > 5) {
- LOGP(DSCHD, LOGL_NOTICE, "SACCH MR cache usage count=%u > 5 "
- "on lchan=%s => ancient measurements, please fix!\n",
- lchan->sacch.mr_cache_usage,
- l1sched_lchan_desc[lchan->type].name);
+ LOGP_LCHAND(lchan, LOGL_NOTICE,
+ "SACCH MR cache usage count=%u > 5 "
+ "=> ancient measurements, please fix!\n",
+ lchan->sacch.mr_cache_usage);
}
- LOGP(DSCHD, LOGL_NOTICE, "Using a %s Measurement Report "
- "on lchan=%s\n", (cached ? "cached" : "dummy"),
- l1sched_lchan_desc[lchan->type].name);
+ LOGP_LCHAND(lchan, LOGL_NOTICE,
+ "Using a %s Measurement Report\n",
+ cached ? "cached" : "dummy");
return prim;
}
@@ -271,11 +270,9 @@
break; /* something else was found */
}
- LOGP(DSCHD, LOGL_DEBUG, "SACCH MR selection on lchan=%s: "
- "mr_tx_last=%d prim_mr=%p prim_nmr=%p\n",
- l1sched_lchan_desc[lchan->type].name,
- lchan->sacch.mr_tx_last,
- prim_mr, prim_nmr);
+ LOGP_LCHAND(lchan, LOGL_DEBUG,
+ "SACCH MR selection: mr_tx_last=%d prim_mr=%p prim_nmr=%p\n",
+ lchan->sacch.mr_tx_last, prim_mr, prim_nmr);
/* Prioritize non-MR prim if possible */
if (mr_now && prim_mr)
@@ -299,16 +296,14 @@
prim->payload, GSM_MACBLOCK_LEN);
lchan->sacch.mr_cache_usage = 0;
- LOGP(DSCHD, LOGL_DEBUG, "SACCH MR cache has been updated "
- "for lchan=%s\n", l1sched_lchan_desc[lchan->type].name);
+ LOGP_LCHAND(lchan, LOGL_DEBUG, "SACCH MR cache has been updated\n");
}
/* Update the MR transmission state */
lchan->sacch.mr_tx_last = PRIM_IS_MR(prim);
- LOGP(DSCHD, LOGL_DEBUG, "SACCH decision on lchan=%s: %s\n",
- l1sched_lchan_desc[lchan->type].name, PRIM_IS_MR(prim) ?
- "Measurement Report" : "data frame");
+ LOGP_LCHAND(lchan, LOGL_DEBUG, "SACCH decision: %s\n",
+ PRIM_IS_MR(prim) ? "Measurement Report" : "data frame");
return prim;
}
@@ -592,8 +587,7 @@
/* Assign the current prim */
lchan->prim = prim;
- LOGP(DSCHD, LOGL_DEBUG, "Transmitting a dummy / silence frame "
- "on lchan=%s\n", l1sched_lchan_desc[chan].name);
+ LOGP_LCHAND(lchan, LOGL_DEBUG, "Transmitting a dummy / silence frame\n");
return 0;
}
diff --git a/src/host/trxcon/src/sched_trx.c b/src/host/trxcon/src/sched_trx.c
index 443c23d..2e7890e 100644
--- a/src/host/trxcon/src/sched_trx.c
+++ b/src/host/trxcon/src/sched_trx.c
@@ -33,7 +33,7 @@
#include <osmocom/core/linuxlist.h>
#include <osmocom/bb/l1sched/l1sched.h>
-#include <osmocom/bb/trxcon/logging.h>
+#include <osmocom/bb/l1sched/logging.h>
static int l1sched_cfg_pchan_comb_req(struct l1sched_state *sched,
uint8_t tn, enum gsm_phys_chan_config pchan)
@@ -150,21 +150,23 @@
l1sched_handle_burst_req(sched, &br[tn]);
}
-struct l1sched_state *l1sched_alloc(void *ctx, uint32_t fn_advance, void *priv)
+struct l1sched_state *l1sched_alloc(void *ctx, const struct l1sched_cfg *cfg,
+ uint32_t fn_advance, void *priv)
{
struct l1sched_state *sched;
- LOGP(DSCH, LOGL_NOTICE, "Init scheduler\n");
-
sched = talloc(ctx, struct l1sched_state);
if (!sched)
return NULL;
+ OSMO_ASSERT(cfg->log_ctx_cb != NULL);
+
*sched = (struct l1sched_state) {
/* .clock_timer is set up in l1sched_clck_correct() */
.clock_cb = &sched_frame_clck_cb,
.fn_counter_advance = fn_advance,
.priv = priv,
+ .cfg = *cfg,
};
return sched;
@@ -177,7 +179,7 @@
if (sched == NULL)
return;
- LOGP(DSCH, LOGL_NOTICE, "Shutdown scheduler\n");
+ LOGP_SCHEDC(sched, LOGL_NOTICE, "Shutdown scheduler\n");
/* Free all potentially allocated timeslots */
for (tn = 0; tn < ARRAY_SIZE(sched->ts); tn++)
@@ -194,8 +196,8 @@
if (sched == NULL)
return;
- LOGP(DSCH, LOGL_NOTICE, "Reset scheduler %s\n",
- reset_clock ? "and clock counter" : "");
+ LOGP_SCHEDC(sched, LOGL_NOTICE, "Reset scheduler %s\n",
+ reset_clock ? "and clock counter" : "");
/* Free all potentially allocated timeslots */
for (tn = 0; tn < ARRAY_SIZE(sched->ts); tn++)
@@ -210,11 +212,11 @@
{
/* Make sure that ts isn't allocated yet */
if (sched->ts[tn] != NULL) {
- LOGP(DSCH, LOGL_ERROR, "Timeslot #%u already allocated\n", tn);
+ LOGP_SCHEDC(sched, LOGL_ERROR, "Timeslot #%u already allocated\n", tn);
return NULL;
}
- LOGP(DSCH, LOGL_NOTICE, "Add a new TDMA timeslot #%u\n", tn);
+ LOGP_SCHEDC(sched, LOGL_NOTICE, "Add a new TDMA timeslot #%u\n", tn);
sched->ts[tn] = talloc_zero(sched, struct l1sched_ts);
sched->ts[tn]->sched = sched;
@@ -233,7 +235,7 @@
if (ts == NULL)
return;
- LOGP(DSCH, LOGL_NOTICE, "Delete TDMA timeslot #%u\n", tn);
+ LOGP_SCHEDC(sched, LOGL_NOTICE, "Delete TDMA timeslot #%u\n", tn);
/* Deactivate all logical channels */
l1sched_deactivate_all_lchans(ts);
@@ -284,8 +286,9 @@
if (ts->mf_layout->chan_config != config)
return -EINVAL;
- LOGP(DSCH, LOGL_NOTICE, "(Re)configure TDMA timeslot #%u as %s\n",
- tn, ts->mf_layout->name);
+ LOGP_SCHEDC(sched, LOGL_NOTICE,
+ "(Re)configure TDMA timeslot #%u as %s\n",
+ tn, ts->mf_layout->name);
/* Init queue primitives for TX */
INIT_LLIST_HEAD(&ts->tx_prims);
@@ -405,7 +408,7 @@
/* Prevent NULL-pointer deference */
if (ts == NULL) {
- LOGP(DSCH, LOGL_ERROR, "Timeslot isn't configured\n");
+ LOGP_SCHEDC(ts->sched, LOGL_ERROR, "Timeslot isn't configured\n");
return -EINVAL;
}
@@ -437,13 +440,11 @@
return -EINVAL;
if (lchan->active) {
- LOGP(DSCH, LOGL_ERROR, "Logical channel %s already activated "
- "on ts=%d\n", l1sched_lchan_desc[chan].name, ts->index);
+ LOGP_LCHANC(lchan, LOGL_ERROR, "is already activated\n");
return -EINVAL;
}
- LOGP(DSCH, LOGL_NOTICE, "Activating lchan=%s "
- "on ts=%d\n", l1sched_lchan_desc[chan].name, ts->index);
+ LOGP_LCHANC(lchan, LOGL_NOTICE, "activating\n");
/* Conditionally allocate memory for bursts */
if (lchan_desc->rx_fn && lchan_desc->burst_buf_size > 0) {
@@ -473,12 +474,12 @@
/* Print some TDMA statistics for Downlink */
if (l1sched_lchan_desc[lchan->type].rx_fn && lchan->active) {
- LOGP(DSCH, LOGL_DEBUG, "TDMA statistics for lchan=%s on ts=%u: "
- "%lu DL frames have been processed, "
- "%lu lost (compensated), last fn=%u\n",
- l1sched_lchan_desc[lchan->type].name, lchan->ts->index,
- lchan->tdma.num_proc, lchan->tdma.num_lost,
- lchan->tdma.last_proc);
+ LOGP_LCHANC(lchan, LOGL_DEBUG, "TDMA statistics: "
+ "%lu DL frames have been processed, "
+ "%lu lost (compensated), last fn=%u\n",
+ lchan->tdma.num_proc,
+ lchan->tdma.num_lost,
+ lchan->tdma.last_proc);
}
/* Reset internal state variables */
@@ -526,13 +527,11 @@
return -EINVAL;
if (!lchan->active) {
- LOGP(DSCH, LOGL_ERROR, "Logical channel %s already deactivated "
- "on ts=%d\n", l1sched_lchan_desc[chan].name, ts->index);
+ LOGP_LCHANC(lchan, LOGL_ERROR, "is already deactivated\n");
return -EINVAL;
}
- LOGP(DSCH, LOGL_DEBUG, "Deactivating lchan=%s "
- "on ts=%d\n", l1sched_lchan_desc[chan].name, ts->index);
+ LOGP_LCHANC(lchan, LOGL_DEBUG, "deactivating\n");
/* Reset internal state, free memory */
l1sched_reset_lchan(lchan);
@@ -547,8 +546,9 @@
{
struct l1sched_lchan_state *lchan;
- LOGP(DSCH, LOGL_DEBUG, "Deactivating all logical channels "
- "on ts=%d\n", ts->index);
+ LOGP_SCHEDC(ts->sched, LOGL_DEBUG,
+ "Deactivating all logical channels on ts=%d\n",
+ ts->index);
llist_for_each_entry(lchan, &ts->lchans, list) {
/* Omit inactive channels */
@@ -660,22 +660,23 @@
if (elapsed < 0) {
/* This burst has already been substituted by a dummy burst (all bits set to zero),
* so better drop it. Otherwise we risk to get undefined behavior in handler(). */
- LOGP(DSCHD, LOGL_ERROR, "(%s) Rx burst with fn=%u older than the last "
- "processed fn=%u (see OS#4658) => dropping\n",
- l1sched_lchan_desc[lchan->type].name,
- fn, lchan->tdma.last_proc);
+ LOGP_LCHAND(lchan, LOGL_ERROR, "Rx burst with fn=%u older than the last "
+ "processed fn=%u (see OS#4658) => dropping\n",
+ fn, lchan->tdma.last_proc);
return -EALREADY;
}
/* Check how many frames we (potentially) need to compensate */
if (elapsed > mf->period) {
- LOGP(DSCHD, LOGL_NOTICE, "Too many (>%u) contiguous TDMA frames elapsed (%d)
"
- "since the last processed fn=%u (current %u)\n",
- mf->period, elapsed, lchan->tdma.last_proc, fn);
+ LOGP_LCHANC(lchan, LOGL_NOTICE,
+ "Too many (>%u) contiguous TDMA frames elapsed (%d) "
+ "since the last processed fn=%u (current %u)\n",
+ mf->period, elapsed, lchan->tdma.last_proc, fn);
return -EIO;
} else if (elapsed == 0) {
- LOGP(DSCHD, LOGL_ERROR, "No TDMA frames elapsed since the last processed "
- "fn=%u, must be a bug?\n", lchan->tdma.last_proc);
+ LOGP_LCHANC(lchan, LOGL_ERROR,
+ "No TDMA frames elapsed since the last processed "
+ "fn=%u, must be a bug?\n", lchan->tdma.last_proc);
return -EIO;
}
@@ -692,8 +693,9 @@
if (fp->dl_chan != lchan->type)
continue;
- LOGP(DSCHD, LOGL_NOTICE, "Substituting lost TDMA frame %u on %s\n",
- fake_meas.fn, l1sched_lchan_desc[lchan->type].name);
+ LOGP_LCHANC(lchan, LOGL_NOTICE,
+ "Substituting lost TDMA frame fn=%u\n",
+ fake_meas.fn);
handler(lchan, fake_meas.fn, fp->dl_bid, bits, &fake_meas);
@@ -722,8 +724,8 @@
/* Check whether required timeslot is allocated and configured */
ts = sched->ts[tn];
if (ts == NULL || ts->mf_layout == NULL) {
- LOGP(DSCHD, LOGL_DEBUG, "TDMA timeslot #%u isn't configured, "
- "ignoring burst...\n", tn);
+ LOGP_SCHEDD(sched, LOGL_DEBUG,
+ "Timeslot #%u isn't configured, ignoring burst...\n", tn);
return -EINVAL;
}
@@ -770,8 +772,9 @@
* As a consequence, subst_frame_loss() will be unable to compensate
* one (potentionally lost) Downlink burst. On practice, it would
* happen once in 4615 * 10e-6 * (2 ^ 32 - 1) seconds or ~6 years. */
- LOGP(DSCHD, LOGL_NOTICE, "Too many TDMA frames have been processed. "
- "Are you running trxcon for more than 6 years?!?\n");
+ LOGP_LCHAND(lchan, LOGL_NOTICE,
+ "Too many TDMA frames have been processed. "
+ "Are you running trxcon for more than 6 years?!?\n");
lchan->tdma.num_proc = 1;
}
diff --git a/src/host/trxcon/src/trxcon.c b/src/host/trxcon/src/trxcon.c
index 0cc0de9..05b51a3 100644
--- a/src/host/trxcon/src/trxcon.c
+++ b/src/host/trxcon/src/trxcon.c
@@ -322,6 +322,18 @@
.event_names = trxcon_fsm_event_names,
};
+static const char *sched_logging_ctx_cb(const struct l1sched_state *sched)
+{
+ const struct trxcon_inst *trxcon = sched->priv;
+ static char buf[128];
+
+ snprintf(&buf[0], sizeof(buf) - 1, "%s{%s}: ",
+ osmo_fsm_inst_name(trxcon->fi),
+ osmo_fsm_state_name(trxcon->fi->fsm,
+ trxcon->fi->state));
+ return buf;
+}
+
struct trxcon_inst *trxcon_inst_alloc(void *ctx)
{
struct trxcon_inst *trxcon;
@@ -343,8 +355,14 @@
return NULL;
}
+ static const struct l1sched_cfg sched_cfg = {
+ .log_ctx_cb = &sched_logging_ctx_cb,
+ .log_cat_common = DSCH,
+ .log_cat_data = DSCHD,
+ };
+
/* Init scheduler */
- trxcon->sched = l1sched_alloc(trxcon, app_data.trx_fn_advance, trxcon);
+ trxcon->sched = l1sched_alloc(trxcon, &sched_cfg, app_data.trx_fn_advance,
trxcon);
if (trxcon->sched == NULL) {
trxcon_inst_free(trxcon);
return NULL;
--
To view, visit https://gerrit.osmocom.org/c/osmocom-bb/+/28744
To unsubscribe, or for help writing mail filters, visit
https://gerrit.osmocom.org/settings
Gerrit-Project: osmocom-bb
Gerrit-Branch: master
Gerrit-Change-Id: I26da1a506b02502a3a6a887533c35fb09c13c429
Gerrit-Change-Number: 28744
Gerrit-PatchSet: 1
Gerrit-Owner: fixeria <vyanitskiy(a)sysmocom.de>
Gerrit-MessageType: newchange