aboutsummaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
authorMichael Iedema <michael@kapsulate.com>2022-05-19 11:00:14 -0700
committerMichael Iedema <michael@kapsulate.com>2022-05-23 02:20:12 -0700
commita7628d9cf0895d5a95fd07e45077f21f40f0dce2 (patch)
treedaafdf7dea994e83a59a3a571b99a9657da42dc9
parent80cd4555b0b62a0f14544a39307e6fe7c14c35f8 (diff)
stats: new trackers for lchan life duration (v2)HEADmaster
This patch adds two stats which track cummulative lchan lifetime by type TCH and SDCCH. These new counters will accomplish two things: 1) Provide a glanceable way to see if lchan durations look healthy. When examining a site, short-lived (<5s) and long-lived (>30s) TCH lchans are difficult to tell apart. If we only see short-lived TCH lchans, there is most likely an RF or signaling problem to investigate. This new counter will expose channel ages in the VTY output 2) Provide a more accurate count for Erlangs per site. Currently, we are basing Erlangs on active TCH channel counts per stats period. This method skews high very quickly. Each active TCH in that period translates into the full 10s of activity. This counter should improve accuracy by two orders of magnitude. Change-Id: Ie3771233ecbd4bc24a24fb22c1064a18e7b8b2b0
-rw-r--r--include/osmocom/bsc/bts.h5
-rw-r--r--include/osmocom/bsc/gsm_data.h7
-rw-r--r--src/osmo-bsc/bsc_init.c16
-rw-r--r--src/osmo-bsc/bts.c61
-rw-r--r--src/osmo-bsc/bts_trx_vty.c7
-rw-r--r--src/osmo-bsc/bts_vty.c25
-rw-r--r--src/osmo-bsc/gsm_data.c15
-rw-r--r--src/osmo-bsc/lchan_fsm.c4
8 files changed, 140 insertions, 0 deletions
diff --git a/include/osmocom/bsc/bts.h b/include/osmocom/bsc/bts.h
index 58ea39cb7..5a67791f5 100644
--- a/include/osmocom/bsc/bts.h
+++ b/include/osmocom/bsc/bts.h
@@ -60,6 +60,8 @@ enum bts_counter_id {
BTS_CTR_CHAN_ACT_SDCCH,
BTS_CTR_CHAN_ACT_TCH,
BTS_CTR_CHAN_ACT_NACK,
+ BTS_CTR_CHAN_TCH_ACTIVE_MILLISECONDS_TOTAL,
+ BTS_CTR_CHAN_SDCCH_ACTIVE_MILLISECONDS_TOTAL,
BTS_CTR_RSL_UNKNOWN,
BTS_CTR_RSL_IPA_NACK,
BTS_CTR_RSL_DELETE_IND,
@@ -757,6 +759,9 @@ void bts_store_uptime(struct gsm_bts *bts);
unsigned long long bts_uptime(const struct gsm_bts *bts);
+#define BTS_STORE_LCHAN_DURATIONS_INTERVAL 1 /* in seconds */
+void bts_store_lchan_durations(struct gsm_bts *bts);
+
char *get_model_oml_status(const struct gsm_bts *bts);
/* reset the state of all MO in the BTS */
void gsm_bts_mo_reset(struct gsm_bts *bts);
diff --git a/include/osmocom/bsc/gsm_data.h b/include/osmocom/bsc/gsm_data.h
index 6df7c6193..6abe94332 100644
--- a/include/osmocom/bsc/gsm_data.h
+++ b/include/osmocom/bsc/gsm_data.h
@@ -889,6 +889,9 @@ struct gsm_lchan {
uint8_t interf_band;
/* MS power control state */
struct lchan_power_ctrl_state ms_power_ctrl;
+ /* Timestamps and markers to track active state duration. */
+ struct timespec active_start;
+ struct timespec active_stored;
};
/* One Timeslot in a TRX */
@@ -1147,6 +1150,7 @@ const char *gsm_chreq_name(enum gsm_chreq_reason_t c);
char *gsm_ts_name(const struct gsm_bts_trx_ts *ts);
char *gsm_ts_and_pchan_name(const struct gsm_bts_trx_ts *ts);
void lchan_update_name(struct gsm_lchan *lchan);
+uint64_t gsm_lchan_active_duration_ms(const struct gsm_lchan *lchan);
static inline char *gsm_lchan_name(const struct gsm_lchan *lchan)
{
@@ -1278,6 +1282,9 @@ struct gsm_network {
/* Timer to write each BTS's uptime counter state to the stats system. */
struct osmo_timer_list bts_store_uptime_timer;
+ /* Timer to write each BTS's set of lchan duration counters' state to the stats system. */
+ struct osmo_timer_list bts_store_lchan_durations_timer;
+
struct {
/* Single MGCP client configuration under msc node (also required for
* MGCP proxy when sccp-lite is used) */
diff --git a/src/osmo-bsc/bsc_init.c b/src/osmo-bsc/bsc_init.c
index 0412f6b6b..650a76ba8 100644
--- a/src/osmo-bsc/bsc_init.c
+++ b/src/osmo-bsc/bsc_init.c
@@ -88,6 +88,18 @@ static void bsc_store_bts_uptime(void *data)
osmo_timer_schedule(&net->bts_store_uptime_timer, BTS_STORE_UPTIME_INTERVAL, 0);
}
+static void bsc_store_bts_lchan_durations(void *data)
+{
+ struct gsm_network *net = data;
+ struct gsm_bts *bts;
+
+ llist_for_each_entry(bts, &net->bts_list, list)
+ bts_store_lchan_durations(bts);
+
+ /* Keep this timer ticking. */
+ osmo_timer_schedule(&net->bts_store_lchan_durations_timer, BTS_STORE_LCHAN_DURATIONS_INTERVAL, 0);
+}
+
static struct gsm_network *bsc_network_init(void *ctx)
{
struct gsm_network *net = gsm_network_init(ctx);
@@ -180,6 +192,10 @@ static struct gsm_network *bsc_network_init(void *ctx)
osmo_timer_setup(&net->bts_store_uptime_timer, bsc_store_bts_uptime, net);
osmo_timer_schedule(&net->bts_store_uptime_timer, BTS_STORE_UPTIME_INTERVAL, 0);
+ /* Init lchan duration tracking timer. */
+ osmo_timer_setup(&net->bts_store_lchan_durations_timer, bsc_store_bts_lchan_durations, net);
+ osmo_timer_schedule(&net->bts_store_lchan_durations_timer, BTS_STORE_LCHAN_DURATIONS_INTERVAL, 0);
+
net->cbc->net = net;
net->cbc->mode = BSC_CBC_LINK_MODE_DISABLED;
net->cbc->server.local_addr = bsc_cbc_default_server_local_addr;
diff --git a/src/osmo-bsc/bts.c b/src/osmo-bsc/bts.c
index c04a59ec0..ad46f54f9 100644
--- a/src/osmo-bsc/bts.c
+++ b/src/osmo-bsc/bts.c
@@ -741,6 +741,61 @@ void bts_store_uptime(struct gsm_bts *bts)
osmo_stat_item_set(osmo_stat_item_group_get_item(bts->bts_statg, BTS_STAT_UPTIME_SECONDS), bts_uptime(bts));
}
+void bts_store_lchan_durations(struct gsm_bts *bts)
+{
+ struct gsm_bts_trx *trx;
+ int i, j;
+ struct timespec now, elapsed;
+ uint64_t elapsed_ms;
+ uint64_t elapsed_tch_ms = 0;
+ uint64_t elapsed_sdcch_ms = 0;
+
+ /* Ignore BTS that are not in operation. */
+ if (!trx_is_usable(bts->c0))
+ return;
+
+ /* Grab storage time to be used for all lchans. */
+ osmo_clock_gettime(CLOCK_MONOTONIC, &now);
+
+ /* Iterate over all lchans. */
+ llist_for_each_entry(trx, &bts->trx_list, list) {
+ for (i = 0; i < ARRAY_SIZE(trx->ts); i++) {
+ struct gsm_bts_trx_ts *ts = &trx->ts[i];
+ for (j = 0; j < ARRAY_SIZE(ts->lchan); j++) {
+ struct gsm_lchan *lchan = &ts->lchan[j];
+
+ /* Ignore lchans whose activation timestamps are not yet set. */
+ if (lchan->active_stored.tv_sec == 0 && lchan->active_stored.tv_nsec == 0)
+ continue;
+
+ /* Calculate elapsed time since last storage. */
+ timespecsub(&now, &lchan->active_stored, &elapsed);
+ elapsed_ms = elapsed.tv_sec * 1000 + elapsed.tv_nsec / 1000000;
+
+ /* Assign elapsed time to appropriate bucket. */
+ switch (lchan->type) {
+ case GSM_LCHAN_TCH_H:
+ case GSM_LCHAN_TCH_F:
+ elapsed_tch_ms += elapsed_ms;
+ break;
+ case GSM_LCHAN_SDCCH:
+ elapsed_sdcch_ms += elapsed_ms;
+ break;
+ default:
+ continue;
+ }
+
+ /* Update storage time. */
+ lchan->active_stored = now;
+ }
+ }
+ }
+
+ /* Export to rate counters. */
+ rate_ctr_add(rate_ctr_group_get_ctr(bts->bts_ctrs, BTS_CTR_CHAN_TCH_ACTIVE_MILLISECONDS_TOTAL), elapsed_tch_ms);
+ rate_ctr_add(rate_ctr_group_get_ctr(bts->bts_ctrs, BTS_CTR_CHAN_SDCCH_ACTIVE_MILLISECONDS_TOTAL), elapsed_sdcch_ms);
+}
+
unsigned long long bts_uptime(const struct gsm_bts *bts)
{
struct timespec tp;
@@ -1099,6 +1154,12 @@ const struct rate_ctr_desc bts_ctr_description[] = {
[BTS_CTR_CHAN_ACT_NACK] = \
{ "chan_act:nack",
"Number of Channel Activations that the BTS NACKed" },
+ [BTS_CTR_CHAN_TCH_ACTIVE_MILLISECONDS_TOTAL] = \
+ { "chan_tch:active_milliseconds:total",
+ "Cumulative number of milliseconds of TCH channel activity" },
+ [BTS_CTR_CHAN_SDCCH_ACTIVE_MILLISECONDS_TOTAL] = \
+ { "chan_sdcch:active_milliseconds:total",
+ "Cumulative number of milliseconds of SDCCH channel activity" },
[BTS_CTR_RSL_UNKNOWN] = \
{ "rsl:unknown",
"Number of unknown/unsupported RSL messages received from BTS" },
diff --git a/src/osmo-bsc/bts_trx_vty.c b/src/osmo-bsc/bts_trx_vty.c
index a3d603321..9cf128e25 100644
--- a/src/osmo-bsc/bts_trx_vty.c
+++ b/src/osmo-bsc/bts_trx_vty.c
@@ -569,6 +569,13 @@ void lchan_dump_full_vty(struct vty *vty, struct gsm_lchan *lchan)
vty_out(vty, "BTS %u, TRX %u, Timeslot %u, Lchan %u: Type %s%s",
lchan->ts->trx->bts->nr, lchan->ts->trx->nr, lchan->ts->nr,
lchan->nr, gsm_lchant_name(lchan->type), VTY_NEWLINE);
+
+ if (lchan->activate.concluded) {
+ vty_out(vty, " Active for: %s seconds%s",
+ osmo_int_to_float_str_c(OTC_SELECT, gsm_lchan_active_duration_ms(lchan), 3),
+ VTY_NEWLINE);
+ }
+
vty_out_dyn_ts_details(vty, lchan->ts);
vty_out(vty, " Connection: %u, State: %s%s%s%s",
lchan->conn ? 1: 0, lchan_state_name(lchan),
diff --git a/src/osmo-bsc/bts_vty.c b/src/osmo-bsc/bts_vty.c
index 4e60cd897..ba4215aaf 100644
--- a/src/osmo-bsc/bts_vty.c
+++ b/src/osmo-bsc/bts_vty.c
@@ -3677,6 +3677,8 @@ void bts_dump_vty(struct vty *vty, struct gsm_bts *bts)
struct gsm_bts_trx *trx;
int ts_hopping_total;
int ts_non_hopping_total;
+ const struct rate_ctr *activations_tch;
+ const struct rate_ctr *activations_sdcch;
vty_out(vty, "BTS %u is of %s type in band %s, has CI %u LAC %u, "
"BSIC %u (NCC=%u, BCC=%u) and %u TRX%s",
@@ -3851,6 +3853,29 @@ void bts_dump_vty(struct vty *vty, struct gsm_bts *bts)
rate_ctr_group_get_ctr(bts->bts_ctrs, BTS_CTR_CHREQ_TOTAL)->current,
rate_ctr_group_get_ctr(bts->bts_ctrs, BTS_CTR_CHREQ_NO_CHANNEL)->current,
VTY_NEWLINE);
+
+ vty_out(vty, " Channel Activations :%s", VTY_NEWLINE);
+ activations_tch = rate_ctr_group_get_ctr(bts->bts_ctrs, BTS_CTR_CHAN_ACT_TCH);
+ vty_out(vty, " TCH %"PRIu64"", activations_tch->current);
+ if (activations_tch->intv[RATE_CTR_INTV_HOUR].rate > 0) {
+ const struct rate_ctr *active_time_tch_ms = rate_ctr_group_get_ctr(bts->bts_ctrs, BTS_CTR_CHAN_TCH_ACTIVE_MILLISECONDS_TOTAL);
+ vty_out(vty, " (avg lifespan %s seconds in last hour)",
+ osmo_int_to_float_str_c(OTC_SELECT,
+ active_time_tch_ms->intv[RATE_CTR_INTV_HOUR].rate
+ / activations_tch->intv[RATE_CTR_INTV_HOUR].rate, 3));
+ }
+ vty_out(vty, "%s", VTY_NEWLINE);
+ activations_sdcch = rate_ctr_group_get_ctr(bts->bts_ctrs, BTS_CTR_CHAN_ACT_SDCCH);
+ vty_out(vty, " SDCCH %"PRIu64"", activations_sdcch->current);
+ if (activations_sdcch->intv[RATE_CTR_INTV_HOUR].rate > 0) {
+ const struct rate_ctr *active_time_sdcch_ms = rate_ctr_group_get_ctr(bts->bts_ctrs, BTS_CTR_CHAN_SDCCH_ACTIVE_MILLISECONDS_TOTAL);
+ vty_out(vty, " (avg lifespan %s seconds in last hour)",
+ osmo_int_to_float_str_c(OTC_SELECT,
+ active_time_sdcch_ms->intv[RATE_CTR_INTV_HOUR].rate
+ / activations_sdcch->intv[RATE_CTR_INTV_HOUR].rate, 3));
+ }
+ vty_out(vty, "%s", VTY_NEWLINE);
+
vty_out(vty, " Channel Failures : %"PRIu64" rf_failures, %"PRIu64" rll failures%s",
rate_ctr_group_get_ctr(bts->bts_ctrs, BTS_CTR_CHAN_RF_FAIL)->current,
rate_ctr_group_get_ctr(bts->bts_ctrs, BTS_CTR_CHAN_RLL_ERR)->current,
diff --git a/src/osmo-bsc/gsm_data.c b/src/osmo-bsc/gsm_data.c
index 22be92db1..64c348f35 100644
--- a/src/osmo-bsc/gsm_data.c
+++ b/src/osmo-bsc/gsm_data.c
@@ -342,6 +342,21 @@ void lchan_update_name(struct gsm_lchan *lchan)
lchan->nr - (lchan->vamos.is_secondary ? ts->max_primary_lchans : 0));
}
+/* If the lchan is currently active, return the duration since activation in milliseconds.
+ * Otherwise return 0. */
+uint64_t gsm_lchan_active_duration_ms(const struct gsm_lchan *lchan)
+{
+ struct timespec now, elapsed;
+
+ if (lchan->active_start.tv_sec == 0 && lchan->active_start.tv_nsec == 0)
+ return 0;
+
+ osmo_clock_gettime(CLOCK_MONOTONIC, &now);
+ timespecsub(&now, &lchan->active_start, &elapsed);
+
+ return elapsed.tv_sec * 1000 + elapsed.tv_nsec / 1000000;
+}
+
/* obtain the MO structure for a given object instance */
static inline struct gsm_abis_mo *
gsm_objclass2mo(struct gsm_bts *bts, uint8_t obj_class,
diff --git a/src/osmo-bsc/lchan_fsm.c b/src/osmo-bsc/lchan_fsm.c
index 5df6c5710..1c85ff30e 100644
--- a/src/osmo-bsc/lchan_fsm.c
+++ b/src/osmo-bsc/lchan_fsm.c
@@ -204,6 +204,10 @@ static void lchan_on_fully_established(struct gsm_lchan *lchan)
return;
lchan->activate.concluded = true;
+ /* Set active state timekeeping markers. */
+ osmo_clock_gettime(CLOCK_MONOTONIC, &lchan->active_start);
+ lchan->active_stored = lchan->active_start;
+
switch (lchan->activate.info.activ_for) {
case ACTIVATE_FOR_MS_CHANNEL_REQUEST:
/* No signalling to do here, MS is free to use the channel, and should go on to connect