From 14db19ed11d38f0d6f08bb1d6139b7b90f4fdc37 Mon Sep 17 00:00:00 2001 From: Andreas Eversberg Date: Mon, 6 Aug 2012 15:03:03 +0200 Subject: [PATCH] Adding flags for debugging assignment and polling timeout --- src/gprs_bssgp_pcu.cpp | 1 + src/gprs_rlcmac.h | 10 +++++ src/gprs_rlcmac_data.cpp | 85 ++++++++++++++++++++++++++++++++++++---- 3 files changed, 88 insertions(+), 8 deletions(-) diff --git a/src/gprs_bssgp_pcu.cpp b/src/gprs_bssgp_pcu.cpp index 9b977f29..374baf63 100644 --- a/src/gprs_bssgp_pcu.cpp +++ b/src/gprs_bssgp_pcu.cpp @@ -138,6 +138,7 @@ int gprs_bssgp_pcu_rx_dl_ud(struct msgb *msg, struct tlv_parsed *tp) tbf->llc_length = len; memset(&tbf->dir.dl, 0, sizeof(tbf->dir.dl)); /* reset rlc states */ + tbf->state_flags = 0; if (!tbf->ms_class && ms_class) tbf->ms_class = ms_class; tbf_update(tbf); diff --git a/src/gprs_rlcmac.h b/src/gprs_rlcmac.h index e3fd9914..27933bde 100644 --- a/src/gprs_rlcmac.h +++ b/src/gprs_rlcmac.h @@ -132,9 +132,19 @@ enum gprs_rlcmac_tbf_direction { GPRS_RLCMAC_UL_TBF }; +#define GPRS_RLCMAC_FLAG_CCCH 0 /* assignment on CCCH */ +#define GPRS_RLCMAC_FLAG_PACCH 1 /* assignment on PACCH */ +#define GPRS_RLCMAC_FLAG_UL_DATA 2 /* uplink data received */ +#define GPRS_RLCMAC_FLAG_DL_ACK 3 /* downlink acknowledge received */ +#define GPRS_RLCMAC_FLAG_TO_UL_ACK 4 +#define GPRS_RLCMAC_FLAG_TO_DL_ACK 5 +#define GPRS_RLCMAC_FLAG_TO_UL_ASS 6 +#define GPRS_RLCMAC_FLAG_TO_DL_ASS 7 + struct gprs_rlcmac_tbf { struct llist_head list; enum gprs_rlcmac_tbf_state state; + uint32_t state_flags; enum gprs_rlcmac_tbf_direction direction; uint8_t tfi; uint32_t tlli; diff --git a/src/gprs_rlcmac_data.cpp b/src/gprs_rlcmac_data.cpp index f56d848e..d59153f7 100644 --- a/src/gprs_rlcmac_data.cpp +++ b/src/gprs_rlcmac_data.cpp @@ -73,6 +73,24 @@ struct rlc_li_field { } __attribute__ ((packed)); } +static int gprs_rlcmac_diag(struct gprs_rlcmac_tbf *tbf) +{ + if ((tbf->state_flags & (1 << GPRS_RLCMAC_FLAG_CCCH))) + LOGP(DRLCMAC, LOGL_NOTICE, "- Assignment was on CCCH\n"); + if ((tbf->state_flags & (1 << GPRS_RLCMAC_FLAG_PACCH))) + LOGP(DRLCMAC, LOGL_NOTICE, "- Assignment was on PACCH\n"); + if ((tbf->state_flags & (1 << GPRS_RLCMAC_FLAG_UL_DATA))) + LOGP(DRLCMAC, LOGL_NOTICE, "- Uplink data was received\n"); + else if (tbf->direction == GPRS_RLCMAC_UL_TBF) + LOGP(DRLCMAC, LOGL_NOTICE, "- No uplink data received yet\n"); + if ((tbf->state_flags & (1 << GPRS_RLCMAC_FLAG_DL_ACK))) + LOGP(DRLCMAC, LOGL_NOTICE, "- Downlink ACK was received\n"); + else if (tbf->direction == GPRS_RLCMAC_DL_TBF) + LOGP(DRLCMAC, LOGL_NOTICE, "- No downlink ACK received yet\n"); + + return 0; +} + int gprs_rlcmac_poll_timeout(struct gprs_rlcmac_tbf *tbf) { LOGP(DRLCMAC, LOGL_NOTICE, "Poll timeout for %s TBF=%d\n", @@ -81,8 +99,12 @@ int gprs_rlcmac_poll_timeout(struct gprs_rlcmac_tbf *tbf) tbf->poll_state = GPRS_RLCMAC_POLL_NONE; if (tbf->ul_ack_state == GPRS_RLCMAC_UL_ACK_WAIT_ACK) { - LOGP(DRLCMAC, LOGL_NOTICE, "- Timeout for polling PACKET " - "CONTROL ACK for PACKET UPLINK ACK\n"); + if (!(tbf->state_flags & (1 << GPRS_RLCMAC_FLAG_TO_UL_ACK))) { + LOGP(DRLCMAC, LOGL_NOTICE, "- Timeout for polling " + "PACKET CONTROL ACK for PACKET UPLINK ACK\n"); + gprs_rlcmac_diag(tbf); + tbf->state_flags |= (1 << GPRS_RLCMAC_FLAG_TO_UL_ACK); + } tbf->ul_ack_state = GPRS_RLCMAC_UL_ACK_NONE; if (tbf->state == GPRS_RLCMAC_FINISHED) { struct gprs_rlcmac_bts *bts = gprs_rlcmac_bts; @@ -102,8 +124,13 @@ int gprs_rlcmac_poll_timeout(struct gprs_rlcmac_tbf *tbf) if (tbf->ul_ass_state == GPRS_RLCMAC_UL_ASS_WAIT_ACK) { struct gprs_rlcmac_bts *bts = gprs_rlcmac_bts; - LOGP(DRLCMAC, LOGL_NOTICE, "- Timeout for polling PACKET " - "CONTROL ACK for PACKET UPLINK ASSIGNMENT.\n"); + if (!(tbf->state_flags & (1 << GPRS_RLCMAC_FLAG_TO_UL_ASS))) { + LOGP(DRLCMAC, LOGL_NOTICE, "- Timeout for polling " + "PACKET CONTROL ACK for PACKET UPLINK " + "ASSIGNMENT.\n"); + gprs_rlcmac_diag(tbf); + tbf->state_flags |= (1 << GPRS_RLCMAC_FLAG_TO_UL_ASS); + } tbf->ul_ass_state = GPRS_RLCMAC_UL_ASS_NONE; tbf->n3105++; if (tbf->n3105 == bts->n3105) { @@ -118,8 +145,13 @@ int gprs_rlcmac_poll_timeout(struct gprs_rlcmac_tbf *tbf) if (tbf->dl_ass_state == GPRS_RLCMAC_DL_ASS_WAIT_ACK) { struct gprs_rlcmac_bts *bts = gprs_rlcmac_bts; - LOGP(DRLCMAC, LOGL_NOTICE, "- Timeout for polling PACKET " - "CONTROL ACK for PACKET DOWNLINK ASSIGNMENT.\n"); + if (!(tbf->state_flags & (1 << GPRS_RLCMAC_FLAG_TO_DL_ASS))) { + LOGP(DRLCMAC, LOGL_NOTICE, "- Timeout for polling " + "PACKET CONTROL ACK for PACKET DOWNLINK " + "ASSIGNMENT.\n"); + gprs_rlcmac_diag(tbf); + tbf->state_flags |= (1 << GPRS_RLCMAC_FLAG_TO_DL_ASS); + } tbf->dl_ass_state = GPRS_RLCMAC_DL_ASS_NONE; tbf->n3105++; if (tbf->n3105 == bts->n3105) { @@ -134,8 +166,12 @@ int gprs_rlcmac_poll_timeout(struct gprs_rlcmac_tbf *tbf) if (tbf->direction == GPRS_RLCMAC_DL_TBF) { struct gprs_rlcmac_bts *bts = gprs_rlcmac_bts; - LOGP(DRLCMAC, LOGL_NOTICE, "- Timeout for polling PACKET " - " DOWNLINK ACK.\n"); + if (!(tbf->state_flags & (1 << GPRS_RLCMAC_FLAG_TO_DL_ACK))) { + LOGP(DRLCMAC, LOGL_NOTICE, "- Timeout for polling " + "PACKET DOWNLINK ACK.\n"); + gprs_rlcmac_diag(tbf); + tbf->state_flags |= (1 << GPRS_RLCMAC_FLAG_TO_DL_ACK); + } tbf->n3105++; if (tbf->n3105 == bts->n3105) { LOGP(DRLCMAC, LOGL_NOTICE, "- N3105 exceeded\n"); @@ -187,6 +223,13 @@ int gprs_rlcmac_rcv_control_block(bitvec *rlc_block, uint8_t trx, uint8_t ts, if (tbf->ul_ack_state == GPRS_RLCMAC_UL_ACK_WAIT_ACK) { LOGP(DRLCMAC, LOGL_DEBUG, "TBF: [UPLINK] END TFI: %u TLLI: 0x%08x \n", tbf->tfi, tbf->tlli); tbf->ul_ack_state = GPRS_RLCMAC_UL_ACK_NONE; + if ((tbf->state_flags & + (1 << GPRS_RLCMAC_FLAG_TO_UL_ACK))) { + tbf->state_flags &= + ~(1 << GPRS_RLCMAC_FLAG_TO_UL_ACK); + LOGP(DRLCMAC, LOGL_NOTICE, "Recovered uplink " + "ack\n"); + } tbf_free(tbf); break; } @@ -204,6 +247,13 @@ int gprs_rlcmac_rcv_control_block(bitvec *rlc_block, uint8_t trx, uint8_t ts, break; } tbf_new_state(tbf, GPRS_RLCMAC_FLOW); + if ((tbf->state_flags & + (1 << GPRS_RLCMAC_FLAG_TO_DL_ASS))) { + tbf->state_flags &= + ~(1 << GPRS_RLCMAC_FLAG_TO_DL_ASS); + LOGP(DRLCMAC, LOGL_NOTICE, "Recovered downlink " + "assignment\n"); + } tbf_assign_control_ts(tbf); break; } @@ -221,6 +271,13 @@ int gprs_rlcmac_rcv_control_block(bitvec *rlc_block, uint8_t trx, uint8_t ts, break; } tbf_new_state(tbf, GPRS_RLCMAC_FLOW); + if ((tbf->state_flags & + (1 << GPRS_RLCMAC_FLAG_TO_UL_ASS))) { + tbf->state_flags &= + ~(1 << GPRS_RLCMAC_FLAG_TO_UL_ASS); + LOGP(DRLCMAC, LOGL_NOTICE, "Recovered uplink " + "assignment\n"); + } tbf_assign_control_ts(tbf); break; } @@ -236,6 +293,11 @@ int gprs_rlcmac_rcv_control_block(bitvec *rlc_block, uint8_t trx, uint8_t ts, fn, tfi, trx, ts); break; } + tbf->state_flags |= (1 << GPRS_RLCMAC_FLAG_DL_ACK); + if ((tbf->state_flags & (1 << GPRS_RLCMAC_FLAG_TO_DL_ACK))) { + tbf->state_flags &= ~(1 << GPRS_RLCMAC_FLAG_TO_DL_ACK); + LOGP(DRLCMAC, LOGL_NOTICE, "Recovered downlink ack\n"); + } /* reset N3105 */ tbf->n3105 = 0; /* stop timer T3191 */ @@ -280,6 +342,7 @@ uplink_request: ul_tbf->dir.ul.contention_resolution_done = 1; ul_tbf->ta = tbf->ta; /* use current TA */ tbf_new_state(ul_tbf, GPRS_RLCMAC_ASSIGN); + ul_tbf->state_flags |= (1 << GPRS_RLCMAC_FLAG_PACCH); tbf_timer_start(ul_tbf, 3169, bts->t3169, 0); /* schedule uplink assignment */ tbf->ul_ass_state = GPRS_RLCMAC_UL_ASS_SEND_ASS; @@ -355,6 +418,7 @@ void tbf_timer_cb(void *_tbf) case 3195: LOGP(DRLCMAC, LOGL_NOTICE, "TBF T%d timeout during " "transsmission\n", tbf->T); + gprs_rlcmac_diag(tbf); /* fall through */ case 3193: LOGP(DRLCMAC, LOGL_DEBUG, "TBF will be freed due to timeout\n"); @@ -662,6 +726,7 @@ int gprs_rlcmac_rcv_data_block_acknowledged(uint8_t trx, uint8_t ts, rh->tfi); return 0; } + tbf->state_flags |= (1 << GPRS_RLCMAC_FLAG_UL_DATA); LOGP(DRLCMACUL, LOGL_DEBUG, "UL DATA TBF=%d received (V(Q)=%d .. " "V(R)=%d)\n", rh->tfi, tbf->dir.ul.v_q, tbf->dir.ul.v_r); @@ -910,6 +975,7 @@ int gprs_rlcmac_rcv_rach(uint8_t ra, uint32_t Fn, int16_t qta) qta = 252; tbf->ta = qta >> 2; tbf_new_state(tbf, GPRS_RLCMAC_FLOW); + tbf->state_flags |= (1 << GPRS_RLCMAC_FLAG_CCCH); tbf_timer_start(tbf, 3169, bts->t3169, 0); LOGP(DRLCMAC, LOGL_DEBUG, "TBF: [UPLINK] START TFI: %u\n", tbf->tfi); LOGP(DRLCMAC, LOGL_DEBUG, "RX: [PCU <- BTS] TFI: %u RACH qbit-ta=%d ra=%d, Fn=%d (%d,%d,%d)\n", tbf->tfi, qta, ra, Fn, (Fn / (26 * 51)) % 32, Fn % 51, Fn % 26); @@ -1427,6 +1493,7 @@ int gprs_rlcmac_downlink_ack(struct gprs_rlcmac_tbf *tbf, uint8_t final, LOGP(DRLCMAC, LOGL_DEBUG, "Trigger dowlink assignment on PACCH, " "because another LLC PDU has arrived in between\n"); memset(&tbf->dir.dl, 0, sizeof(tbf->dir.dl)); /* reset RLC states */ + tbf->state_flags = 0; tbf_update(tbf); gprs_rlcmac_trigger_downlink_assignment(tbf, tbf, NULL); @@ -1555,6 +1622,7 @@ void gprs_rlcmac_trigger_downlink_assignment(struct gprs_rlcmac_tbf *tbf, tbf->ta = old_tbf->ta; /* change state */ tbf_new_state(tbf, GPRS_RLCMAC_ASSIGN); + tbf->state_flags |= (1 << GPRS_RLCMAC_FLAG_PACCH); #endif } else { LOGP(DRLCMAC, LOGL_DEBUG, "Send dowlink assignment for TBF=%d on PCH, no TBF exist (IMSI=%s)\n", tbf->tfi, imsi); @@ -1564,6 +1632,7 @@ void gprs_rlcmac_trigger_downlink_assignment(struct gprs_rlcmac_tbf *tbf, } /* change state */ tbf_new_state(tbf, GPRS_RLCMAC_ASSIGN); + tbf->state_flags |= (1 << GPRS_RLCMAC_FLAG_CCCH); /* send immediate assignment */ gprs_rlcmac_downlink_assignment(tbf, 0, imsi); /* send immediate assignment */