From 31716f981a260390cbdda7fdb164ec4faca12c8a Mon Sep 17 00:00:00 2001 From: Neels Hofmeyr Date: Thu, 19 Jul 2018 16:14:09 +0200 Subject: 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 --- src/osmo-bsc/handover_decision_2.c | 259 +++++++++++-------------------------- 1 file changed, 73 insertions(+), 186 deletions(-) (limited to 'src/osmo-bsc/handover_decision_2.c') diff --git a/src/osmo-bsc/handover_decision_2.c b/src/osmo-bsc/handover_decision_2.c index 7ac54df95..e514b6c5f 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 @@ static void process_meas_neigh(struct gsm_meas_rep *mr) 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 @@ static bool codec_type_is_supported(struct gsm_subscriber_connection *conn, } 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 @@ static uint8_t check_requirements(struct gsm_lchan *lchan, struct gsm_bts *bts, 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 @@ static uint8_t check_requirements(struct gsm_lchan *lchan, struct gsm_bts *bts, 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 @@ static uint8_t check_requirements(struct gsm_lchan *lchan, struct gsm_bts *bts, 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 @@ static uint8_t check_requirements(struct gsm_lchan *lchan, struct gsm_bts *bts, /* 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 @@ static uint8_t check_requirements(struct gsm_lchan *lchan, struct gsm_bts *bts, * 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 @@ static int trigger_handover_or_assignment(struct gsm_lchan *lchan, struct gsm_bt 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 @@ static int trigger_handover_or_assignment(struct gsm_lchan *lchan, struct gsm_bt 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 @@ static int trigger_handover_or_assignment(struct gsm_lchan *lchan, struct gsm_bt } /* 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) { - if (neighbor) - LOGP(DHODEC, LOGL_DEBUG, " - neighbor BTS %d, RX level " - "%d -> %d\n", candidate->bts->nr, rxlev2dbm(rxlev), - rxlev2dbm(candidate->avg)); - 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)); +#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 ((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 "); + if (neighbor) + 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, " 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 @@ static void collect_assignment_candidate(struct gsm_lchan *lchan, struct ho_cand 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 @@ static void collect_handover_candidate(struct gsm_lchan *lchan, struct neigh_mea 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 @@ static void collect_candidates_for_lchan(struct gsm_lchan *lchan, { 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 @@ static void collect_candidates_for_lchan(struct gsm_lchan *lchan, 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 @@ static void collect_candidates_for_lchan(struct gsm_lchan *lchan, 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 @@ static void on_measurement_report(struct gsm_meas_rep *mr) 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 @@ static void on_measurement_report(struct gsm_meas_rep *mr) 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 @@ static void on_measurement_report(struct gsm_meas_rep *mr) /* 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 @@ static void on_measurement_report(struct gsm_meas_rep *mr) 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 @@ static void on_measurement_report(struct gsm_meas_rep *mr) /* 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 @@ next_b1: /* 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 @@ next_b1: 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 @@ next_b2: 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 @@ next_b2: 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 @@ next_b2: 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 @@ next_c1: 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 @@ next_c2: 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); -- cgit v1.2.3