diff options
Diffstat (limited to 'src')
-rw-r--r-- | src/bts.cpp | 80 | ||||
-rw-r--r-- | src/tbf.cpp | 111 | ||||
-rw-r--r-- | src/tbf.h | 4 | ||||
-rw-r--r-- | src/tbf_dl.cpp | 42 | ||||
-rw-r--r-- | src/tbf_ul.cpp | 8 |
5 files changed, 105 insertions, 140 deletions
diff --git a/src/bts.cpp b/src/bts.cpp index e17399ac..b2af7aac 100644 --- a/src/bts.cpp +++ b/src/bts.cpp @@ -338,15 +338,13 @@ int BTS::add_paging(uint8_t chan_needed, uint8_t *identity_lv) } /* mark first slot found, if none is marked already */ if (ts == 8 && first_ts >= 0) { - LOGP(DRLCMAC, LOGL_DEBUG, "- %s uses " + LOGPTBF(tbf, LOGL_DEBUG, "uses " "TRX=%d TS=%d, so we mark\n", - tbf_name(tbf), tbf->trx->trx_no, first_ts); slot_mask[tbf->trx->trx_no] |= (1 << first_ts); } else - LOGP(DRLCMAC, LOGL_DEBUG, "- %s uses " + LOGPTBF(tbf, LOGL_DEBUG, "uses " "already marked TRX=%d TS=%d\n", - tbf_name(tbf), tbf->trx->trx_no, ts); } } @@ -690,17 +688,13 @@ int BTS::rcv_rach(uint16_t ra, uint32_t Fn, int16_t qta, uint8_t is_11bit, tbf->set_state(GPRS_RLCMAC_FLOW); tbf->state_flags |= (1 << GPRS_RLCMAC_FLAG_CCCH); tbf_timer_start(tbf, 3169, m_bts.t3169, 0, "RACH (new UL-TBF)"); - LOGP(DRLCMAC, LOGL_DEBUG, "%s [UPLINK] START\n", - tbf_name(tbf)); - LOGP(DRLCMAC, LOGL_DEBUG, "%s RX: [PCU <- BTS] RACH " + LOGPTBF(tbf, LOGL_DEBUG, "[UPLINK] START\n"); + LOGPTBF(tbf, LOGL_DEBUG, "RX: [PCU <- BTS] RACH " "qbit-ta=%d ra=0x%02x, Fn=%d " " (%d,%d,%d)\n", - tbf_name(tbf), qta, ra, Fn, (Fn / (26 * 51)) % 32, Fn % 51, Fn % 26); - LOGP(DRLCMAC, LOGL_INFO, "%s TX: START Immediate " - "Assignment Uplink (AGCH)\n", - tbf_name(tbf)); + LOGPTBF(tbf, LOGL_INFO, "TX: START Immediate Assignment Uplink (AGCH)\n"); trx_no = tbf->trx->trx_no; ts_no = tbf->first_ts; usf = tbf->m_usf[ts_no]; @@ -812,7 +806,7 @@ void BTS::snd_dl_ass(gprs_rlcmac_tbf *tbf, uint8_t poll, const char *imsi) int plen; unsigned int ts = tbf->first_ts; - LOGP(DRLCMAC, LOGL_INFO, "TX: START %s Immediate Assignment Downlink (PCH)\n", tbf_name(tbf)); + LOGPTBF(tbf, LOGL_INFO, "TX: START Immediate Assignment Downlink (PCH)\n"); bitvec *immediate_assignment = bitvec_alloc(22, tall_pcu_ctx); /* without plen */ bitvec_unhex(immediate_assignment, "2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b"); /* use request reference that has maximum distance to current time, @@ -1004,21 +998,21 @@ void gprs_rlcmac_pdch::rcv_control_ack(Packet_Control_Acknowledgement_t *packet, } tbf->update_ms(tlli, GPRS_RLCMAC_UL_TBF); - LOGP(DRLCMAC, LOGL_DEBUG, "RX: [PCU <- BTS] %s Packet Control Ack\n", tbf_name(tbf)); + LOGPTBF(tbf, LOGL_DEBUG, "RX: [PCU <- BTS] Packet Control Ack\n"); tbf->poll_state = GPRS_RLCMAC_POLL_NONE; /* check if this control ack belongs to packet uplink ack */ ul_tbf = as_ul_tbf(tbf); if (ul_tbf && ul_tbf->handle_ctrl_ack()) { - LOGP(DRLCMAC, LOGL_DEBUG, "TBF: [UPLINK] END %s\n", tbf_name(tbf)); + LOGPTBF(tbf, LOGL_DEBUG, "[UPLINK] END\n"); if (ul_tbf->ctrl_ack_to_toggle()) - LOGP(DRLCMAC, LOGL_NOTICE, "Recovered uplink ack for UL %s\n", tbf_name(tbf)); + LOGPTBF(tbf, LOGL_NOTICE, "Recovered uplink ack for UL\n"); tbf_free(tbf); return; } if (tbf->dl_ass_state == GPRS_RLCMAC_DL_ASS_WAIT_ACK) { - LOGP(DRLCMAC, LOGL_DEBUG, "TBF: [UPLINK] DOWNLINK ASSIGNED %s\n", tbf_name(tbf)); + LOGPTBF(tbf, LOGL_DEBUG, "[UPLINK] DOWNLINK ASSIGNED\n"); /* reset N3105 */ tbf->n3105 = 0; tbf->dl_ass_state = GPRS_RLCMAC_DL_ASS_NONE; @@ -1035,10 +1029,9 @@ void gprs_rlcmac_pdch::rcv_control_ack(Packet_Control_Acknowledgement_t *packet, if ((new_tbf->state_flags & (1 << GPRS_RLCMAC_FLAG_CCCH))) { /* We now know that the PACCH really existed */ - LOGP(DRLCMAC, LOGL_INFO, + LOGPTBF(new_tbf, LOGL_INFO, "The TBF has been confirmed on the PACCH, " - "changed type from CCCH to PACCH for %s\n", - tbf_name(new_tbf)); + "changed type from CCCH to PACCH\n"); new_tbf->state_flags &= ~(1 << GPRS_RLCMAC_FLAG_CCCH); new_tbf->state_flags |= (1 << GPRS_RLCMAC_FLAG_PACCH); } @@ -1049,14 +1042,13 @@ void gprs_rlcmac_pdch::rcv_control_ack(Packet_Control_Acknowledgement_t *packet, (1 << GPRS_RLCMAC_FLAG_TO_DL_ASS))) { new_tbf->state_flags &= ~(1 << GPRS_RLCMAC_FLAG_TO_DL_ASS); - LOGP(DRLCMAC, LOGL_NOTICE, "Recovered downlink " - "assignment for %s\n", tbf_name(new_tbf)); + LOGPTBF(new_tbf, LOGL_NOTICE, "Recovered downlink assignment\n"); } tbf_assign_control_ts(new_tbf); return; } if (tbf->ul_ass_state == GPRS_RLCMAC_UL_ASS_WAIT_ACK) { - LOGP(DRLCMAC, LOGL_DEBUG, "TBF: [DOWNLINK] UPLINK ASSIGNED %s\n", tbf_name(tbf)); + LOGPTBF(tbf, LOGL_DEBUG, "[DOWNLINK] UPLINK ASSIGNED\n"); /* reset N3105 */ tbf->n3105 = 0; tbf->ul_ass_state = GPRS_RLCMAC_UL_ASS_NONE; @@ -1076,8 +1068,7 @@ void gprs_rlcmac_pdch::rcv_control_ack(Packet_Control_Acknowledgement_t *packet, (1 << GPRS_RLCMAC_FLAG_TO_UL_ASS))) { new_tbf->state_flags &= ~(1 << GPRS_RLCMAC_FLAG_TO_UL_ASS); - LOGP(DRLCMAC, LOGL_NOTICE, "Recovered uplink " - "assignment for UL %s\n", tbf_name(new_tbf)); + LOGPTBF(new_tbf, LOGL_NOTICE, "Recovered uplink assignment for UL\n"); } tbf_assign_control_ts(new_tbf); /* there might be LLC packets waiting in the queue, but the DL @@ -1142,7 +1133,7 @@ static void get_meas(struct pcu_l1_meas *meas, for (i = 0; i < OSMO_MIN(ARRAY_SIZE(qr->Slot), ARRAY_SIZE(meas->ts)); i++) { if (qr->Slot[i].Exist) { - LOGP(DRLCMAC, LOGL_INFO, + LOGP(DRLCMAC, LOGL_DEBUG, "Channel quality report: i_level[%d] = %d\n", i, qr->Slot[i].I_LEVEL_TN); meas->set_ms_i_level(i, -2 * qr->Slot[i].I_LEVEL_TN); @@ -1195,9 +1186,9 @@ void gprs_rlcmac_pdch::rcv_control_dl_ack_nack(Packet_Downlink_Ack_Nack_t *ack_n } if (tbf->handle_ack_nack()) - LOGP(DRLCMAC, LOGL_NOTICE, "Recovered downlink ack for %s\n", tbf_name(tbf)); + LOGPTBF(tbf, LOGL_NOTICE, "Recovered downlink ack\n"); - LOGP(DRLCMAC, LOGL_DEBUG, "RX: [PCU <- BTS] %s Packet Downlink Ack/Nack\n", tbf_name(tbf)); + LOGPTBF(tbf, LOGL_DEBUG, "RX: [PCU <- BTS] Packet Downlink Ack/Nack\n"); bits.data = bits_data; bits.data_len = sizeof(bits_data); @@ -1259,11 +1250,10 @@ void gprs_rlcmac_pdch::rcv_control_egprs_dl_ack_nack(EGPRS_PD_AckNack_t *ack_nac } if (tbf->handle_ack_nack()) - LOGP(DRLCMAC, LOGL_NOTICE, "Recovered EGPRS downlink ack for %s\n", tbf_name(tbf)); + LOGPTBF(tbf, LOGL_NOTICE, "Recovered EGPRS downlink ack\n"); - LOGP(DRLCMAC, LOGL_DEBUG, - "RX: [PCU <- BTS] %s EGPRS Packet Downlink Ack/Nack\n", - tbf_name(tbf)); + LOGPTBF(tbf, LOGL_DEBUG, + "RX: [PCU <- BTS] EGPRS Packet Downlink Ack/Nack\n"); LOGP(DRLCMAC, LOGL_DEBUG, "EGPRS ACK/NACK: " "ut: %d, final: %d, bow: %d, eow: %d, ssn: %d, have_crbb: %d, " @@ -1348,19 +1338,17 @@ void gprs_rlcmac_pdch::rcv_resource_request(Packet_Resource_Request_t *request, /* We got a RACH so the MS was in packet idle mode and thus * didn't have any active TBFs */ if (ul_tbf) { - LOGP(DRLCMACUL, LOGL_NOTICE, "Got RACH from " - "TLLI=0x%08x while %s still " - "exists. Killing pending UL TBF\n", - tlli, tbf_name(ul_tbf)); + LOGPTBFUL(ul_tbf, LOGL_NOTICE, + "Got RACH from TLLI=0x%08x while TBF still exists. Killing pending UL TBF\n", + tlli); tbf_free(ul_tbf); ul_tbf = NULL; } if (dl_tbf) { - LOGP(DRLCMACUL, LOGL_NOTICE, "Got RACH from " - "TLLI=0x%08x while %s still exists. " - "Release pending DL TBF\n", tlli, - tbf_name(dl_tbf)); + LOGPTBFUL(dl_tbf, LOGL_NOTICE, + "Got RACH from TLLI=0x%08x while TBF still exists. Release pending DL TBF\n", + tlli); tbf_free(dl_tbf); dl_tbf = NULL; } @@ -1400,8 +1388,8 @@ void gprs_rlcmac_pdch::rcv_resource_request(Packet_Resource_Request_t *request, } /* set control ts to current MS's TS, until assignment complete */ - LOGP(DRLCMAC, LOGL_DEBUG, "%s change control TS %d -> %d until assinment is complete.\n", - tbf_name(ul_tbf), ul_tbf->control_ts, ts_no); + LOGPTBF(ul_tbf, LOGL_DEBUG, "change control TS %d -> %d until assinment is complete.\n", + ul_tbf->control_ts, ts_no); ul_tbf->control_ts = ts_no; /* schedule uplink assignment */ @@ -1427,9 +1415,8 @@ void gprs_rlcmac_pdch::rcv_resource_request(Packet_Resource_Request_t *request, LOGP(DRLCMAC, LOGL_NOTICE, "PACKET RESSOURCE REQ unknown downlink TFI=%d\n", tfi); return; } - LOGP(DRLCMAC, LOGL_ERROR, - "RX: [PCU <- BTS] %s FIXME: Packet resource request\n", - tbf_name(dl_tbf)); + LOGPTBFDL(dl_tbf, LOGL_ERROR, + "RX: [PCU <- BTS] FIXME: Packet resource request\n"); } else { struct gprs_rlcmac_ul_tbf *ul_tbf; int8_t tfi = request->ID.u.Global_TFI.u.UPLINK_TFI; @@ -1438,9 +1425,8 @@ void gprs_rlcmac_pdch::rcv_resource_request(Packet_Resource_Request_t *request, LOGP(DRLCMAC, LOGL_NOTICE, "PACKET RESSOURCE REQ unknown uplink TFI=%d\n", tfi); return; } - LOGP(DRLCMAC, LOGL_ERROR, - "RX: [PCU <- BTS] %s FIXME: Packet resource request\n", - tbf_name(ul_tbf)); + LOGPTBFUL(ul_tbf, LOGL_ERROR, + "RX: [PCU <- BTS] %s FIXME: Packet resource request\n"); } } diff --git a/src/tbf.cpp b/src/tbf.cpp index c139af7b..18059ace 100644 --- a/src/tbf.cpp +++ b/src/tbf.cpp @@ -446,21 +446,19 @@ void tbf_free(struct gprs_rlcmac_tbf *tbf) dl_tbf->cleanup(); } - LOGP(DRLCMAC, LOGL_INFO, "%s free\n", tbf_name(tbf)); + LOGPTBF(tbf, LOGL_INFO, "free\n"); if (tbf->ul_ass_state != GPRS_RLCMAC_UL_ASS_NONE) - LOGP(DRLCMAC, LOGL_ERROR, "%s Software error: Pending uplink " + LOGPTBF(tbf, LOGL_ERROR, "Software error: Pending uplink " "assignment in state %s. This may not happen, because the " "assignment message never gets transmitted. Please " "be sure not to free in this state. PLEASE FIX!\n", - tbf_name(tbf), get_value_string(gprs_rlcmac_tbf_ul_ass_state_names, tbf->ul_ass_state)); if (tbf->dl_ass_state != GPRS_RLCMAC_DL_ASS_NONE) - LOGP(DRLCMAC, LOGL_ERROR, "%s Software error: Pending downlink " + LOGPTBF(tbf, LOGL_ERROR, "Software error: Pending downlink " "assignment in state %s. This may not happen, because the " "assignment message never gets transmitted. Please " "be sure not to free in this state. PLEASE FIX!\n", - tbf_name(tbf), get_value_string(gprs_rlcmac_tbf_dl_ass_state_names, tbf->dl_ass_state)); tbf->stop_timer("freeing TBF"); @@ -473,7 +471,8 @@ void tbf_free(struct gprs_rlcmac_tbf *tbf) rate_ctr_group_free(tbf->m_ctrs); - LOGP(DRLCMAC, LOGL_DEBUG, "********** TBF ends here **********\n"); + LOGP(DRLCMAC, LOGL_DEBUG, "********** %s-TBF ends here **********\n", + (tbf->direction != GPRS_RLCMAC_UL_TBF) ? "DL" : "UL"); talloc_free(tbf); } @@ -482,11 +481,11 @@ int gprs_rlcmac_tbf::update() struct gprs_rlcmac_bts *bts_data = bts->bts_data(); int rc; - LOGP(DRLCMAC, LOGL_DEBUG, "********** TBF update **********\n"); - if (direction != GPRS_RLCMAC_DL_TBF) return -EINVAL; + LOGP(DRLCMAC, LOGL_DEBUG, "********** DL-TBF update **********\n"); + tbf_unlink_pdch(this); rc = bts_data->alloc_algorithm(bts_data, ms(), this, bts_data->alloc_algorithm_curst, 0, -1); @@ -508,10 +507,10 @@ int gprs_rlcmac_tbf::update() int tbf_assign_control_ts(struct gprs_rlcmac_tbf *tbf) { if (tbf->control_ts == 0xff) - LOGP(DRLCMAC, LOGL_INFO, "- Setting Control TS %d\n", + LOGPTBF(tbf, LOGL_INFO, "Setting Control TS %d\n", tbf->first_common_ts); else if (tbf->control_ts != tbf->first_common_ts) - LOGP(DRLCMAC, LOGL_INFO, "- Changing Control TS %d\n", + LOGPTBF(tbf, LOGL_INFO, "Changing Control TS %d\n", tbf->first_common_ts); tbf->control_ts = tbf->first_common_ts; @@ -556,8 +555,8 @@ void gprs_rlcmac_tbf::stop_t3191() void gprs_rlcmac_tbf::stop_timer(const char *reason) { if (osmo_timer_pending(&timer)) { - LOGP(DRLCMAC, LOGL_DEBUG, "%s stopping timer T%u [%s]\n", - tbf_name(this), T, reason); + LOGPTBF(this, LOGL_DEBUG, "stopping timer T%u [%s]\n", + T, reason); osmo_timer_del(&timer); } } @@ -568,21 +567,19 @@ int gprs_rlcmac_tbf::check_polling(uint32_t fn, uint8_t ts, uint32_t new_poll_fn = next_fn(fn, 13); if (!is_control_ts(ts)) { - LOGP(DRLCMAC, LOGL_DEBUG, "Polling cannot be " + LOGPTBF(this, LOGL_DEBUG, "Polling cannot be " "scheduled in this TS %d (first control TS %d)\n", ts, control_ts); return -EINVAL; } if (poll_state != GPRS_RLCMAC_POLL_NONE) { - LOGP(DRLCMAC, LOGL_DEBUG, - "Polling is already scheduled for %s\n", - name()); + LOGPTBF(this, LOGL_DEBUG, "Polling is already scheduled\n"); return -EBUSY; } if (bts->sba()->find(trx->trx_no, ts, next_fn(fn, 13))) { - LOGP(DRLCMAC, LOGL_DEBUG, "%s: Polling is already scheduled " + LOGPTBF(this, LOGL_DEBUG, "Polling is already scheduled " "for single block allocation at FN %d TS %d ...\n", - name(), new_poll_fn, ts); + new_poll_fn, ts); return -EBUSY; } @@ -642,8 +639,8 @@ void gprs_rlcmac_tbf::poll_timeout() { gprs_rlcmac_ul_tbf *ul_tbf = as_ul_tbf(this); - LOGP(DRLCMAC, LOGL_NOTICE, "%s poll timeout for FN=%d, TS=%d (curr FN %d)\n", - tbf_name(this), poll_fn, poll_ts, bts->current_frame_number()); + LOGPTBF(this, LOGL_NOTICE, "poll timeout for FN=%d, TS=%d (curr FN %d)\n", + poll_fn, poll_ts, bts->current_frame_number()); poll_state = GPRS_RLCMAC_POLL_NONE; @@ -739,9 +736,7 @@ void gprs_rlcmac_tbf::poll_timeout() /* resend IMM.ASS on CCCH on timeout */ if ((dl_tbf->state_flags & (1 << GPRS_RLCMAC_FLAG_CCCH)) && !(dl_tbf->state_flags & (1 << GPRS_RLCMAC_FLAG_DL_ACK))) { - LOGP(DRLCMAC, LOGL_DEBUG, "Re-send dowlink assignment " - "for %s on PCH (IMSI=%s)\n", - tbf_name(dl_tbf), + LOGPTBF(dl_tbf, LOGL_DEBUG, "Re-send dowlink assignment on PCH (IMSI=%s)\n", imsi()); /* send immediate assignment */ dl_tbf->bts->snd_dl_ass(dl_tbf, 0, imsi()); @@ -843,9 +838,9 @@ struct gprs_rlcmac_ul_tbf *tbf_alloc_ul_tbf(struct gprs_rlcmac_bts *bts, return NULL; } - LOGP(DRLCMAC, LOGL_DEBUG, "********** TBF starts here **********\n"); - LOGP(DRLCMAC, LOGL_INFO, "Allocating %s TBF: MS_CLASS=%d/%d\n", - "UL", ms_class, egprs_ms_class); + LOGP(DRLCMAC, LOGL_DEBUG, "********** UL-TBF starts here **********\n"); + LOGP(DRLCMAC, LOGL_INFO, "Allocating UL TBF: MS_CLASS=%d/%d\n", + ms_class, egprs_ms_class); tbf = talloc(tall_pcu_ctx, struct gprs_rlcmac_ul_tbf); @@ -936,9 +931,9 @@ struct gprs_rlcmac_dl_tbf *tbf_alloc_dl_tbf(struct gprs_rlcmac_bts *bts, egprs_ms_class = 1; } - LOGP(DRLCMAC, LOGL_DEBUG, "********** TBF starts here **********\n"); - LOGP(DRLCMAC, LOGL_INFO, "Allocating %s TBF: MS_CLASS=%d/%d\n", - "DL", ms_class, egprs_ms_class); + LOGP(DRLCMAC, LOGL_DEBUG, "********** DL-TBF starts here **********\n"); + LOGP(DRLCMAC, LOGL_INFO, "Allocating DL TBF: MS_CLASS=%d/%d\n", + ms_class, egprs_ms_class); tbf = talloc(tall_pcu_ctx, struct gprs_rlcmac_dl_tbf); @@ -1002,20 +997,19 @@ static void tbf_timer_cb(void *_tbf) void gprs_rlcmac_tbf::handle_timeout() { - LOGP(DRLCMAC, LOGL_DEBUG, "%s timer %u expired.\n", - tbf_name(this), T); + LOGPTBF(this, LOGL_DEBUG, "timer %u expired.\n", T); switch (T) { case 0: /* assignment */ if ((state_flags & (1 << GPRS_RLCMAC_FLAG_PACCH))) { if (state_is(GPRS_RLCMAC_ASSIGN)) { - LOGP(DRLCMAC, LOGL_NOTICE, "%s releasing due to " - "PACCH assignment timeout.\n", tbf_name(this)); + LOGPTBF(this, LOGL_NOTICE, + "releasing due to PACCH assignment timeout.\n"); tbf_free(this); return; } else - LOGP(DRLCMAC, LOGL_ERROR, "Error: %s is not " - "in assign state\n", tbf_name(this)); + LOGPTBF(this, LOGL_ERROR, + "Error: TBF is not in assign state\n"); } if ((state_flags & (1 << GPRS_RLCMAC_FLAG_CCCH))) { gprs_rlcmac_dl_tbf *dl_tbf = as_dl_tbf(this); @@ -1042,15 +1036,15 @@ void gprs_rlcmac_tbf::handle_timeout() dl_tbf->trigger_ass(dl_tbf); } else - LOGP(DRLCMAC, LOGL_NOTICE, "%s Continue flow after " - "IMM.ASS confirm\n", tbf_name(dl_tbf)); + LOGPTBF(dl_tbf, LOGL_NOTICE, + "Continue flow after IMM.ASS confirm\n"); } break; case 3169: case 3191: case 3195: - LOGP(DRLCMAC, LOGL_NOTICE, "%s T%d timeout during " - "transsmission\n", tbf_name(this), T); + LOGPTBF(this, LOGL_NOTICE, "T%d timeout during " + "transsmission\n", T); rlcmac_diag(); /* fall through */ case 3193: @@ -1105,9 +1099,8 @@ struct msgb *gprs_rlcmac_tbf::create_dl_ass(uint32_t fn, uint8_t ts) if (poll_state == GPRS_RLCMAC_POLL_SCHED && ul_ass_state == GPRS_RLCMAC_UL_ASS_WAIT_ACK) { - LOGP(DRLCMACUL, LOGL_DEBUG, "Polling is already " - "scheduled for %s, so we must wait for the uplink " - "assignment...\n", tbf_name(this)); + LOGPTBFUL(this, LOGL_DEBUG, + "Polling is already scheduled, so we must wait for the uplink assignment...\n"); return NULL; } rc = check_polling(fn, ts, &new_poll_fn, &rrbp); @@ -1133,9 +1126,8 @@ struct msgb *gprs_rlcmac_tbf::create_dl_ass(uint32_t fn, uint8_t ts) new_dl_tbf = ms()->dl_tbf(); if (!new_dl_tbf) { - LOGP(DRLCMACDL, LOGL_ERROR, "We have a schedule for downlink " - "assignment at %s, but there is no downlink " - "TBF\n", tbf_name(this)); + LOGPTBFDL(this, LOGL_ERROR, + "We have a schedule for downlink assignment, but there is no downlink TBF\n"); dl_ass_state = GPRS_RLCMAC_DL_ASS_NONE; return NULL; } @@ -1164,7 +1156,7 @@ struct msgb *gprs_rlcmac_tbf::create_dl_ass(uint32_t fn, uint8_t ts) } bitvec_unhex(ass_vec, "2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b"); - LOGP(DRLCMAC, LOGL_INFO, "%s start Packet Downlink Assignment (PACCH)\n", tbf_name(new_dl_tbf)); + LOGPTBF(new_dl_tbf, LOGL_INFO, "start Packet Downlink Assignment (PACCH)\n"); RlcMacDownlink_t * mac_control_block = (RlcMacDownlink_t *)talloc_zero(tall_pcu_ctx, RlcMacDownlink_t); Encoding::write_packet_downlink_assignment(mac_control_block, old_tfi_is_valid, m_tfi, (direction == GPRS_RLCMAC_DL_TBF), @@ -1233,9 +1225,8 @@ struct msgb *gprs_rlcmac_tbf::create_ul_ass(uint32_t fn, uint8_t ts) if (poll_state == GPRS_RLCMAC_POLL_SCHED && ul_ass_state == GPRS_RLCMAC_UL_ASS_WAIT_ACK) { - LOGP(DRLCMACUL, LOGL_DEBUG, "Polling is already " - "scheduled for %s, so we must wait for the uplink " - "assignment...\n", tbf_name(this)); + LOGPTBFUL(this, LOGL_DEBUG, + "Polling is already scheduled, so we must wait for the uplink assignment...\n"); return NULL; } @@ -1246,9 +1237,8 @@ struct msgb *gprs_rlcmac_tbf::create_ul_ass(uint32_t fn, uint8_t ts) if (ms()) new_tbf = ms()->ul_tbf(); if (!new_tbf) { - LOGP(DRLCMACUL, LOGL_ERROR, "We have a schedule for uplink " - "assignment at downlink %s, but there is no uplink " - "TBF\n", tbf_name(this)); + LOGPTBFUL(this, LOGL_ERROR, + "We have a schedule for uplink assignment, but there is no uplink TBF\n"); ul_ass_state = GPRS_RLCMAC_UL_ASS_NONE; return NULL; } @@ -1256,7 +1246,7 @@ struct msgb *gprs_rlcmac_tbf::create_ul_ass(uint32_t fn, uint8_t ts) msg = msgb_alloc(23, "rlcmac_ul_ass"); if (!msg) return NULL; - LOGP(DRLCMAC, LOGL_INFO, "%ss start Packet Uplink Assignment (PACCH)\n", tbf_name(new_tbf)); + LOGPTBF(new_tbf, LOGL_INFO, "start Packet Uplink Assignment (PACCH)\n"); bitvec *ass_vec = bitvec_alloc(23, tall_pcu_ctx); if (!ass_vec) { msgb_free(msg); @@ -1318,8 +1308,7 @@ int gprs_rlcmac_tbf::establish_dl_tbf_on_pacch() return -1; } - LOGP(DRLCMAC, LOGL_DEBUG, "%s Trigger downlink assignment on PACCH\n", - tbf_name(this)); + LOGPTBF(this, LOGL_DEBUG, "Trigger downlink assignment on PACCH\n"); new_tbf->trigger_ass(this); return 0; @@ -1346,18 +1335,14 @@ int gprs_rlcmac_tbf::set_tlli_from_ul(uint32_t new_tlli) } if (dl_tbf && dl_tbf->ms() != ms()) { - LOGP(DRLCMACUL, LOGL_NOTICE, "Got RACH from " - "TLLI=0x%08x while %s still exists. " - "Killing pending DL TBF\n", new_tlli, - tbf_name(dl_tbf)); + LOGPTBFUL(dl_tbf, LOGL_NOTICE, + "Got RACH from TLLI=0x%08x while TBF still exists: killing pending DL TBF\n", new_tlli); tbf_free(dl_tbf); dl_tbf = NULL; } if (ul_tbf && ul_tbf->ms() != ms()) { - LOGP(DRLCMACUL, LOGL_NOTICE, "Got RACH from " - "TLLI=0x%08x while %s still exists. " - "Killing pending UL TBF\n", new_tlli, - tbf_name(ul_tbf)); + LOGPTBFUL(ul_tbf, LOGL_NOTICE, + "Got RACH from TLLI=0x%08x while TBF still exists: killing pending UL TBF\n", new_tlli); tbf_free(ul_tbf); ul_tbf = NULL; } @@ -134,6 +134,10 @@ enum tbf_egprs_ul_counters { TBF_CTR_EGPRS_UL_MCS9, }; +#define LOGPTBF(tbf, level, fmt, args...) LOGP(DRLCMAC, level, "%s " fmt, tbf_name(tbf), ## args) +#define LOGPTBFUL(tbf, level, fmt, args...) LOGP(DRLCMACUL, level, "%s " fmt, tbf_name(tbf), ## args) +#define LOGPTBFDL(tbf, level, fmt, args...) LOGP(DRLCMACDL, level, "%s " fmt, tbf_name(tbf), ## args) + #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 */ diff --git a/src/tbf_dl.cpp b/src/tbf_dl.cpp index 4fc60e4c..0bcb67b1 100644 --- a/src/tbf_dl.cpp +++ b/src/tbf_dl.cpp @@ -58,8 +58,7 @@ static void llc_timer_cb(void *_tbf) if (tbf->state_is_not(GPRS_RLCMAC_FLOW)) return; - LOGP(DRLCMAC, LOGL_DEBUG, - "%s LLC receive timeout, requesting DL ACK\n", tbf_name(tbf)); + LOGPTBFDL(tbf, LOGL_DEBUG, "LLC receive timeout, requesting DL ACK\n"); tbf->request_dl_ack(); } @@ -87,7 +86,7 @@ int gprs_rlcmac_dl_tbf::append_data(const uint8_t ms_class, const uint16_t pdu_delay_csec, const uint8_t *data, const uint16_t len) { - LOGP(DRLCMAC, LOGL_INFO, "%s append\n", tbf_name(this)); + LOGPTBFDL(this, LOGL_DEBUG, "appending %u bytes\n", len); gprs_llc_queue::MetaInfo info; struct msgb *llc_msg = msgb_alloc(len, "llc_pdu_queue"); if (!llc_msg) @@ -101,9 +100,7 @@ int gprs_rlcmac_dl_tbf::append_data(const uint8_t ms_class, start_llc_timer(); if (state_is(GPRS_RLCMAC_WAIT_RELEASE)) { - LOGP(DRLCMAC, LOGL_DEBUG, - "%s in WAIT RELEASE state " - "(T3193), so reuse TBF\n", tbf_name(this)); + LOGPTBFDL(this, LOGL_DEBUG, "in WAIT RELEASE state (T3193), so reuse TBF\n"); tbf_update_ms_class(this, ms_class); establish_dl_tbf_on_pacch(); } @@ -156,7 +153,7 @@ static int tbf_new_dl_assignment(struct gprs_rlcmac_bts *bts, dl_tbf->update_ms(tlli, GPRS_RLCMAC_DL_TBF); dl_tbf->ms()->set_ta(ta); - LOGP(DRLCMAC, LOGL_DEBUG, "%s [DOWNLINK] START\n", tbf_name(dl_tbf)); + LOGPTBFDL(dl_tbf, LOGL_DEBUG, "[DOWNLINK] START\n"); /* Store IMSI for later look-up and PCH retransmission */ dl_tbf->assign_imsi(imsi); @@ -305,10 +302,10 @@ drop_frame: } if (frames) { - LOGP(DRLCMACDL, LOGL_NOTICE, "%s Discarding LLC PDU " + LOGPTBFDL(this, LOGL_NOTICE, "Discarding LLC PDU " "because lifetime limit reached, " "count=%u new_queue_size=%zu\n", - tbf_name(this), frames, llc_queue_size()); + frames, llc_queue_size()); if (frames > 0xff) frames = 0xff; if (octets > 0xffffff) @@ -470,9 +467,8 @@ struct msgb *gprs_rlcmac_dl_tbf::create_dl_acked_block(uint32_t fn, uint8_t ts) int bsn, bsn2 = -1; bool may_combine; - LOGP(DRLCMACDL, LOGL_DEBUG, "%s downlink (V(A)==%d .. " - "V(S)==%d)\n", tbf_name(this), - m_window.v_a(), m_window.v_s()); + LOGPTBFDL(this, LOGL_DEBUG, "downlink (V(A)==%d .. V(S)==%d)\n", + m_window.v_a(), m_window.v_s()); bsn = take_next_bsn(fn, -1, &may_combine); if (bsn < 0) @@ -492,7 +488,7 @@ void gprs_rlcmac_dl_tbf::trigger_ass(struct gprs_rlcmac_tbf *old_tbf) /* check for downlink tbf: */ if (old_tbf) { - LOGP(DRLCMACDL, LOGL_DEBUG, "Send dowlink assignment on PACCH, because %s exists\n", tbf_name(old_tbf)); + LOGPTBFDL(this, LOGL_DEBUG, "Send dowlink assignment on PACCH, because %s exists\n", old_tbf->name()); old_tbf->dl_ass_state = GPRS_RLCMAC_DL_ASS_SEND_ASS; old_tbf->was_releasing = old_tbf->state_is(GPRS_RLCMAC_WAIT_RELEASE); @@ -504,8 +500,8 @@ void gprs_rlcmac_dl_tbf::trigger_ass(struct gprs_rlcmac_tbf *old_tbf) /* start timer */ tbf_timer_start(this, 0, Tassign_pacch, "assignment (PACCH)"); } else { - LOGP(DRLCMACDL, LOGL_DEBUG, "Send dowlink assignment for %s on PCH, no TBF exist (IMSI=%s)\n", - tbf_name(this), imsi()); + LOGPTBFDL(this, LOGL_DEBUG, "Send dowlink assignment on PCH, no TBF exist (IMSI=%s)\n", + imsi()); was_releasing = state_is(GPRS_RLCMAC_WAIT_RELEASE); /* change state */ @@ -530,9 +526,7 @@ void gprs_rlcmac_dl_tbf::schedule_next_frame() if (!msg) return; - LOGP(DRLCMACDL, LOGL_INFO, - "- Dequeue next LLC for %s (len=%d)\n", - tbf_name(this), msg->len); + LOGPTBFDL(this, LOGL_INFO, "Dequeue next LLC (len=%d)\n", msg->len); m_llc.put_frame(msg->data, msg->len); bts->llc_frame_sched(); @@ -616,8 +610,7 @@ int gprs_rlcmac_dl_tbf::create_new_bsn(const uint32_t fn, GprsCodingScheme cs) if (ar == Encoding::AR_NEED_MORE_BLOCKS) break; - LOGP(DRLCMACDL, LOGL_INFO, "Complete DL frame for %s" - "len=%d\n", tbf_name(this), m_llc.frame_length()); + LOGPTBFDL(this, LOGL_INFO, "Complete DL frame, len=%d\n", m_llc.frame_length()); gprs_rlcmac_dl_bw(this, m_llc.frame_length()); bts->llc_dl_bytes(m_llc.frame_length()); m_llc.reset(); @@ -1058,8 +1051,7 @@ int gprs_rlcmac_dl_tbf::update_window(const uint8_t ssn, const uint8_t *rbb) * to previous TBF * FIXME: we should implement polling for * control ack!*/ - LOGP(DRLCMACDL, LOGL_NOTICE, "- ack range is out of " - "V(A)..V(S) range %s Free TBF!\n", tbf_name(this)); + LOGPTBFDL(this, LOGL_NOTICE, "ack range is out of V(A)..V(S) range - Free TBF!\n"); return 1; /* indicate to free TBF */ } @@ -1172,7 +1164,7 @@ int gprs_rlcmac_dl_tbf::rcvd_dl_ack(uint8_t final_ack, unsigned first_bsn, struct bitvec *rbb) { int rc; - LOGP(DRLCMACDL, LOGL_DEBUG, "%s downlink acknowledge\n", tbf_name(this)); + LOGPTBFDL(this, LOGL_DEBUG, "downlink acknowledge\n"); rc = update_window(first_bsn, rbb); @@ -1190,12 +1182,12 @@ int gprs_rlcmac_dl_tbf::rcvd_dl_ack(uint8_t final_ack, unsigned first_bsn, int gprs_rlcmac_dl_tbf::rcvd_dl_ack(uint8_t final_ack, uint8_t ssn, uint8_t *rbb) { - LOGP(DRLCMACDL, LOGL_DEBUG, "%s downlink acknowledge\n", tbf_name(this)); + LOGPTBFDL(this, LOGL_DEBUG, "downlink acknowledge\n"); if (!final_ack) return update_window(ssn, rbb); - LOGP(DRLCMACDL, LOGL_DEBUG, "- Final ACK received.\n"); + LOGPTBFDL(this, LOGL_DEBUG, "Final ACK received.\n"); return maybe_start_new_window(); } diff --git a/src/tbf_ul.cpp b/src/tbf_ul.cpp index 0bbb817d..09ee1f04 100644 --- a/src/tbf_ul.cpp +++ b/src/tbf_ul.cpp @@ -84,8 +84,7 @@ int gprs_rlcmac_ul_tbf::assemble_forward_llc(const gprs_rlc_data *_data) if (frame->is_complete) { /* send frame to SGSN */ - LOGP(DRLCMACUL, LOGL_INFO, "%s complete UL frame len=%d\n", - tbf_name(this) , m_llc.frame_length()); + LOGPTBFUL(this, LOGL_INFO, "complete UL frame len=%d\n", m_llc.frame_length()); snd_ul_ud(); bts->llc_ul_bytes(m_llc.frame_length()); m_llc.reset(); @@ -128,9 +127,8 @@ struct msgb *gprs_rlcmac_ul_tbf::create_ul_ack(uint32_t fn, uint8_t ts) if (final) { if (poll_state == GPRS_RLCMAC_POLL_SCHED && ul_ack_state == GPRS_RLCMAC_UL_ACK_WAIT_ACK) { - LOGP(DRLCMACUL, LOGL_DEBUG, "Polling is already " - "scheduled for %s, so we must wait for " - "the final uplink ack...\n", tbf_name(this)); + LOGPTBFUL(this, LOGL_DEBUG, + "Polling is already scheduled, so we must wait for the final uplink ack...\n"); return NULL; } |