iedemam has uploaded this change for review.

View Change

WIP: New stats for lchan life duration.

Change-Id: I1b0670c47cb5e0b7776eda89d1e71545ba0e3347
---
M include/osmocom/bsc/bts.h
M include/osmocom/bsc/gsm_data.h
M src/osmo-bsc/bts.c
M src/osmo-bsc/bts_trx_vty.c
M src/osmo-bsc/bts_vty.c
M src/osmo-bsc/gsm_data.c
M src/osmo-bsc/lchan_fsm.c
7 files changed, 61 insertions(+), 0 deletions(-)

git pull ssh://gerrit.osmocom.org:29418/osmo-bsc refs/changes/81/27081/1
diff --git a/include/osmocom/bsc/bts.h b/include/osmocom/bsc/bts.h
index c4ee39d..f4c96da 100644
--- a/include/osmocom/bsc/bts.h
+++ b/include/osmocom/bsc/bts.h
@@ -74,6 +74,8 @@
BTS_CTR_LCHAN_BORKEN_EV_TS_ERROR,
BTS_CTR_LCHAN_BORKEN_FROM_WAIT_RR_CHAN_MODE_MODIFY_ACK,
BTS_CTR_LCHAN_BORKEN_FROM_WAIT_RSL_CHAN_MODE_MODIFY_ACK,
+ BTS_CTR_LCHAN_TCH_TOTAL_ACTIVE_MILLISECONDS,
+ BTS_CTR_LCHAN_SDCCH_TOTAL_ACTIVE_MILLISECONDS,
BTS_CTR_TS_BORKEN_FROM_NOT_INITIALIZED,
BTS_CTR_TS_BORKEN_FROM_UNUSED,
BTS_CTR_TS_BORKEN_FROM_WAIT_PDCH_ACT,
diff --git a/include/osmocom/bsc/gsm_data.h b/include/osmocom/bsc/gsm_data.h
index 910c3d3..017aff9 100644
--- a/include/osmocom/bsc/gsm_data.h
+++ b/include/osmocom/bsc/gsm_data.h
@@ -748,6 +748,8 @@
* sent ACKs like Immediate Assignment or BSSMAP Assignment Complete, and if other errors
* occur later, e.g. during release, that we don't send a NACK out of context. */
bool concluded;
+ /* Interval timing to capture duration per activation and cummulative active time */
+ struct timespec concluded_timestamp;
enum gsm0808_cause gsm0808_error_cause;
/* Actually used TSC Set. */
int tsc_set;
@@ -1125,6 +1127,7 @@
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);
+long long gsm_lchan_active_duration_ms(const struct gsm_lchan *lchan);

static inline char *gsm_lchan_name(const struct gsm_lchan *lchan)
{
diff --git a/src/osmo-bsc/bts.c b/src/osmo-bsc/bts.c
index 1461585..85161e0 100644
--- a/src/osmo-bsc/bts.c
+++ b/src/osmo-bsc/bts.c
@@ -1082,6 +1082,12 @@
[BTS_CTR_LCHAN_BORKEN_EV_TS_ERROR] = \
{ "lchan_borken:event:ts_error",
"LCHAN_EV_TS_ERROR received in a BORKEN state" },
+ [BTS_CTR_LCHAN_TCH_TOTAL_ACTIVE_MILLISECONDS] = \
+ { "lchan_tch:total:active_milliseconds",
+ "Cummulative number of active milliseconds on TCH lchans" },
+ [BTS_CTR_LCHAN_SDCCH_TOTAL_ACTIVE_MILLISECONDS] = \
+ { "lchan_sdcch:total:active_milliseconds",
+ "Cummulative number of active milliseconds on SDCCH lchans" },
[BTS_CTR_TS_BORKEN_FROM_NOT_INITIALIZED] = \
{ "ts_borken:from_state:not_initialized",
"Transitions from TS NOT_INITIALIZED state to BORKEN state" },
diff --git a/src/osmo-bsc/bts_trx_vty.c b/src/osmo-bsc/bts_trx_vty.c
index 39584a5..9ef57ad 100644
--- a/src/osmo-bsc/bts_trx_vty.c
+++ b/src/osmo-bsc/bts_trx_vty.c
@@ -569,6 +569,12 @@
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) {
+ long long duration_ms = gsm_lchan_active_duration_ms(lchan);
+ vty_out(vty, " Activated %llu ms ago%s", duration_ms, 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 0c7259b..b06b9a8 100644
--- a/src/osmo-bsc/bts_vty.c
+++ b/src/osmo-bsc/bts_vty.c
@@ -3822,6 +3822,22 @@
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);
+
+ uint64_t activations_tch = rate_ctr_group_get_ctr(bts->bts_ctrs, BTS_CTR_CHAN_ACT_TCH)->current;
+ uint64_t activations_sdcch = rate_ctr_group_get_ctr(bts->bts_ctrs, BTS_CTR_CHAN_ACT_SDCCH)->current;
+ uint64_t duration_tch = rate_ctr_group_get_ctr(bts->bts_ctrs, BTS_CTR_LCHAN_TCH_TOTAL_ACTIVE_MILLISECONDS)->current;
+ uint64_t duration_sdcch = rate_ctr_group_get_ctr(bts->bts_ctrs, BTS_CTR_LCHAN_SDCCH_TOTAL_ACTIVE_MILLISECONDS)->current;
+ vty_out(vty, " Channel Activations : %"PRIu64" TCH", activations_tch);
+ if (activations_tch > 0) {
+ vty_out(vty, " (average lifespan %"PRIu64" ms)", duration_tch / activations_tch);
+ }
+ vty_out(vty, "%s", VTY_NEWLINE);
+ vty_out(vty, " %"PRIu64" SDCCH", activations_sdcch);
+ if (activations_sdcch > 0) {
+ vty_out(vty, " (average lifespan %"PRIu64" ms)", duration_sdcch / activations_sdcch);
+ }
+ 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 38d8a7c..1d165f5 100644
--- a/src/osmo-bsc/gsm_data.c
+++ b/src/osmo-bsc/gsm_data.c
@@ -345,6 +345,19 @@
lchan->nr - (lchan->vamos.is_secondary ? ts->max_primary_lchans : 0));
}

