pespin has uploaded this change for review.
Add new log category 'ms'
This is useful to track the lifecycle of MS objects. The RLCMAC cateogry
used so far in those log messages is too broad.
Change-Id: Ib4ce88d0f7309ac77c064a94bb0d667e8dbc33dd
---
M src/gprs_debug.c
M src/gprs_debug.h
M src/gprs_ms.c
M tests/app_info/AppInfoTest.cpp
M tests/ms/MsTest.cpp
M tests/tbf/TbfTest.cpp
M tests/ulc/PdchUlcTest.cpp
7 files changed, 50 insertions(+), 30 deletions(-)
git pull ssh://gerrit.osmocom.org:29418/osmo-pcu refs/changes/83/32383/1
diff --git a/src/gprs_debug.c b/src/gprs_debug.c
index 8aeca5b..e3f862d 100644
--- a/src/gprs_debug.c
+++ b/src/gprs_debug.c
@@ -79,6 +79,13 @@
.loglevel = LOGL_NOTICE,
.enabled = 1,
},
+ [DMS] = {
+ .name = "DMS",
+ .color = "\033[1;32m",
+ .description = "Mobile Station (MS)",
+ .loglevel = LOGL_NOTICE,
+ .enabled = 1,
+ },
[DTBF] = {
.name = "DTBF",
.color = "\033[1;34m",
diff --git a/src/gprs_debug.h b/src/gprs_debug.h
index db9630c..b66de90 100644
--- a/src/gprs_debug.h
+++ b/src/gprs_debug.h
@@ -34,6 +34,7 @@
DRLCMACUL,
DRLCMACSCHED,
DRLCMACMEAS,
+ DMS,
DTBF,
DTBFDL,
DTBFUL,
diff --git a/src/gprs_ms.c b/src/gprs_ms.c
index 617c769..a209758 100644
--- a/src/gprs_ms.c
+++ b/src/gprs_ms.c
@@ -82,7 +82,7 @@
level = LOGL_DEBUG;
- LOGPSRC(DRLCMAC, level, file, line, "%s: %s %s: now used by %s\n",
+ LOGPSRC(DMS, level, file, line, "%s: %s %s: now used by %s\n",
ms_name(ms),
(e->count - old_use_count) > 0 ? "+" : "-", e->use,
(osmo_use_count_to_str_buf(buf, sizeof(buf), &ms->use_count), buf));
@@ -100,7 +100,7 @@
static void ms_release_timer_cb(void *data)
{
struct GprsMs *ms = (struct GprsMs *) data;
- LOGPMS(ms, DRLCMAC, LOGL_INFO, "Release timer expired\n");
+ LOGPMS(ms, DMS, LOGL_INFO, "Release timer expired\n");
/* Finally free the MS after being idle for a while according to config */
talloc_free(ms);
@@ -148,7 +148,7 @@
int codel_interval = LLC_CODEL_USE_DEFAULT;
- LOGP(DRLCMAC, LOGL_INFO, "Creating MS object\n");
+ LOGP(DMS, LOGL_INFO, "Creating MS object\n");
ms->imsi[0] = '\0';
osmo_timer_setup(&ms->timer, ms_release_timer_cb, ms);
@@ -184,7 +184,7 @@
{
struct llist_item *pos, *tmp;
- LOGPMS(ms, DRLCMAC, LOGL_INFO, "Destroying MS object\n");
+ LOGPMS(ms, DMS, LOGL_INFO, "Destroying MS object\n");
bts_stat_item_dec(ms->bts, STAT_MS_PRESENT);
llist_del(&ms->list);
@@ -240,7 +240,7 @@
return;
}
- LOGPMS(ms, DRLCMAC, LOGL_DEBUG, "Schedule MS release in %u secs\n", ms->delay);
+ LOGPMS(ms, DMS, LOGL_DEBUG, "Schedule MS release in %u secs\n", ms->delay);
osmo_timer_schedule(&ms->timer, ms->delay, 0);
}
@@ -249,7 +249,7 @@
if (!osmo_timer_pending(ms->timer.data))
return;
- LOGPMS(ms, DRLCMAC, LOGL_DEBUG, "Cancel scheduled MS release\n");
+ LOGPMS(ms, DMS, LOGL_DEBUG, "Cancel scheduled MS release\n");
osmo_timer_del(&ms->timer);
}
@@ -329,7 +329,7 @@
static void ms_attach_ul_tbf(struct GprsMs *ms, struct gprs_rlcmac_ul_tbf *tbf)
{
- LOGPMS(ms, DRLCMAC, LOGL_INFO, "Attaching UL TBF: %s\n", tbf_name((struct gprs_rlcmac_tbf *)tbf));
+ LOGPMS(ms, DMS, LOGL_INFO, "Attaching UL TBF: %s\n", tbf_name((struct gprs_rlcmac_tbf *)tbf));
if (ms->ul_tbf)
llist_add_tail(tbf_ms_list(ul_tbf_as_tbf(ms->ul_tbf)), &ms->old_tbfs);
@@ -341,7 +341,7 @@
static void ms_attach_dl_tbf(struct GprsMs *ms, struct gprs_rlcmac_dl_tbf *tbf)
{
- LOGPMS(ms, DRLCMAC, LOGL_INFO, "Attaching DL TBF: %s\n", tbf_name((struct gprs_rlcmac_tbf *)tbf));
+ LOGPMS(ms, DMS, LOGL_INFO, "Attaching DL TBF: %s\n", tbf_name((struct gprs_rlcmac_tbf *)tbf));
if (ms->dl_tbf)
llist_add_tail(tbf_ms_list(dl_tbf_as_tbf(ms->dl_tbf)), &ms->old_tbfs);
@@ -374,7 +374,7 @@
if (!ms_tbf_is_attached(ms, tbf))
return;
- LOGPMS(ms, DRLCMAC, LOGL_INFO, "Detaching TBF: %s\n",
+ LOGPMS(ms, DMS, LOGL_INFO, "Detaching TBF: %s\n",
tbf_name(tbf));
if (tbf == ul_tbf_as_tbf(ms->ul_tbf)) {
@@ -394,7 +394,7 @@
ms_ref() taken to avoid use-after-free. */
void ms_reset(struct GprsMs *ms)
{
- LOGPMS(ms, DRLCMAC, LOGL_INFO, "Clearing MS object\n");
+ LOGPMS(ms, DMS, LOGL_INFO, "Clearing MS object\n");
struct llist_item *pos;
struct gprs_rlcmac_tbf *tbf;
@@ -458,7 +458,7 @@
ms_name_buf(old_ms, old_ms_name, sizeof(old_ms_name));
- LOGPMS(ms, DRLCMAC, LOGL_INFO, "Merge MS: %s\n", old_ms_name);
+ LOGPMS(ms, DMS, LOGL_INFO, "Merge MS: %s\n", old_ms_name);
if (strlen(ms_imsi(ms)) == 0 && strlen(ms_imsi(old_ms)) != 0)
osmo_strlcpy(ms->imsi, ms_imsi(old_ms), sizeof(ms->imsi));
@@ -498,7 +498,7 @@
return;
if (tlli != ms->new_dl_tlli) {
- LOGP(DRLCMAC, LOGL_INFO,
+ LOGP(DMS, LOGL_INFO,
"Modifying MS object, UL TLLI: 0x%08x -> 0x%08x, "
"not yet confirmed\n",
ms_tlli(ms), tlli);
@@ -506,7 +506,7 @@
return;
}
- LOGP(DRLCMAC, LOGL_INFO,
+ LOGP(DMS, LOGL_INFO,
"Modifying MS object, TLLI: 0x%08x -> 0x%08x, "
"already confirmed partly\n",
ms->tlli, tlli);
@@ -524,7 +524,7 @@
/* The MS has not sent a message with the new TLLI, which may
* happen according to the spec [TODO: add reference]. */
- LOGP(DRLCMAC, LOGL_INFO,
+ LOGP(DMS, LOGL_INFO,
"The MS object cannot fully confirm an unexpected TLLI: 0x%08x, "
"partly confirmed\n", tlli);
/* Use the network's idea of TLLI as candidate, this does not
@@ -533,7 +533,7 @@
return false;
}
- LOGP(DRLCMAC, LOGL_INFO,
+ LOGP(DMS, LOGL_INFO,
"Modifying MS object, TLLI: 0x%08x confirmed\n", tlli);
ms_apply_tlli_change(ms, tlli);
@@ -544,12 +544,12 @@
void ms_set_imsi(struct GprsMs *ms, const char *imsi)
{
if (!imsi) {
- LOGP(DRLCMAC, LOGL_ERROR, "Expected IMSI!\n");
+ LOGP(DMS, LOGL_ERROR, "Expected IMSI!\n");
return;
}
if (imsi[0] && strlen(imsi) < 3) {
- LOGP(DRLCMAC, LOGL_ERROR, "No valid IMSI '%s'!\n",
+ LOGP(DMS, LOGL_ERROR, "No valid IMSI '%s'!\n",
imsi);
return;
}
@@ -557,7 +557,7 @@
if (strcmp(imsi, ms->imsi) == 0)
return;
- LOGP(DRLCMAC, LOGL_INFO,
+ LOGP(DMS, LOGL_INFO,
"Modifying MS object, TLLI = 0x%08x, IMSI '%s' -> '%s'\n",
ms_tlli(ms), ms->imsi, imsi);
@@ -570,7 +570,7 @@
* different IMSI */
OSMO_ASSERT(old_ms != ms);
- LOGPMS(ms, DRLCMAC, LOGL_NOTICE,
+ LOGPMS(ms, DMS, LOGL_NOTICE,
"IMSI '%s' was already assigned to another "
"MS object: TLLI = 0x%08x, that IMSI will be removed\n",
imsi, ms_tlli(old_ms));
@@ -595,12 +595,12 @@
return;
if (gsm48_ta_is_valid(ta_)) {
- LOGP(DRLCMAC, LOGL_INFO,
+ LOGP(DMS, LOGL_INFO,
"Modifying MS object, TLLI = 0x%08x, TA %d -> %d\n",
ms_tlli(ms), ms->ta, ta_);
ms->ta = ta_;
} else
- LOGP(DRLCMAC, LOGL_NOTICE,
+ LOGP(DMS, LOGL_NOTICE,
"MS object, TLLI = 0x%08x, invalid TA %d rejected (old "
"value %d kept)\n", ms_tlli(ms), ta_, ms->ta);
}
@@ -610,7 +610,7 @@
if (ms_class_ == ms->ms_class)
return;
- LOGP(DRLCMAC, LOGL_INFO,
+ LOGP(DMS, LOGL_INFO,
"Modifying MS object, TLLI = 0x%08x, MS class %d -> %d\n",
ms_tlli(ms), ms->ms_class, ms_class_);
@@ -622,14 +622,14 @@
if (ms_class_ == ms->egprs_ms_class)
return;
- LOGP(DRLCMAC, LOGL_INFO,
+ LOGP(DMS, LOGL_INFO,
"Modifying MS object, TLLI = 0x%08x, EGPRS MS class %d -> %d\n",
ms_tlli(ms), ms->egprs_ms_class, ms_class_);
ms->egprs_ms_class = ms_class_;
if (!bts_max_mcs_ul(ms->bts) || !bts_max_mcs_dl(ms->bts)) {
- LOGPMS(ms, DRLCMAC, LOGL_DEBUG,
+ LOGPMS(ms, DMS, LOGL_DEBUG,
"Avoid enabling EGPRS because use of MCS is disabled: ul=%u dl=%u\n",
bts_max_mcs_ul(ms->bts), bts_max_mcs_dl(ms->bts));
return;
@@ -643,7 +643,7 @@
} else {
ms_set_mode(ms, EGPRS);
}
- LOGPMS(ms, DRLCMAC, LOGL_INFO, "Enabled EGPRS, mode %s\n", mode_name(ms_mode(ms)));
+ LOGPMS(ms, DMS, LOGL_INFO, "Enabled EGPRS, mode %s\n", mode_name(ms_mode(ms)));
}
void ms_update_error_rate(struct GprsMs *ms, struct gprs_rlcmac_tbf *tbf, int error_rate)
@@ -882,7 +882,7 @@
}
if (orig_cs != cs)
- LOGPMS(ms, DRLCMACDL, LOGL_INFO, "MS (mode=%s) suggests transmitting "
+ LOGPMS(ms, DMS, LOGL_INFO, "MS (mode=%s) suggests transmitting "
"DL %s, downgrade to %s in order to match TBF & scheduler requirements\n",
mode_name(ms_mode(ms)), mcs_name(orig_cs), mcs_name(cs));
diff --git a/tests/app_info/AppInfoTest.cpp b/tests/app_info/AppInfoTest.cpp
index cb11d0f..d33e8ce 100644
--- a/tests/app_info/AppInfoTest.cpp
+++ b/tests/app_info/AppInfoTest.cpp
@@ -180,7 +180,7 @@
log_set_print_filename2(osmo_stderr_target, LOG_FILENAME_NONE);
log_set_print_category(osmo_stderr_target, 0);
log_set_print_category_hex(osmo_stderr_target, 0);
- log_parse_category_mask(osmo_stderr_target, "DL1IF,1:DRLCMAC,3:DRLCMACSCHED,1");
+ log_parse_category_mask(osmo_stderr_target, "DL1IF,1:DRLCMAC,3:DRLCMACSCHED,1:DMS,3");
the_pcu = gprs_pcu_alloc(tall_pcu_ctx);
bts_alloc(the_pcu, 0);
diff --git a/tests/ms/MsTest.cpp b/tests/ms/MsTest.cpp
index 7b7d59a..2a15a7b 100644
--- a/tests/ms/MsTest.cpp
+++ b/tests/ms/MsTest.cpp
@@ -542,7 +542,7 @@
log_set_log_level(osmo_stderr_target, LOGL_INFO);
log_set_print_category(osmo_stderr_target, 0);
log_set_print_category_hex(osmo_stderr_target, 0);
- log_parse_category_mask(osmo_stderr_target, "DPCU,3:DRLCMAC,3");
+ log_parse_category_mask(osmo_stderr_target, "DPCU,3:DRLCMAC,3:DMS,3");
the_pcu = gprs_pcu_alloc(tall_pcu_ctx);
diff --git a/tests/tbf/TbfTest.cpp b/tests/tbf/TbfTest.cpp
index 4adbaf8..ad08318 100644
--- a/tests/tbf/TbfTest.cpp
+++ b/tests/tbf/TbfTest.cpp
@@ -3470,7 +3470,7 @@
log_set_print_category_hex(osmo_stderr_target, 0);
log_parse_category_mask(osmo_stderr_target, "DRLCMAC,1:DRLCMACDATA,3:DRLCMACDL,3:DRLCMACUL,3:"
"DRLCMACSCHED,1:DRLCMACMEAS,3:DNS,3:DLBSSGP,3:DPCU,5:"
- "DL1IF,6:DTBF,1:DTBFUL,1:DTBFDL,1:DLGLOBAL,2:");
+ "DL1IF,6:DMS,1:DTBF,1:DTBFUL,1:DTBFDL,1:DLGLOBAL,2:");
osmo_fsm_log_addr(false);
vty_init(&pcu_vty_info);
pcu_vty_init();
diff --git a/tests/ulc/PdchUlcTest.cpp b/tests/ulc/PdchUlcTest.cpp
index 3756b9d..be370bd 100644
--- a/tests/ulc/PdchUlcTest.cpp
+++ b/tests/ulc/PdchUlcTest.cpp
@@ -317,7 +317,7 @@
log_set_log_level(osmo_stderr_target, LOGL_DEBUG);
log_set_print_category_hex(osmo_stderr_target, 0);
log_set_print_category(osmo_stderr_target, 0);
- log_parse_category_mask(osmo_stderr_target, "DPCU,1:DRLCMAC,1:DRLCMACUL,1");
+ log_parse_category_mask(osmo_stderr_target, "DPCU,1:DRLCMAC,1:DRLCMACUL,1:DMS,1");
the_pcu = gprs_pcu_alloc(tall_pcu_ctx);
To view, visit change 32383. To unsubscribe, or for help writing mail filters, visit settings.