Neels Hofmeyr has submitted this change and it was merged. (
https://gerrit.osmocom.org/10058 )
Change subject: hodec2 log: less verbose, more concise logging
......................................................................
hodec2 log: less verbose, more concise logging
Drop numerous log statements that merely bloat the ho decision log.
Logging HO candidates: log more compact in a single line, do not use LOGPC and
multiline output. The result is more useful information in a quarter of the log
lines.
LOGPHOLCHAN(), LOGPHOLCHANTOBTS():
- log lchan->type instead of lchan->ts->pchan
- always log the speech mode
===== Before =====
DHODEC handover_decision_2.c:1131 (lchan 0.010 TCH/F) (subscr IMSI:000001)
MEASUREMENT REPORT (1 neighbors)
DHODEC handover_decision_2.c:1136 (lchan 0.010 TCH/F) (subscr IMSI:000001) 0:
arfcn=871 bsic=63 neigh_idx=0 rxlev=30 flags=0
DHODEC handover_decision_2.c:261 (lchan 0.010 TCH/F) (subscr IMSI:000001) neigh
871 rxlev=30 last_seen_nr=3
DHODEC handover_decision_2.c:1158 (lchan 0.010 TCH/F) (subscr IMSI:000001)
HODEC2: evaluating measurement report
DHODEC handover_decision_2.c:1175 (lchan 0.010 TCH/F) (subscr IMSI:000001)
Measurement report: average RX level = -110
DHODEC handover_decision_2.c:1190 (lchan 0.010 TCH/F) (subscr IMSI:000001)
Virtually improving RX level from -110 to -105, due to AFS bias
DHODEC handover_decision_2.c:1220 (lchan 0.010 TCH/F) (subscr IMSI:000001)
Attempting handover/assignment due to low rxlev
DHODEC handover_decision_2.c:899 (lchan 0.010 TCH/F) (subscr IMSI:000001)
Collecting candidates for Assignment and Handover
DHODEC handover_decision_2.c:407 (lchan 0.010 TCH/F)->(BTS 0) (subscr
IMSI:000001) tch_mode='SPEECH_AMR' type='TCH_F'
DHODEC handover_decision_2.c:313 (lchan 0.010 TCH/F) (subscr IMSI:000001) FR3
supported
DHODEC handover_decision_2.c:313 (lchan 0.010 TCH/F) (subscr IMSI:000001) HR3
supported
DHODEC handover_decision_2.c:489 (lchan 0.010 TCH/F)->(BTS 0) (subscr
IMSI:000001) removing TCH/F, already on TCH/F in this cell
DHODEC handover_decision_2.c:573 (lchan 0.010 TCH/F)->(BTS 0) (subscr
IMSI:000001) TCH/H would not be congested after HO
DHODEC handover_decision_2.c:605 (lchan 0.010 TCH/F)->(BTS 0) (subscr
IMSI:000001) TCH/H would not be less congested in target than source cell after
HO
DHODEC handover_decision_2.c:609 (lchan 0.010 TCH/F)->(BTS 0) (subscr
IMSI:000001) requirements=0x30
DHODEC handover_decision_2.c:704 - current BTS 0, RX level -110
DHODEC handover_decision_2.c:707 o free TCH/F slots 3, minimum required 0
DHODEC handover_decision_2.c:709 o free TCH/H slots 4, minimum required 0
DHODEC handover_decision_2.c:714 o no requirement fulfilled for TCHF (no
assignment possible)
DHODEC handover_decision_2.c:737 o requirement A B fulfilled for TCHH (not
congested after assignment)
DHODEC handover_decision_2.c:407 (lchan 0.010 TCH/F)->(BTS 1) (subscr
IMSI:000001) tch_mode='SPEECH_AMR' type='TCH_F'
DHODEC handover_decision_2.c:313 (lchan 0.010 TCH/F) (subscr IMSI:000001) FR3
supported
DHODEC handover_decision_2.c:313 (lchan 0.010 TCH/F) (subscr IMSI:000001) HR3
supported
DHODEC handover_decision_2.c:563 (lchan 0.010 TCH/F)->(BTS 1) (subscr
IMSI:000001) TCH/F would not be congested after HO
DHODEC handover_decision_2.c:573 (lchan 0.010 TCH/F)->(BTS 1) (subscr
IMSI:000001) TCH/H would not be congested after HO
DHODEC handover_decision_2.c:595 (lchan 0.010 TCH/F)->(BTS 1) (subscr
IMSI:000001) TCH/F would not be less congested in target than source cell after
HO
DHODEC handover_decision_2.c:605 (lchan 0.010 TCH/F)->(BTS 1) (subscr
IMSI:000001) TCH/H would not be less congested in target than source cell after
HO
DHODEC handover_decision_2.c:609 (lchan 0.010 TCH/F)->(BTS 1) (subscr
IMSI:000001) requirements=0x33
DHODEC handover_decision_2.c:701 - neighbor BTS 1, RX level -110 -> -80
DHODEC handover_decision_2.c:707 o free TCH/F slots 4, minimum required 0
DHODEC handover_decision_2.c:709 o free TCH/H slots 4, minimum required 0
DHODEC handover_decision_2.c:712 o requirement A B fulfilled for TCHF (not
congested after handover)
DHODEC handover_decision_2.c:737 o requirement A B fulfilled for TCHH (not
congested after handover)
DHODEC handover_decision_2.c:914 (lchan 0.010 TCH/F) (subscr IMSI:000001)
adding 2 candidates from 1 neighbors, total 2
DHODEC handover_decision_2.c:1020 (lchan 0.010 TCH/F)->(BTS 1) (subscr
IMSI:000001) Best candidate, RX level -80
DHODEC handover_decision_2.c:625 (lchan 0.010 TCH/F)->(BTS 1) (subscr
IMSI:000001) Triggering Handover
DHODEC handover_decision_2.c:688 (lchan 0.010 TCH/F)->(BTS 1) (subscr
IMSI:000001) Triggering handover to TCH/F, due to low rxlevel
DHO handover_logic.c:133 (BTS 0 trx 0 ts 1 lchan 0 TCH/F)->(BTS 1 lchan TCH_F)
Initiating Handover...
DMSC handover_logic.c:135 SUBSCR_CONN[0x612000000520]{ACTIVE}: Received Event
HO_START
DHODEC handover_logic.c:172 (BTS 0 trx 0 arfcn 870 ts 1 lchan 0 TCH/F)->(BTS 1
trx 0 arfcn 871 ts 1 lchan 0 TCH/F) (subscr IMSI:000001) Triggering Handover
===== After =====
DHODEC handover_decision_2.c:1039 (lchan 0.010 TCH_F SPEECH_AMR) (subscr
IMSI:000001) MEASUREMENT REPORT (1 neighbors)
DHODEC handover_decision_2.c:1044 (lchan 0.010 TCH_F SPEECH_AMR) (subscr
IMSI:000001) 0: arfcn=871 bsic=63 neigh_idx=0 rxlev=30 flags=0
DHODEC handover_decision_2.c:1097 (lchan 0.010 TCH_F SPEECH_AMR) (subscr
IMSI:000001) Avg RX level = -110 dBm, +5 dBm AFS bias = -105 dBm; Avg RX
quality = -1 (invalid), +0 AFS bias = -1
DHODEC handover_decision_2.c:1122 (lchan 0.010 TCH_F SPEECH_AMR) (subscr
IMSI:000001) RX level is TOO LOW: -105 < -100
DHODEC handover_decision_2.c:677 (lchan 0.010 TCH_F SPEECH_AMR)->(BTS 0)
(subscr IMSI:000001) RX level -110; TCH/F={free 3 (want 0), [-] not a
candidate}; TCH/H={free 4 (want 0), [ABC] good}
DHODEC handover_decision_2.c:671 (lchan 0.010 TCH_F SPEECH_AMR)->(BTS 1)
(subscr IMSI:000001) RX level -110 -> -80; TCH/F={free 4 (want 0), [ABC] good};
TCH/H={free 4 (want 0), [ABC] good}
DHODEC handover_decision_2.c:928 (lchan 0.010 TCH_F SPEECH_AMR)->(BTS 1)
(subscr IMSI:000001) Best candidate, RX level -80
DHODEC handover_decision_2.c:641 (lchan 0.010 TCH_F SPEECH_AMR)->(BTS 1)
(subscr IMSI:000001) Triggering handover to TCH/F, due to low rxlevel
DMSC handover_logic.c:125 SUBSCR_CONN[0x612000000520]{ACTIVE}: Received Event
HO_START
DHODEC handover_logic.c:169 (BTS 0 trx 0 arfcn 870 ts 1 lchan 0 TCH_F
SPEECH_AMR)->(BTS 1 trx 0 arfcn 871 ts 1 lchan 0 TCH/F) (subscr IMSI:000001)
Triggering Handover
Change-Id: If1add9b57a051d32b67a4a08ab47a9655aa9dd17
---
M include/osmocom/bsc/handover.h
M src/osmo-bsc/handover_decision.c
M src/osmo-bsc/handover_decision_2.c
M src/osmo-bsc/handover_logic.c
4 files changed, 81 insertions(+), 222 deletions(-)
Approvals:
Jenkins Builder: Verified
Harald Welte: Looks good to me, approved
diff --git a/include/osmocom/bsc/handover.h b/include/osmocom/bsc/handover.h
index eb03f6a..772ab98 100644
--- a/include/osmocom/bsc/handover.h
+++ b/include/osmocom/bsc/handover.h
@@ -12,13 +12,14 @@
struct gsm_meas_rep mr;
#define LOGPHOLCHANTOLCHAN(old_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, \
+ LOGP(DHODEC, level, "(BTS %u trx %u arfcn %u ts %u lchan %u %s
%s)->(BTS %u trx %u arfcn %u ts %u lchan %u %s) (subscr %s) " fmt, \
old_lchan->ts->trx->bts->nr, \
old_lchan->ts->trx->nr, \
old_lchan->ts->trx->arfcn, \
old_lchan->ts->nr, \
old_lchan->nr, \
- gsm_pchan_name(old_lchan->ts->pchan), \
+ gsm_lchant_name(old_lchan->type), \
+ gsm48_chan_mode_name(old_lchan->tch_mode), \
new_lchan->ts->trx->bts->nr, \
new_lchan->ts->trx->nr, \
new_lchan->ts->trx->arfcn, \
diff --git a/src/osmo-bsc/handover_decision.c b/src/osmo-bsc/handover_decision.c
index 887c299..0e79023 100644
--- a/src/osmo-bsc/handover_decision.c
+++ b/src/osmo-bsc/handover_decision.c
@@ -201,7 +201,10 @@
struct gsm_bts *bts = mr->lchan->ts->trx->bts;
struct neigh_meas_proc *best_cell = NULL;
unsigned int best_better_db = 0;
- int i, rc;
+ int i;
+
+ if (!ho_get_ho_active(bts->ho))
+ return 0;
/* find the best cell in this report that is at least RXLEV_HYST
* better than the current serving cell */
@@ -231,28 +234,7 @@
if (!best_cell)
return 0;
- LOGP(DHODEC, LOGL_INFO, "%s: Cell on ARFCN %u is better: ",
- gsm_ts_name(mr->lchan->ts), best_cell->arfcn);
- if (!ho_get_ho_active(bts->ho)) {
- LOGPC(DHODEC, LOGL_INFO, "Skipping, Handover disabled\n");
- return 0;
- }
-
- rc = handover_to_arfcn_bsic(mr->lchan, best_cell->arfcn,
best_cell->bsic);
- switch (rc) {
- case 0:
- LOGPC(DHODEC, LOGL_INFO, "Starting handover: meas report number
%d \n", mr->nr);
- break;
- case -ENOSPC:
- LOGPC(DHODEC, LOGL_INFO, "No channel available\n");
- break;
- case -EBUSY:
- LOGPC(DHODEC, LOGL_INFO, "Handover already active\n");
- break;
- default:
- LOGPC(DHODEC, LOGL_ERROR, "Unknown error\n");
- }
- return rc;
+ return handover_to_arfcn_bsic(mr->lchan, best_cell->arfcn,
best_cell->bsic);
}
/* process an already parsed measurement report and decide if we want to
diff --git a/src/osmo-bsc/handover_decision_2.c
b/src/osmo-bsc/handover_decision_2.c
index 7ac54df..e514b6c 100644
--- a/src/osmo-bsc/handover_decision_2.c
+++ b/src/osmo-bsc/handover_decision_2.c
@@ -40,22 +40,24 @@
LOGP(DHODEC, level, "(BTS %u) " fmt, bts->nr, ## args)
#define LOGPHOLCHAN(lchan, level, fmt, args...) \
- LOGP(DHODEC, level, "(lchan %u.%u%u%u %s) (subscr %s) " fmt, \
+ LOGP(DHODEC, level, "(lchan %u.%u%u%u %s %s) (subscr %s) " fmt, \
lchan->ts->trx->bts->nr, \
lchan->ts->trx->nr, \
lchan->ts->nr, \
lchan->nr, \
- gsm_pchan_name(lchan->ts->pchan), \
+ gsm_lchant_name(lchan->type), \
+ gsm48_chan_mode_name(lchan->tch_mode), \
bsc_subscr_name(lchan->conn? lchan->conn->bsub : NULL), \
## args)
#define LOGPHOLCHANTOBTS(lchan, new_bts, level, fmt, args...) \
- LOGP(DHODEC, level, "(lchan %u.%u%u%u %s)->(BTS %u) (subscr %s) " fmt, \
+ LOGP(DHODEC, level, "(lchan %u.%u%u%u %s %s)->(BTS %u) (subscr %s) "
fmt, \
lchan->ts->trx->bts->nr, \
lchan->ts->trx->nr, \
lchan->ts->nr, \
lchan->nr, \
- gsm_pchan_name(lchan->ts->pchan), \
+ gsm_lchant_name(lchan->type), \
+ gsm48_chan_mode_name(lchan->tch_mode), \
new_bts->nr, \
bsc_subscr_name(lchan->conn? lchan->conn->bsub : NULL), \
## args)
@@ -257,13 +259,9 @@
if (mrc) {
nmp->rxlev[idx] = mrc->rxlev;
nmp->last_seen_nr = mr->nr;
- LOGPHOLCHAN(mr->lchan, LOGL_DEBUG, "neigh %u rxlev=%d
last_seen_nr=%u\n",
- nmp->arfcn, mrc->rxlev, nmp->last_seen_nr);
mrc->flags |= MRC_F_PROCESSED;
} else {
nmp->rxlev[idx] = 0;
- LOGPHOLCHAN(mr->lchan, LOGL_DEBUG, "neigh %u not in
report (last_seen_nr=%u)\n",
- nmp->arfcn, nmp->last_seen_nr);
}
nmp->rxlev_cnt++;
}
@@ -308,11 +306,8 @@
}
for (i = 0; i < clist->len; i++) {
- if (clist->codec[i].type == type) {
- LOGPHOLCHAN(conn->lchan, LOGL_DEBUG, "%s supported\n",
- gsm0808_speech_codec_type_name(type));
+ if (clist->codec[i].type == type)
return true;
- }
}
LOGPHOLCHAN(conn->lchan, LOGL_DEBUG, "Codec not supported by MS or not
allowed by MSC: %s\n",
gsm0808_speech_codec_type_name(type));
@@ -402,10 +397,6 @@
return 0;
}
- LOGPHOLCHANTOBTS(lchan, bts, LOGL_DEBUG, "tch_mode='%s' type='%s'\n",
- get_value_string(gsm48_chan_mode_names,
lchan->tch_mode),
- gsm_lchant_name(lchan->type));
-
/* compatibility check for codecs.
* if so, the candidates for full rate and half rate are selected */
switch (lchan->tch_mode) {
@@ -413,9 +404,6 @@
switch (lchan->type) {
case GSM_LCHAN_TCH_F: /* mandatory */
requirement |= REQUIREMENT_A_TCHF;
- LOGPHOLCHANTOBTS(lchan, bts, LOGL_DEBUG, "tch_mode='%s'
type='%s' supported\n",
-
get_value_string(gsm48_chan_mode_names, lchan->tch_mode),
- gsm_lchant_name(lchan->type));
break;
case GSM_LCHAN_TCH_H:
if (!bts->codec.hr) {
@@ -485,13 +473,9 @@
if (bts == current_bts) {
switch (lchan->type) {
case GSM_LCHAN_TCH_F:
- LOGPHOLCHANTOBTS(lchan, bts, LOGL_DEBUG,
- "removing TCH/F, already on TCH/F in
this cell\n");
requirement &= ~(REQUIREMENT_A_TCHF);
break;
case GSM_LCHAN_TCH_H:
- LOGPHOLCHANTOBTS(lchan, bts, LOGL_DEBUG,
- "removing TCH/H, already on TCH/H in
this cell\n");
requirement &= ~(REQUIREMENT_A_TCHH);
break;
default:
@@ -558,24 +542,12 @@
/* the minimum free timeslots that are defined for this cell must
* be maintained _after_ handover/assignment */
if (requirement & REQUIREMENT_A_TCHF) {
- if (tchf_count - 1 >= ho_get_hodec2_tchf_min_slots(bts->ho)) {
- LOGPHOLCHANTOBTS(lchan, bts, LOGL_DEBUG,
- "TCH/F would not be congested after
HO\n");
+ if (tchf_count - 1 >= ho_get_hodec2_tchf_min_slots(bts->ho))
requirement |= REQUIREMENT_B_TCHF;
- } else {
- LOGPHOLCHANTOBTS(lchan, bts, LOGL_DEBUG,
- "TCH/F would be congested after HO\n");
- }
}
if (requirement & REQUIREMENT_A_TCHH) {
- if (tchh_count - 1 >= ho_get_hodec2_tchh_min_slots(bts->ho)) {
- LOGPHOLCHANTOBTS(lchan, bts, LOGL_DEBUG,
- "TCH/H would not be congested after
HO\n");
+ if (tchh_count - 1 >= ho_get_hodec2_tchh_min_slots(bts->ho))
requirement |= REQUIREMENT_B_TCHH;
- } else {
- LOGPHOLCHANTOBTS(lchan, bts, LOGL_DEBUG,
- "TCH/H would be congested after HO\n");
- }
}
/* Requirement C */
@@ -584,30 +556,16 @@
* free slots of the current cell _after_ handover/assignment */
count = bts_count_free_ts(current_bts,
(lchan->type == GSM_LCHAN_TCH_H) ?
- GSM_PCHAN_TCH_H : GSM_PCHAN_TCH_F);
+ GSM_PCHAN_TCH_H : GSM_PCHAN_TCH_F);
if (requirement & REQUIREMENT_A_TCHF) {
- if (tchf_count - 1 >= count + 1) {
- LOGPHOLCHANTOBTS(lchan, bts, LOGL_DEBUG,
- "TCH/F would be less congested in
target than source cell after HO\n");
+ if (tchf_count - 1 >= count + 1)
requirement |= REQUIREMENT_C_TCHF;
- } else {
- LOGPHOLCHANTOBTS(lchan, bts, LOGL_DEBUG,
- "TCH/F would not be less congested in
target than source cell after HO\n");
- }
}
if (requirement & REQUIREMENT_A_TCHH) {
- if (tchh_count - 1 >= count + 1) {
- LOGPHOLCHANTOBTS(lchan, bts, LOGL_DEBUG,
- "TCH/H would be less congested in
target than source cell after HO\n");
+ if (tchh_count - 1 >= count + 1)
requirement |= REQUIREMENT_C_TCHH;
- } else {
- LOGPHOLCHANTOBTS(lchan, bts, LOGL_DEBUG,
- "TCH/H would not be less congested in
target than source cell after HO\n");
- }
}
- LOGPHOLCHANTOBTS(lchan, bts, LOGL_DEBUG, "requirements=0x%x\n",
requirement);
-
/* return mask of fulfilled requirements */
return requirement;
}
@@ -619,11 +577,6 @@
int afs_bias = 0;
bool full_rate = false;
- if (current_bts == new_bts)
- LOGPHOLCHAN(lchan, LOGL_NOTICE, "Triggering Assignment\n");
- else
- LOGPHOLCHANTOBTS(lchan, new_bts, LOGL_NOTICE, "Triggering
Handover\n");
-
/* afs_bias becomes > 0, if AFS is used and is improved */
if (lchan->tch_mode == GSM48_CMODE_SPEECH_AMR)
afs_bias = ho_get_hodec2_afs_bias_rxlev(new_bts->ho);
@@ -682,7 +635,7 @@
full_rate ? "TCH/F" : "TCH/H",
ho_reason_name(global_ho_reason));
else
- LOGPHOLCHANTOBTS(lchan, new_bts, LOGL_NOTICE,
+ LOGPHOLCHANTOBTS(lchan, new_bts, LOGL_INFO,
"Triggering handover to %s, due to %s\n",
full_rate ? "TCH/F" : "TCH/H",
ho_reason_name(global_ho_reason));
@@ -692,71 +645,36 @@
}
/* debug collected candidates */
-static inline void debug_candidate(struct ho_candidate *candidate,
- int neighbor, int8_t rxlev, int tchf_count, int tchh_count)
+static inline void debug_candidate(struct gsm_lchan *lchan, struct
ho_candidate *candidate,
+ struct gsm_bts *neighbor, int8_t rxlev, int tchf_count, int tchh_count)
{
+#define HO_CANDIDATE_FMT(tchx, TCHX) "TCH/" #TCHX "={free %d (want %d),
[%s%s%s]%s}"
+#define HO_CANDIDATE_ARGS(tchx, TCHX) \
+ tch##tchx##_count,
ho_get_hodec2_tch##tchx##_min_slots(candidate->bts->ho), \
+ candidate->requirements & REQUIREMENT_A_TCH##TCHX ? "A" : \
+ (candidate->requirements & REQUIREMENT_TCH##TCHX##_MASK) == 0?
"-" : "", \
+ candidate->requirements & REQUIREMENT_B_TCH##TCHX ? "B" : "", \
+ candidate->requirements & REQUIREMENT_B_TCH##TCHX ? "C" : "", \
+ (candidate->requirements & REQUIREMENT_TCH##TCHX##_MASK) == 0 ? "
not a candidate" : \
+ ((candidate->requirements & REQUIREMENT_TCH##TCHX##_MASK) ==
REQUIREMENT_A_TCH##TCHX ? \
+ " more congestion" : \
+ (candidate->requirements & REQUIREMENT_B_TCH##TCHX ? \
+ " good" : \
+ /* now has to be candidate->requirements & REQUIREMENT_C_TCHX
!= 0: */ \
+ " less-or-equal congestion"))
+
if (neighbor)
- LOGP(DHODEC, LOGL_DEBUG, " - neighbor BTS %d, RX level "
- "%d -> %d\n", candidate->bts->nr, rxlev2dbm(rxlev),
- rxlev2dbm(candidate->avg));
+ LOGPHOLCHANTOBTS(lchan, neighbor, LOGL_DEBUG,
+ "RX level %d -> %d; "
+ HO_CANDIDATE_FMT(f, F) "; " HO_CANDIDATE_FMT(h, H) "\n",
+ rxlev2dbm(rxlev), rxlev2dbm(candidate->avg),
+ HO_CANDIDATE_ARGS(f, F), HO_CANDIDATE_ARGS(h, H));
else
- LOGP(DHODEC, LOGL_DEBUG, " - current BTS %d, RX level %d\n",
- candidate->bts->nr, rxlev2dbm(candidate->avg));
-
- LOGP(DHODEC, LOGL_DEBUG, " o free TCH/F slots %d, minimum required "
- "%d\n", tchf_count,
ho_get_hodec2_tchf_min_slots(candidate->bts->ho));
- LOGP(DHODEC, LOGL_DEBUG, " o free TCH/H slots %d, minimum required "
- "%d\n", tchh_count,
ho_get_hodec2_tchh_min_slots(candidate->bts->ho));
-
- if ((candidate->requirements & REQUIREMENT_TCHF_MASK))
- LOGP(DHODEC, LOGL_DEBUG, " o requirement ");
- else
- LOGP(DHODEC, LOGL_DEBUG, " o no requirement ");
- if ((candidate->requirements & REQUIREMENT_A_TCHF))
- LOGPC(DHODEC, LOGL_DEBUG, "A ");
- if ((candidate->requirements & REQUIREMENT_B_TCHF))
- LOGPC(DHODEC, LOGL_DEBUG, "B ");
- if ((candidate->requirements & REQUIREMENT_C_TCHF))
- LOGPC(DHODEC, LOGL_DEBUG, "C ");
- LOGPC(DHODEC, LOGL_DEBUG, "fulfilled for TCHF");
- if (!(candidate->requirements & REQUIREMENT_TCHF_MASK)) /* nothing */
- LOGPC(DHODEC, LOGL_DEBUG, " (no %s possible)\n",
- (neighbor) ? "handover" : "assignment");
- else if ((candidate->requirements & REQUIREMENT_TCHF_MASK)
- == REQUIREMENT_A_TCHF) /* only A */
- LOGPC(DHODEC, LOGL_DEBUG, " (more congestion after %s)\n",
- (neighbor) ? "handover" : "assignment");
- else if ((candidate->requirements & REQUIREMENT_B_TCHF)) /* B incl. */
- LOGPC(DHODEC, LOGL_DEBUG, " (not congested after %s)\n",
- (neighbor) ? "handover" : "assignment");
- else /* so it must include C */
- LOGPC(DHODEC, LOGL_DEBUG, " (less or equally congested after "
- "%s)\n", (neighbor) ? "handover" : "assignment");
-
- if ((candidate->requirements & REQUIREMENT_TCHH_MASK))
- LOGP(DHODEC, LOGL_DEBUG, " o requirement ");
- else
- LOGP(DHODEC, LOGL_DEBUG, " o no requirement ");
- if ((candidate->requirements & REQUIREMENT_A_TCHH))
- LOGPC(DHODEC, LOGL_DEBUG, "A ");
- if ((candidate->requirements & REQUIREMENT_B_TCHH))
- LOGPC(DHODEC, LOGL_DEBUG, "B ");
- if ((candidate->requirements & REQUIREMENT_C_TCHH))
- LOGPC(DHODEC, LOGL_DEBUG, "C ");
- LOGPC(DHODEC, LOGL_DEBUG, "fulfilled for TCHH");
- if (!(candidate->requirements & REQUIREMENT_TCHH_MASK)) /* nothing */
- LOGPC(DHODEC, LOGL_DEBUG, " (no %s possible)\n",
- (neighbor) ? "handover" : "assignment");
- else if ((candidate->requirements & REQUIREMENT_TCHH_MASK)
- == REQUIREMENT_A_TCHH) /* only A */
- LOGPC(DHODEC, LOGL_DEBUG, " (more congestion after %s)\n",
- (neighbor) ? "handover" : "assignment");
- else if ((candidate->requirements & REQUIREMENT_B_TCHH)) /* B incl. */
- LOGPC(DHODEC, LOGL_DEBUG, " (not congested after %s)\n",
- (neighbor) ? "handover" : "assignment");
- else /* so it must include C */
- LOGPC(DHODEC, LOGL_DEBUG, " (less or equally congested after "
- "%s)\n", (neighbor) ? "handover" : "assignment");
+ LOGPHOLCHANTOBTS(lchan, lchan->ts->trx->bts, LOGL_DEBUG,
+ "RX level %d; "
+ HO_CANDIDATE_FMT(f, F) "; " HO_CANDIDATE_FMT(h, H) "\n",
+ rxlev2dbm(candidate->avg),
+ HO_CANDIDATE_ARGS(f, F), HO_CANDIDATE_ARGS(h, H));
}
/* add candidate for re-assignment within the current cell */
@@ -775,7 +693,7 @@
c->bts = bts;
c->requirements = check_requirements(lchan, bts, tchf_count,
tchh_count);
c->avg = av_rxlev;
- debug_candidate(c, 0, 0, tchf_count, tchh_count);
+ debug_candidate(lchan, c, NULL, 0, tchf_count, tchh_count);
(*candidates)++;
}
@@ -855,7 +773,7 @@
c->requirements = check_requirements(lchan, neighbor_bts, tchf_count,
tchh_count);
c->avg = avg;
- debug_candidate(c, 1, av_rxlev, tchf_count, tchh_count);
+ debug_candidate(lchan, c, neighbor_bts, av_rxlev, tchf_count,
tchh_count);
(*candidates)++;
}
@@ -865,14 +783,12 @@
{
struct gsm_bts *bts = lchan->ts->trx->bts;
int av_rxlev;
- unsigned int candidates_was;
bool assignment;
bool handover;
int neighbors_count = 0;
unsigned int rxlev_avg_win = ho_get_hodec2_rxlev_avg_win(bts->ho);
OSMO_ASSERT(candidates);
- candidates_was = *candidates;
/* caculate average rxlev for this cell over the window */
av_rxlev = get_meas_rep_avg(lchan,
@@ -893,11 +809,6 @@
assignment = ho_get_hodec2_as_active(bts->ho);
handover = ho_get_ho_active(bts->ho);
- LOGPHOLCHAN(lchan, LOGL_DEBUG, "Collecting candidates for%s%s%s\n",
- assignment ? " Assignment" : "",
- assignment && handover ? " and" : "",
- handover ? " Handover" : "");
-
if (assignment)
collect_assignment_candidate(lchan, clist, candidates,
av_rxlev);
@@ -909,9 +820,6 @@
include_weaker_rxlev,
av_rxlev, &neighbors_count);
}
}
-
- LOGPHOLCHAN(lchan, LOGL_DEBUG, "adding %u candidates from %u neighbors,
total %u\n",
- *candidates - candidates_was, neighbors_count, *candidates);
}
/*
@@ -1155,8 +1063,6 @@
return;
}
- LOGPHOLCHAN(lchan, LOGL_DEBUG, "HODEC2: evaluating measurement
report\n");
-
/* get average levels. if not enought measurements yet, value is < 0 */
av_rxlev = get_meas_rep_avg(lchan,
ho_get_hodec2_full_tdma(bts->ho) ?
@@ -1170,34 +1076,29 @@
LOGPHOLCHAN(lchan, LOGL_INFO, "Skipping, Not enough recent
measurements\n");
return;
}
- if (av_rxlev >= 0) {
- LOGPHOLCHAN(lchan, LOGL_DEBUG, "Measurement report: average RX
level = %d\n",
- rxlev2dbm(av_rxlev));
- }
- if (av_rxqual >= 0) {
- LOGPHOLCHAN(lchan, LOGL_DEBUG, "Measurement report: average RX
quality = %d\n",
- av_rxqual);
- }
/* improve levels in case of AFS, if defined */
if (lchan->type == GSM_LCHAN_TCH_F
&& lchan->tch_mode == GSM48_CMODE_SPEECH_AMR) {
+ int av_rxlev_was = av_rxlev;
+ int av_rxqual_was = av_rxqual;
int rxlev_bias = ho_get_hodec2_afs_bias_rxlev(bts->ho);
int rxqual_bias = ho_get_hodec2_afs_bias_rxqual(bts->ho);
- if (av_rxlev >= 0 && rxlev_bias) {
- int imp = av_rxlev + rxlev_bias;
- LOGPHOLCHAN(lchan, LOGL_INFO, "Virtually improving RX
level from %d to %d,"
- " due to AFS bias\n", rxlev2dbm(av_rxlev),
rxlev2dbm(imp));
- av_rxlev = imp;
- }
- if (av_rxqual >= 0 && rxqual_bias) {
- int imp = av_rxqual - rxqual_bias;
- if (imp < 0)
- imp = 0;
- LOGPHOLCHAN(lchan, LOGL_INFO, "Virtually improving RX
quality from %d to %d,"
- " due to AFS bias\n", rxlev2dbm(av_rxqual),
rxlev2dbm(imp));
- av_rxqual = imp;
- }
+ if (av_rxlev >= 0)
+ av_rxlev = av_rxlev + rxlev_bias;
+ if (av_rxqual >= 0)
+ av_rxqual = OSMO_MAX(0, av_rxqual - rxqual_bias);
+
+ LOGPHOLCHAN(lchan, LOGL_DEBUG,
+ "Avg RX level = %d dBm, %+d dBm AFS bias = %d dBm;"
+ " Avg RX quality = %d%s, %+d AFS bias = %d\n",
+ rxlev2dbm(av_rxlev_was), rxlev_bias,
rxlev2dbm(av_rxlev),
+ OSMO_MAX(-1, av_rxqual_was), av_rxqual_was < 0 ? "
(invalid)" : "",
+ -rxqual_bias, OSMO_MAX(-1, av_rxqual));
+ } else {
+ LOGPHOLCHAN(lchan, LOGL_DEBUG, "Avg RX level = %d dBm; Avg RX
quality = %d%s\n",
+ rxlev2dbm(av_rxlev),
+ OSMO_MAX(-1, av_rxqual), av_rxqual < 0 ? "
(invalid)" : "");
}
/* Bad Quality */
@@ -1217,7 +1118,8 @@
/* Low Level */
if (av_rxlev >= 0 && rxlev2dbm(av_rxlev) <
ho_get_hodec2_min_rxlev(bts->ho)) {
global_ho_reason = HO_REASON_LOW_RXLEVEL;
- LOGPHOLCHAN(lchan, LOGL_INFO, "Attempting handover/assignment
due to low rxlev\n");
+ LOGPHOLCHAN(lchan, LOGL_NOTICE, "RX level is TOO LOW: %d <
%d\n",
+ rxlev2dbm(av_rxlev),
ho_get_hodec2_min_rxlev(bts->ho));
find_alternative_lchan(lchan, true);
return;
}
@@ -1226,7 +1128,8 @@
if (lchan->meas_rep_count > 0
&& lchan->rqd_ta > ho_get_hodec2_max_distance(bts->ho)) {
global_ho_reason = HO_REASON_MAX_DISTANCE;
- LOGPHOLCHAN(lchan, LOGL_INFO, "Attempting handover due to high
TA\n");
+ LOGPHOLCHAN(lchan, LOGL_NOTICE, "TA is TOO HIGH: %u > %d\n",
+ lchan->rqd_ta, ho_get_hodec2_max_distance(bts->ho));
/* start penalty timer to prevent comming back too
* early. it must be started before selecting a better cell,
* so there is no assignment selected, due to running
@@ -1242,7 +1145,6 @@
/* try handover to a better cell */
if (av_rxlev >= 0 && (mr->nr % pwr_interval) == 0) {
- LOGPHOLCHAN(lchan, LOGL_INFO, "Looking whether a cell has
better RXLEV\n");
global_ho_reason = HO_REASON_BETTER_CELL;
find_alternative_lchan(lchan, false);
}
@@ -1439,12 +1341,10 @@
/* perform handover, if there is a candidate */
if (best_cand) {
any_ho = 1;
- LOGPHOLCHAN(best_cand->lchan, LOGL_INFO,
- "Best candidate BTS %u (RX level %d) without
congestion found\n",
- best_cand->bts->nr, rxlev2dbm(best_cand->avg));
- if (is_improved)
- LOGP(DHODEC, LOGL_INFO, "(is improved due to "
- "AHS -> AFS)\n");
+ LOGPHOLCHAN(best_cand->lchan, LOGL_DEBUG,
+ "Best candidate BTS %u (RX level %d%s) without
congestion found\n",
+ best_cand->bts->nr, rxlev2dbm(best_cand->avg),
+ is_improved ? ", RX quality improved by AHS->AFS" :
"");
trigger_handover_or_assignment(best_cand->lchan, best_cand->bts,
best_cand->requirements & REQUIREMENT_B_MASK);
#if 0
@@ -1468,9 +1368,6 @@
goto exit;
}
- LOGPHOBTS(bts, LOGL_DEBUG, "Did not find a best candidate that fulfills
requirement B"
- " (omitting change from AHS to AFS)\n");
-
#if 0
next_b2:
#endif
@@ -1504,8 +1401,6 @@
is_improved = 1;
} else
is_improved = 0;
- LOGP(DHODEC, LOGL_DEBUG, "candidate %d: avg=%d
worst_avg_db=%d\n", i, avg,
- worst_avg_db);
if (avg < worst_avg_db) {
worst_cand = &clist[i];
worst_avg_db = avg;
@@ -1517,11 +1412,9 @@
if (worst_cand) {
any_ho = 1;
LOGP(DHODEC, LOGL_INFO, "Worst candidate for assignment "
- "(RX level %d) from TCH/H -> TCH/F without congestion "
- "found\n", rxlev2dbm(worst_cand->avg));
- if (is_improved)
- LOGP(DHODEC, LOGL_INFO, "(is improved due to "
- "AHS -> AFS)\n");
+ "(RX level %d%s) from TCH/H -> TCH/F without congestion
"
+ "found\n", rxlev2dbm(worst_cand->avg),
+ is_improved ? ", RX quality improved by AHS->AFS" : "");
trigger_handover_or_assignment(worst_cand->lchan,
worst_cand->bts,
worst_cand->requirements & REQUIREMENT_B_MASK);
@@ -1543,9 +1436,6 @@
goto exit;
}
- LOGPHOBTS(bts, LOGL_DEBUG, "Did not find a worst candidate that
fulfills requirement B,"
- " selecting candidates that change from AHS to AFS only\n");
-
#if 0
next_c1:
#endif
@@ -1584,7 +1474,6 @@
is_improved = 1;
} else
is_improved = 0;
- LOGP(DHODEC, LOGL_DEBUG, "candidate %d: avg=%d
best_avg_db=%d\n", i, avg, best_avg_db);
if (avg > best_avg_db) {
best_cand = &clist[i];
best_avg_db = avg;
@@ -1672,11 +1561,9 @@
if (worst_cand) {
any_ho = 1;
LOGP(DHODEC, LOGL_INFO, "Worst candidate for assignment "
- "(RX level %d) from TCH/H -> TCH/F with less or equal "
- "congestion found\n", rxlev2dbm(worst_cand->avg));
- if (is_improved)
- LOGP(DHODEC, LOGL_INFO, "(is improved due to "
- "AHS -> AFS)\n");
+ "(RX level %d%s) from TCH/H -> TCH/F with less or equal
"
+ "congestion found\n", rxlev2dbm(worst_cand->avg),
+ is_improved ? ", RX quality improved by AHS->AFS" : "");
trigger_handover_or_assignment(worst_cand->lchan,
worst_cand->bts,
worst_cand->requirements & REQUIREMENT_C_MASK);
diff --git a/src/osmo-bsc/handover_logic.c b/src/osmo-bsc/handover_logic.c
index 064615c..509de53 100644
--- a/src/osmo-bsc/handover_logic.c
+++ b/src/osmo-bsc/handover_logic.c
@@ -122,17 +122,6 @@
llist_add(&ho->list, &bsc_handovers);
conn->ho = ho;
-
- DEBUGP(DHO, "(BTS %u trx %u ts %u lchan %u %s)->(BTS %u lchan %s)
Initiating %s...\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),
- do_assignment ? "Assignment" : "Handover");
-
rc = osmo_fsm_inst_dispatch(conn->fi, GSCON_EV_HO_START, NULL);
if (rc < 0) {
--
To view, visit https://gerrit.osmocom.org/10058
To unsubscribe, or for help writing mail filters, visit
https://gerrit.osmocom.org/settings
Gerrit-Project: osmo-bsc
Gerrit-Branch: master
Gerrit-MessageType: merged
Gerrit-Change-Id: If1add9b57a051d32b67a4a08ab47a9655aa9dd17
Gerrit-Change-Number: 10058
Gerrit-PatchSet: 3
Gerrit-Owner: Neels Hofmeyr <[email protected]>
Gerrit-Reviewer: Harald Welte <[email protected]>
Gerrit-Reviewer: Jenkins Builder
Gerrit-Reviewer: Neels Hofmeyr <[email protected]>
