aboutsummaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
authorNeels Hofmeyr <neels@hofmeyr.de>2018-02-12 17:25:04 +0100
committerNeels Hofmeyr <neels@hofmeyr.de>2018-02-16 16:11:16 +0100
commitcbc999cb93ce5cf5fcc4e169ef3db7f1ef074c5d (patch)
tree98af593eb725fbb16c458c512a9c874579e3e7f4
parent05a3a2d5a7b780219e969b6ba2661b7e977f98ac (diff)
HO: logging: more logs, and more concise logging
Explicitly log "Handover" or "Assignment", add more info to existing log statements and add more log statements. Log ho failure both on RR and HO log categories: RR receives the HO failure message, while the HO failure is an important event to note when watching the HO category. Change-Id: Ia3999755cdd4e0c2861582b20e2dbb7e1538e074
-rw-r--r--src/libbsc/bsc_api.c4
-rw-r--r--src/libbsc/handover_logic.c52
2 files changed, 41 insertions, 15 deletions
diff --git a/src/libbsc/bsc_api.c b/src/libbsc/bsc_api.c
index 21836f3..d81bf0d 100644
--- a/src/libbsc/bsc_api.c
+++ b/src/libbsc/bsc_api.c
@@ -675,8 +675,8 @@ static void handle_rr_ho_fail(struct msgb *msg)
struct lchan_signal_data sig;
struct gsm48_hdr *gh = msgb_l3(msg);
- DEBUGP(DRR, "HANDOVER FAILED cause = %s\n",
- rr_cause_name(gh->data[0]));
+ DEBUGP(DRR, "HANDOVER FAILED cause = %s\n", rr_cause_name(gh->data[0]));
+ DEBUGP(DHO, "HANDOVER FAILED cause = %s\n", rr_cause_name(gh->data[0]));
sig.lchan = msg->lchan;
sig.mr = NULL;
diff --git a/src/libbsc/handover_logic.c b/src/libbsc/handover_logic.c
index 52e5dd3..3dd7227 100644
--- a/src/libbsc/handover_logic.c
+++ b/src/libbsc/handover_logic.c
@@ -40,6 +40,26 @@
#include <osmocom/bsc/gsm_04_08_utils.h>
#include <osmocom/bsc/handover.h>
+#define LOGPHOLCHANTOLCHAN(lchan, new_lchan, level, fmt, args...) \
+ LOGP(DHODEC, level, "(BTS %u trx %u arfcn %u ts %u lchan %u %s)->(BTS %u trx %u arfcn %u ts %u lchan %u %s) (subscr %s) " fmt, \
+ lchan->ts->trx->bts->nr, \
+ lchan->ts->trx->nr, \
+ lchan->ts->trx->arfcn, \
+ lchan->ts->nr, \
+ lchan->nr, \
+ gsm_pchan_name(lchan->ts->pchan), \
+ new_lchan->ts->trx->bts->nr, \
+ new_lchan->ts->trx->nr, \
+ new_lchan->ts->trx->arfcn, \
+ new_lchan->ts->nr, \
+ new_lchan->nr, \
+ gsm_pchan_name(new_lchan->ts->pchan), \
+ bsc_subscr_name(lchan->conn->bsub), \
+ ## args)
+
+#define LOGPHO(struct_bsc_handover, level, fmt, args ...) \
+ LOGPHOLCHANTOLCHAN(struct_bsc_handover->old_lchan, struct_bsc_handover->new_lchan, level, fmt, ## args)
+
struct bsc_handover {
struct llist_head list;
@@ -105,10 +125,6 @@ int bsc_handover_start(struct gsm_lchan *old_lchan, struct gsm_bts *new_bts,
if (bsc_ho_by_old_lchan(old_lchan))
return -EBUSY;
- DEBUGP(DHO, "Beginning with handover operation"
- "(old_lchan on BTS %u, new BTS %u) ...\n",
- old_lchan->ts->trx->bts->nr, new_bts->nr);
- /* No new BTS? Then it shall be assignment within the same BTS. */
if (!new_bts)
new_bts = old_lchan->ts->trx->bts;
do_assignment = (new_bts == old_lchan->ts->trx->bts);
@@ -122,6 +138,15 @@ int bsc_handover_start(struct gsm_lchan *old_lchan, struct gsm_bts *new_bts,
return -ENOSPC;
}
+ DEBUGP(DHO, "(BTS %u trx %u ts %u lchan %u %s)->(BTS %u lchan %s) Beginning with handover operation...\n",
+ old_lchan->ts->trx->bts->nr,
+ old_lchan->ts->trx->nr,
+ old_lchan->ts->nr,
+ old_lchan->nr,
+ gsm_pchan_name(old_lchan->ts->pchan),
+ new_bts->nr,
+ gsm_lchant_name(new_lchan_type));
+
new_lchan = lchan_alloc(new_bts, new_lchan_type, 0);
if (!new_lchan) {
LOGP(DHO, LOGL_NOTICE, "No free channel for %s\n", gsm_lchant_name(new_lchan_type));
@@ -141,6 +166,8 @@ int bsc_handover_start(struct gsm_lchan *old_lchan, struct gsm_bts *new_bts,
ho->inter_cell = !do_assignment;
ho->async = true;
+ LOGPHO(ho, LOGL_INFO, "Triggering %s\n", do_assignment? "Assignment" : "Handover");
+
/* copy some parameters from old lchan */
memcpy(&new_lchan->encr, &old_lchan->encr, sizeof(new_lchan->encr));
if (do_assignment) {
@@ -165,7 +192,8 @@ int bsc_handover_start(struct gsm_lchan *old_lchan, struct gsm_bts *new_bts,
ho->async ? RSL_ACT_INTER_ASYNC : RSL_ACT_INTER_SYNC,
ho->ho_ref);
if (rc < 0) {
- LOGP(DHO, LOGL_ERROR, "could not activate channel\n");
+ LOGPHO(ho, LOGL_INFO, "%s Failure: activate lchan rc = %d\n",
+ do_assignment? "Assignment" : "Handover", rc);
new_lchan->conn->ho_lchan = NULL;
new_lchan->conn = NULL;
talloc_free(ho);
@@ -231,7 +259,7 @@ static int ho_chan_activ_ack(struct gsm_lchan *new_lchan)
if (!ho)
return -ENODEV;
- DEBUGP(DHO, "handover activate ack, send HO Command\n");
+ LOGPHO(ho, LOGL_INFO, "Channel Activate Ack, send %s COMMAND\n", ho->inter_cell? "HANDOVER" : "ASSIGNMENT");
/* we can now send the 04.08 HANDOVER COMMAND to the MS
* using the old lchan */
@@ -283,10 +311,8 @@ static int ho_gsm48_ho_compl(struct gsm_lchan *new_lchan)
}
net = new_lchan->ts->trx->bts->network;
- LOGP(DHO, LOGL_INFO, "Subscriber %s HO from BTS %u->%u on ARFCN "
- "%u->%u\n", bsc_subscr_name(ho->old_lchan->conn->bsub),
- ho->old_lchan->ts->trx->bts->nr, new_lchan->ts->trx->bts->nr,
- ho->old_lchan->ts->trx->arfcn, new_lchan->ts->trx->arfcn);
+
+ LOGPHO(ho, LOGL_INFO, "%s Complete\n", ho->inter_cell ? "Handover" : "Assignment");
rate_ctr_inc(&net->bsc_ctrs->ctr[BSC_CTR_HANDOVER_COMPLETED]);
@@ -294,10 +320,10 @@ static int ho_gsm48_ho_compl(struct gsm_lchan *new_lchan)
/* Replace the ho lchan with the primary one */
if (ho->old_lchan != new_lchan->conn->lchan)
- LOGP(DHO, LOGL_ERROR, "Primary lchan changed during handover.\n");
+ LOGPHO(ho, LOGL_ERROR, "Primary lchan changed during handover.\n");
if (new_lchan != new_lchan->conn->ho_lchan)
- LOGP(DHO, LOGL_ERROR, "Handover channel changed during this handover.\n");
+ LOGPHO(ho, LOGL_ERROR, "Handover channel changed during this handover.\n");
new_lchan->conn->ho_lchan = NULL;
new_lchan->conn->lchan = new_lchan;
@@ -348,7 +374,7 @@ static int ho_rsl_detect(struct gsm_lchan *new_lchan)
return -ENODEV;
}
- LOGP(DHO, LOGL_DEBUG, "%s Handover RACH detected\n", gsm_lchan_name(new_lchan));
+ LOGPHO(ho, LOGL_DEBUG, "Handover RACH detected\n");
/* This is just for logging on the DHO category. The actual MGCP switchover happens in
* osmo_bsc_mgcp.c by receiving the same S_LCHAN_HANDOVER_DETECT signal.