+/* Get duration of active time for this lchan in milliseconds */
+long long gsm_lchan_active_duration_ms(const struct gsm_lchan *lchan) {
+ long long duration = 0;
+ if (lchan->activate.concluded) {
+ struct timespec now;
+ struct timespec elapsed;
+ osmo_clock_gettime(CLOCK_MONOTONIC, &now);
+ timespecsub(&now, &lchan->activate.concluded_timestamp, &elapsed);
+ duration = elapsed.tv_sec * 1000LL + elapsed.tv_nsec / 1000000;
+ }
+ return duration;
+}
+
/* 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 84f8dc5..e9dbc9f 100644
--- a/src/osmo-bsc/lchan_fsm.c
+++ b/src/osmo-bsc/lchan_fsm.c
@@ -203,6 +203,7 @@
if (lchan->activate.concluded)
return;
lchan->activate.concluded = true;
+ osmo_clock_gettime(CLOCK_MONOTONIC, &lchan->activate.concluded_timestamp);

switch (lchan->activate.info.activ_for) {
case ACTIVATE_FOR_MS_CHANNEL_REQUEST:
@@ -1806,6 +1807,20 @@
if (!lchan || !lchan->fi || lchan->fi->state == LCHAN_ST_UNUSED)
return;

+
+ /* Add active milliseconds to cummulative counts per channel type */
+ long long duration_ms = gsm_lchan_active_duration_ms(lchan);
+ struct rate_ctr_group *bts_ctrs = lchan->ts->trx->bts->bts_ctrs;
+ if (lchan->type == GSM_LCHAN_TCH_F || lchan->type == GSM_LCHAN_TCH_H) {
+ LOG_LCHAN(lchan, LOGL_INFO, "GSM_LCHAN_TCH was active for %llu milliseconds\n", duration_ms);
+ rate_ctr_add(rate_ctr_group_get_ctr(bts_ctrs, BTS_CTR_LCHAN_TCH_TOTAL_ACTIVE_MILLISECONDS), duration_ms);
+ } else if (lchan->type == GSM_LCHAN_SDCCH) {
+ LOG_LCHAN(lchan, LOGL_INFO, "GSM_LCHAN_SDCCH was active for %llu milliseconds\n", duration_ms);
+ rate_ctr_add(rate_ctr_group_get_ctr(bts_ctrs, BTS_CTR_LCHAN_SDCCH_TOTAL_ACTIVE_MILLISECONDS), duration_ms);
+ } else {
+ LOG_LCHAN(lchan, LOGL_NOTICE, "UNKNOWN CHANNEL TYPE was active for %llu milliseconds\n", duration_ms);
+ }
+
if (lchan->release.in_release_handler)
return;
lchan->release.in_release_handler = true;

To view, visit change 27081. To unsubscribe, or for help writing mail filters, visit settings.

Gerrit-Project: osmo-bsc
Gerrit-Branch: master
Gerrit-Change-Id: I1b0670c47cb5e0b7776eda89d1e71545ba0e3347
Gerrit-Change-Number: 27081
Gerrit-PatchSet: 1
Gerrit-Owner: iedemam <michael@kapsulate.com>
Gerrit-MessageType: newchange