summaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
authorVadim Yanitskiy <vyanitskiy@sysmocom.de>2022-07-22 07:21:11 +0700
committerVadim Yanitskiy <vyanitskiy@sysmocom.de>2022-07-26 00:46:43 +0700
commit8f9e9806e6e33b406c4f5432b9f0f9819b430ec5 (patch)
tree78366f6460c893f8bd9db3d90dd8d757cb8d61ee
parent4a4bc0ed6e6d8890e192f6c099e6fa20c69c42a6 (diff)
trxcon: make l1sched logging configurable, use trxcon->fi as prefix
This change makes it possible to configure l1sched related logging: * l1sched_logging_init() allows to configure logging categories for common and data messages (by default, DLGLOBAL is used); * struct l1sched_cfg allows to configure a logging prefix to be used in l1sched messges (by default, 'l1sched[0x%p] is used)'. Let's use osmo_fsm_inst_name(trxcon->fi) as the logging prefix. Change-Id: I26da1a506b02502a3a6a887533c35fb09c13c429 Related: OS#5599, OS#3761
-rw-r--r--src/host/trxcon/include/osmocom/bb/l1sched/Makefile.am1
-rw-r--r--src/host/trxcon/include/osmocom/bb/l1sched/l1sched.h12
-rw-r--r--src/host/trxcon/include/osmocom/bb/l1sched/logging.h34
-rw-r--r--src/host/trxcon/include/osmocom/bb/trxcon/trxcon.h3
-rw-r--r--src/host/trxcon/src/sched_clck.c21
-rw-r--r--src/host/trxcon/src/sched_lchan_common.c6
-rw-r--r--src/host/trxcon/src/sched_lchan_pdtch.c34
-rw-r--r--src/host/trxcon/src/sched_lchan_rach.c29
-rw-r--r--src/host/trxcon/src/sched_lchan_sch.c11
-rw-r--r--src/host/trxcon/src/sched_lchan_tchf.c53
-rw-r--r--src/host/trxcon/src/sched_lchan_tchh.c51
-rw-r--r--src/host/trxcon/src/sched_lchan_xcch.c39
-rw-r--r--src/host/trxcon/src/sched_mframe.c1
-rw-r--r--src/host/trxcon/src/sched_prim.c46
-rw-r--r--src/host/trxcon/src/sched_trx.c103
-rw-r--r--src/host/trxcon/src/trxcon.c10
16 files changed, 253 insertions, 201 deletions
diff --git a/src/host/trxcon/include/osmocom/bb/l1sched/Makefile.am b/src/host/trxcon/include/osmocom/bb/l1sched/Makefile.am
index 295cc6b4..76f54a7e 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 29694107..3c28f450 100644
--- a/src/host/trxcon/include/osmocom/bb/l1sched/l1sched.h
+++ b/src/host/trxcon/include/osmocom/bb/l1sched/l1sched.h
@@ -346,6 +346,12 @@ struct l1sched_ts_prim_rach {
uint8_t offset;
};
+/*! Scheduler configuration */
+struct l1sched_cfg {
+ /*! Logging context (used as prefix for messages) */
+ const char *log_prefix;
+};
+
/*! One scheduler instance */
struct l1sched_state {
/*! Clock state */
@@ -366,6 +372,8 @@ struct l1sched_state {
struct l1sched_ts *ts[TRX_TS_COUNT];
/*! BSIC value learned from SCH bursts */
uint8_t bsic;
+ /*! Logging context (used as prefix for messages) */
+ const char *log_prefix;
/*! Some private data */
void *priv;
};
@@ -375,7 +383,9 @@ const struct l1sched_tdma_multiframe *l1sched_mframe_layout(
enum gsm_phys_chan_config config, int tn);
/* Scheduler management functions */
-struct l1sched_state *l1sched_alloc(void *ctx, uint32_t fn_advance, void *priv);
+void l1sched_logging_init(int log_cat_common, int log_cat_data);
+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 00000000..fb1c018c
--- /dev/null
+++ b/src/host/trxcon/include/osmocom/bb/l1sched/logging.h
@@ -0,0 +1,34 @@
+#pragma once
+
+extern int l1sched_log_cat_common;
+extern int l1sched_log_cat_data;
+
+/* Messages using l1sched_state as the context */
+#define LOGP_SCHED_CAT(sched, cat, level, fmt, args...) \
+ LOGP(l1sched_log_cat_##cat, level, "%s" fmt, \
+ (sched)->log_prefix, ## 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/include/osmocom/bb/trxcon/trxcon.h b/src/host/trxcon/include/osmocom/bb/trxcon/trxcon.h
index 2c28f809..12ad0171 100644
--- a/src/host/trxcon/include/osmocom/bb/trxcon/trxcon.h
+++ b/src/host/trxcon/include/osmocom/bb/trxcon/trxcon.h
@@ -22,6 +22,9 @@ enum trxcon_fsm_events {
struct trxcon_inst {
struct osmo_fsm_inst *fi;
+ /* Logging context for sched and l1c */
+ const char *log_prefix;
+
/* The L1 scheduler */
struct l1sched_state *sched;
/* L1/L2 interfaces */
diff --git a/src/host/trxcon/src/sched_clck.c b/src/host/trxcon/src/sched_clck.c
index 27e8eb9d..a3d75fce 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 @@ static void l1sched_clck_tick(void *data)
/* 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 @@ static void l1sched_clck_tick(void *data)
/* 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 @@ int l1sched_clck_handle(struct l1sched_state *sched, uint32_t fn)
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 @@ int l1sched_clck_handle(struct l1sched_state *sched, uint32_t fn)
/* 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 5d5ef6da..6fe5b2e3 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 @@ size_t l1sched_bad_frame_ind(uint8_t *l2, struct l1sched_lchan_state *lchan)
/* 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 9cad53a9..0ef4573e 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 @@ int rx_pdtch_fn(struct l1sched_lchan_state *lchan,
/* 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 @@ int rx_pdtch_fn(struct l1sched_lchan_state *lchan,
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 rx_pdtch_fn(struct l1sched_lchan_state *lchan,
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 @@ int tx_pdtch_fn(struct l1sched_lchan_state *lchan,
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 @@ send_burst:
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 e5944c61..e7422b22 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 @@ int tx_rach_fn(struct l1sched_lchan_state *lchan,
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 @@ int tx_rach_fn(struct l1sched_lchan_state *lchan,
/* 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 @@ int tx_rach_fn(struct l1sched_lchan_state *lchan,
/* 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 @@ int tx_rach_fn(struct l1sched_lchan_state *lchan,
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 235e64ce..c61e1340 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 @@ int rx_sch_fn(struct l1sched_lchan_state *lchan,
/* 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 83491931..1a1b93d3 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 @@ int rx_tchf_fn(struct l1sched_lchan_state *lchan,
/* 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 @@ int rx_tchf_fn(struct l1sched_lchan_state *lchan,
* 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 @@ int rx_tchf_fn(struct l1sched_lchan_state *lchan,
/* 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 @@ bfi:
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 tx_tchf_fn(struct l1sched_lchan_state *lchan,
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 @@ int tx_tchf_fn(struct l1sched_lchan_state *lchan,
* 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 @@ int tx_tchf_fn(struct l1sched_lchan_state *lchan,
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 @@ int tx_tchf_fn(struct l1sched_lchan_state *lchan,
/* 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 @@ send_burst:
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 de9c0477..b0bc566b 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 @@ uint32_t l1sched_tchh_block_dl_first_fn(enum l1sched_lchan_type chan,
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 @@ int rx_tchh_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);
if (*mask == 0x00) {
/* Align to the first burst */
@@ -268,10 +266,10 @@ int rx_tchh_fn(struct l1sched_lchan_state *lchan,
* 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 @@ int rx_tchh_fn(struct l1sched_lchan_state *lchan,
/* 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 @@ bfi:
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 tx_tchh_fn(struct l1sched_lchan_state *lchan,
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 @@ int tx_tchh_fn(struct l1sched_lchan_state *lchan,
* 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 @@ int tx_tchh_fn(struct l1sched_lchan_state *lchan,
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 @@ int tx_tchh_fn(struct l1sched_lchan_state *lchan,
/* 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 @@ send_burst:
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 e6777640..0d248662 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 @@ int rx_data_fn(struct l1sched_lchan_state *lchan,
/* 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 @@ int rx_data_fn(struct l1sched_lchan_state *lchan,
/* 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 rx_data_fn(struct l1sched_lchan_state *lchan,
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 @@ int tx_data_fn(struct l1sched_lchan_state *lchan,
/* 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 @@ int tx_data_fn(struct l1sched_lchan_state *lchan,
/* 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 @@ send_burst:
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 e8aa4397..90b7763c 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 0b1b0df7..33d48de4 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 @@ static struct l1sched_ts_prim *prim_alloc(void *ctx, size_t pl_len,
/* 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 @@ struct l1sched_ts_prim *l1sched_prim_push(struct l1sched_state *sched,
/* 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 @@ static struct l1sched_ts_prim *prim_compose_mr(struct l1sched_lchan_state *lchan
/* 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 @@ static struct l1sched_ts_prim *prim_dequeue_sacch(struct llist_head *queue,
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 @@ static struct l1sched_ts_prim *prim_dequeue_sacch(struct llist_head *queue,
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 @@ int l1sched_prim_dummy(struct l1sched_lchan_state *lchan)
/* 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 443c23d4..d44c1bac 100644
--- a/src/host/trxcon/src/sched_trx.c
+++ b/src/host/trxcon/src/sched_trx.c
@@ -33,7 +33,11 @@
#include <osmocom/core/linuxlist.h>
#include <osmocom/bb/l1sched/l1sched.h>
-#include <osmocom/bb/trxcon/logging.h>
+#include <osmocom/bb/l1sched/logging.h>
+
+/* Logging categories to be used for common/data messages */
+int l1sched_log_cat_common = DLGLOBAL;
+int l1sched_log_cat_data = DLGLOBAL;
static int l1sched_cfg_pchan_comb_req(struct l1sched_state *sched,
uint8_t tn, enum gsm_phys_chan_config pchan)
@@ -150,11 +154,16 @@ static void sched_frame_clck_cb(struct l1sched_state *sched)
l1sched_handle_burst_req(sched, &br[tn]);
}
-struct l1sched_state *l1sched_alloc(void *ctx, uint32_t fn_advance, void *priv)
+void l1sched_logging_init(int log_cat_common, int log_cat_data)
{
- struct l1sched_state *sched;
+ l1sched_log_cat_common = log_cat_common;
+ l1sched_log_cat_data = log_cat_data;
+}
- LOGP(DSCH, LOGL_NOTICE, "Init scheduler\n");
+struct l1sched_state *l1sched_alloc(void *ctx, const struct l1sched_cfg *cfg,
+ uint32_t fn_advance, void *priv)
+{
+ struct l1sched_state *sched;
sched = talloc(ctx, struct l1sched_state);
if (!sched)
@@ -167,6 +176,11 @@ struct l1sched_state *l1sched_alloc(void *ctx, uint32_t fn_advance, void *priv)
.priv = priv,
};
+ if (cfg->log_prefix == NULL)
+ sched->log_prefix = talloc_asprintf(sched, "l1sched[0x%p]: ", sched);
+ else
+ sched->log_prefix = talloc_strdup(sched, cfg->log_prefix);
+
return sched;
}
@@ -177,7 +191,7 @@ void l1sched_free(struct l1sched_state *sched)
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 +208,8 @@ void l1sched_reset(struct l1sched_state *sched, bool reset_clock)
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 +224,11 @@ struct l1sched_ts *l1sched_add_ts(struct l1sched_state *sched, int tn)
{
/* 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 +247,7 @@ void l1sched_del_ts(struct l1sched_state *sched, int tn)
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 +298,9 @@ int l1sched_configure_ts(struct l1sched_state *sched, int tn,
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 +420,7 @@ int l1sched_set_lchans(struct l1sched_ts *ts, uint8_t chan_nr,
/* 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 +452,11 @@ int l1sched_activate_lchan(struct l1sched_ts *ts, enum l1sched_lchan_type chan)
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 +486,12 @@ static void l1sched_reset_lchan(struct l1sched_lchan_state *lchan)
/* 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 +539,11 @@ int l1sched_deactivate_lchan(struct l1sched_ts *ts, enum l1sched_lchan_type chan
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 +558,9 @@ void l1sched_deactivate_all_lchans(struct l1sched_ts *ts)
{
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 +672,23 @@ static int subst_frame_loss(struct l1sched_lchan_state *lchan,
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 +705,9 @@ static int subst_frame_loss(struct l1sched_lchan_state *lchan,
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 +736,8 @@ int l1sched_handle_rx_burst(struct l1sched_state *sched, uint8_t tn,
/* 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 +784,9 @@ int l1sched_handle_rx_burst(struct l1sched_state *sched, uint8_t tn,
* 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 df411c39..86d4c491 100644
--- a/src/host/trxcon/src/trxcon.c
+++ b/src/host/trxcon/src/trxcon.c
@@ -333,6 +333,9 @@ struct trxcon_inst *trxcon_inst_alloc(void *ctx)
trxcon, LOGL_DEBUG, NULL);
OSMO_ASSERT(trxcon->fi != NULL);
+ /* Logging context to be used by both l1ctl and l1sched modules */
+ trxcon->log_prefix = talloc_asprintf(trxcon, "%s: ", osmo_fsm_inst_name(trxcon->fi));
+
/* Init transceiver interface */
trxcon->trx = trx_if_open(trxcon,
app_data.trx_bind_ip,
@@ -344,7 +347,11 @@ struct trxcon_inst *trxcon_inst_alloc(void *ctx)
}
/* Init scheduler */
- trxcon->sched = l1sched_alloc(trxcon, app_data.trx_fn_advance, trxcon);
+ const struct l1sched_cfg sched_cfg = {
+ .log_prefix = trxcon->log_prefix,
+ };
+
+ trxcon->sched = l1sched_alloc(trxcon, &sched_cfg, app_data.trx_fn_advance, trxcon);
if (trxcon->sched == NULL) {
trxcon_inst_free(trxcon);
return NULL;
@@ -530,6 +537,7 @@ int main(int argc, char **argv)
/* Init logging system */
trx_log_init(tall_trxcon_ctx, app_data.debug_mask);
+ l1sched_logging_init(DSCH, DSCHD);
/* Configure pretty logging */
log_set_print_extended_timestamp(osmo_stderr_target, 1);