forked from cellular-infrastructure/osmo-pcu
debug_diagram: Remove the special debug_diagram compilation mode
This approach is somehow flawed. We need/want to debug problems on systems with real traffic and re-compiling it with debug_diagram is not an option. All internal logging needs to be expressive enough so we can understand what is going on (e.g. create a script to post-process the output).
This commit is contained in:
Holger Hans Peter Freyther
parent
a6ba67cb3a
commit
12c039cdb2
|
|
@ -499,7 +499,6 @@ void BTS::snd_dl_ass(gprs_rlcmac_tbf *tbf, uint8_t poll, const char *imsi)
|
|||
{
|
||||
int plen;
|
||||
|
||||
debug_diagram(this, tbf->diag, "IMM.ASS (PCH)");
|
||||
LOGP(DRLCMAC, LOGL_INFO, "TX: START %s Immediate Assignment Downlink (PCH)\n", tbf_name(tbf));
|
||||
bitvec *immediate_assignment = bitvec_alloc(22); /* without plen */
|
||||
bitvec_unhex(immediate_assignment, "2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b");
|
||||
|
|
@ -709,7 +708,6 @@ void gprs_rlcmac_pdch::rcv_control_ack(Packet_Control_Acknowledgement_t *packet,
|
|||
if (tbf->ul_ack_state == GPRS_RLCMAC_UL_ACK_WAIT_ACK) {
|
||||
LOGP(DRLCMAC, LOGL_DEBUG, "TBF: [UPLINK] END %s\n", tbf_name(tbf));
|
||||
tbf->ul_ack_state = GPRS_RLCMAC_UL_ACK_NONE;
|
||||
debug_diagram(bts(), tbf->diag, "got CTL-ACK (fin)");
|
||||
if ((tbf->state_flags &
|
||||
(1 << GPRS_RLCMAC_FLAG_TO_UL_ACK))) {
|
||||
tbf->state_flags &=
|
||||
|
|
@ -725,7 +723,6 @@ void gprs_rlcmac_pdch::rcv_control_ack(Packet_Control_Acknowledgement_t *packet,
|
|||
/* reset N3105 */
|
||||
tbf->n3105 = 0;
|
||||
tbf->dl_ass_state = GPRS_RLCMAC_DL_ASS_NONE;
|
||||
debug_diagram(bts(), tbf->diag, "got CTL-ACK DL-ASS");
|
||||
if (tbf->direction == GPRS_RLCMAC_UL_TBF)
|
||||
tbf = bts()->tbf_by_tlli(tbf->tlli(),
|
||||
GPRS_RLCMAC_DL_TBF);
|
||||
|
|
@ -753,7 +750,6 @@ void gprs_rlcmac_pdch::rcv_control_ack(Packet_Control_Acknowledgement_t *packet,
|
|||
/* reset N3105 */
|
||||
tbf->n3105 = 0;
|
||||
tbf->ul_ass_state = GPRS_RLCMAC_UL_ASS_NONE;
|
||||
debug_diagram(bts(), tbf->diag, "got CTL-AC UL-ASS");
|
||||
#warning "TBF is changing on the way... *sigh*"
|
||||
if (tbf->direction == GPRS_RLCMAC_DL_TBF)
|
||||
tbf = bts()->tbf_by_tlli(tbf->tlli(),
|
||||
|
|
@ -808,7 +804,6 @@ void gprs_rlcmac_pdch::rcv_control_dl_ack_nack(Packet_Downlink_Ack_Nack_t *ack_n
|
|||
tbf->stop_t3191();
|
||||
LOGP(DRLCMAC, LOGL_DEBUG, "RX: [PCU <- BTS] %s Packet Downlink Ack/Nack\n", tbf_name(tbf));
|
||||
tbf->poll_state = GPRS_RLCMAC_POLL_NONE;
|
||||
debug_diagram(bts(), tbf->diag, "got DL-ACK");
|
||||
|
||||
rc = tbf->snd_dl_ack(
|
||||
ack_nack->Ack_Nack_Description.FINAL_ACK_INDICATION,
|
||||
|
|
@ -888,7 +883,6 @@ void gprs_rlcmac_pdch::rcv_resource_request(Packet_Resource_Request_t *request,
|
|||
tbf->control_ts = ts_no;
|
||||
/* schedule uplink assignment */
|
||||
tbf->ul_ass_state = GPRS_RLCMAC_UL_ASS_SEND_ASS;
|
||||
debug_diagram(bts->bts, tbf->diag, "Res. REQ");
|
||||
return;
|
||||
}
|
||||
|
||||
|
|
|
|||
|
|
@ -29,90 +29,6 @@
|
|||
|
||||
extern void *tall_pcu_ctx;
|
||||
|
||||
#ifdef DEBUG_DIAGRAM
|
||||
struct timeval diagram_time = {0,0};
|
||||
struct timeval diagram_last_tv = {0,0};
|
||||
|
||||
void debug_diagram(BTS *bts, int diag, const char *format, ...)
|
||||
{
|
||||
va_list ap;
|
||||
char debug[128];
|
||||
char line[1024];
|
||||
struct gprs_rlcmac_tbf *tbf, *tbf_a[16];
|
||||
int max_diag = -1, i;
|
||||
uint64_t diff = 0;
|
||||
|
||||
va_start(ap, format);
|
||||
vsnprintf(debug, sizeof(debug) - 1, format, ap);
|
||||
debug[19] = ' ';
|
||||
debug[20] = '\0';
|
||||
va_end(ap);
|
||||
|
||||
memset(tbf_a, 0, sizeof(tbf_a));
|
||||
llist_for_each_entry(tbf, &bts->bts_data()->ul_tbfs, list) {
|
||||
if (tbf->diag < 16) {
|
||||
if (tbf->diag > max_diag)
|
||||
max_diag = tbf->diag;
|
||||
tbf_a[tbf->diag] = tbf;
|
||||
}
|
||||
}
|
||||
llist_for_each_entry(tbf, &bts->bts_data()->dl_tbfs, list) {
|
||||
if (tbf->diag < 16) {
|
||||
if (tbf->diag > max_diag)
|
||||
max_diag = tbf->diag;
|
||||
tbf_a[tbf->diag] = tbf;
|
||||
}
|
||||
}
|
||||
|
||||
if (diagram_last_tv.tv_sec) {
|
||||
diff = (uint64_t)(diagram_time.tv_sec -
|
||||
diagram_last_tv.tv_sec) * 1000;
|
||||
diff += diagram_time.tv_usec / 1000;
|
||||
diff -= diagram_last_tv.tv_usec / 1000;
|
||||
}
|
||||
memcpy(&diagram_last_tv, &diagram_time, sizeof(struct timeval));
|
||||
|
||||
if (diff > 0) {
|
||||
if (diff > 99999)
|
||||
strcpy(line, " ... : ");
|
||||
else
|
||||
sprintf(line, "%3d.%03d: ", (int)(diff / 1000),
|
||||
(int)(diff % 1000));
|
||||
for (i = 0; i <= max_diag; i++) {
|
||||
if (tbf_a[i] == NULL) {
|
||||
strcat(line, " ");
|
||||
continue;
|
||||
}
|
||||
if (tbf_a[i]->diag_new) {
|
||||
strcat(line, " | ");
|
||||
continue;
|
||||
}
|
||||
strcat(line, " ");
|
||||
}
|
||||
puts(line);
|
||||
}
|
||||
strcpy(line, " : ");
|
||||
for (i = 0; i <= max_diag; i++) {
|
||||
if (tbf_a[i] == NULL) {
|
||||
strcat(line, " ");
|
||||
continue;
|
||||
}
|
||||
if (tbf_a[i]->diag != diag) {
|
||||
strcat(line, " | ");
|
||||
continue;
|
||||
}
|
||||
if (strlen(debug) < 19) {
|
||||
strcat(line, " ");
|
||||
memcpy(line + strlen(line) - 11 - strlen(debug) / 2,
|
||||
debug, strlen(debug));
|
||||
} else
|
||||
strcat(line, debug);
|
||||
tbf_a[i]->diag_new = 1;
|
||||
}
|
||||
puts(line);
|
||||
}
|
||||
#endif
|
||||
|
||||
int gprs_rlcmac_paging_request(uint8_t *ptmsi, uint16_t ptmsi_len,
|
||||
const char *imsi)
|
||||
{
|
||||
|
|
|
|||
|
|
@ -32,9 +32,6 @@ extern "C" {
|
|||
}
|
||||
#endif
|
||||
|
||||
/* generate a diagram for debugging timing issues */
|
||||
//#define DEBUG_DIAGRAM
|
||||
|
||||
/* This special feature will delay assignment of downlink TBF by one second,
|
||||
* in case there is already a TBF.
|
||||
* This is usefull to debug downlink establishment during packet idle mode.
|
||||
|
|
@ -65,12 +62,6 @@ struct gprs_rlcmac_cs {
|
|||
uint8_t block_payload;
|
||||
};
|
||||
|
||||
#ifdef DEBUG_DIAGRAM
|
||||
void debug_diagram(BTS *bts, int diag, const char *format, ...);
|
||||
#else
|
||||
#define debug_diagram(a, b, c, args...) ;
|
||||
#endif
|
||||
|
||||
int gprs_rlcmac_received_lost(struct gprs_rlcmac_tbf *tbf, uint16_t received,
|
||||
uint16_t lost);
|
||||
|
||||
|
|
|
|||
|
|
@ -44,10 +44,6 @@ extern void *bv_tall_ctx;
|
|||
static int quit = 0;
|
||||
static int rt_prio = -1;
|
||||
|
||||
#ifdef DEBUG_DIAGRAM
|
||||
extern struct timeval diagram_time;
|
||||
#endif
|
||||
|
||||
static void print_help()
|
||||
{
|
||||
printf( "Some useful options:\n"
|
||||
|
|
@ -242,9 +238,6 @@ int main(int argc, char *argv[])
|
|||
osmo_gsm_timers_update();
|
||||
|
||||
osmo_select_main(0);
|
||||
#ifdef DEBUG_DIAGRAM
|
||||
gettimeofday(&diagram_time, NULL);
|
||||
#endif
|
||||
}
|
||||
|
||||
telnet_exit();
|
||||
|
|
|
|||
64
src/tbf.cpp
64
src/tbf.cpp
|
|
@ -280,9 +280,6 @@ void tbf_free(struct gprs_rlcmac_tbf *tbf)
|
|||
gprs_rlcmac_rssi_rep(tbf);
|
||||
gprs_rlcmac_lost_rep(tbf);
|
||||
|
||||
debug_diagram(tbf->bts, tbf->diag, "+---------------+");
|
||||
debug_diagram(tbf->bts, tbf->diag, "| THE END |");
|
||||
debug_diagram(tbf->bts, tbf->diag, "+---------------+");
|
||||
LOGP(DRLCMAC, LOGL_INFO, "%s free\n", tbf_name(tbf));
|
||||
if (tbf->ul_ass_state != GPRS_RLCMAC_UL_ASS_NONE)
|
||||
LOGP(DRLCMAC, LOGL_ERROR, "%s Software error: Pending uplink "
|
||||
|
|
@ -365,7 +362,6 @@ static const char *tbf_state_name[] = {
|
|||
void tbf_new_state(struct gprs_rlcmac_tbf *tbf,
|
||||
enum gprs_rlcmac_tbf_state state)
|
||||
{
|
||||
debug_diagram(tbf->bts, tbf->diag, "->%s", tbf_state_name[state]);
|
||||
LOGP(DRLCMAC, LOGL_DEBUG, "%s changes state from %s to %s\n",
|
||||
tbf_name(tbf),
|
||||
tbf_state_name[tbf->state], tbf_state_name[state]);
|
||||
|
|
@ -422,13 +418,11 @@ void gprs_rlcmac_tbf::poll_timeout()
|
|||
state_flags |= (1 << GPRS_RLCMAC_FLAG_TO_UL_ACK);
|
||||
}
|
||||
ul_ack_state = GPRS_RLCMAC_UL_ACK_NONE;
|
||||
debug_diagram(bts, this->diag, "timeout UL-ACK");
|
||||
if (state_is(GPRS_RLCMAC_FINISHED)) {
|
||||
dir.ul.n3103++;
|
||||
if (dir.ul.n3103 == bts->bts_data()->n3103) {
|
||||
LOGP(DRLCMAC, LOGL_NOTICE,
|
||||
"- N3103 exceeded\n");
|
||||
debug_diagram(bts, diag, "N3103 exceeded");
|
||||
tbf_new_state(this, GPRS_RLCMAC_RELEASING);
|
||||
tbf_timer_start(this, 3169, bts->bts_data()->t3169, 0);
|
||||
return;
|
||||
|
|
@ -445,11 +439,9 @@ void gprs_rlcmac_tbf::poll_timeout()
|
|||
state_flags |= (1 << GPRS_RLCMAC_FLAG_TO_UL_ASS);
|
||||
}
|
||||
ul_ass_state = GPRS_RLCMAC_UL_ASS_NONE;
|
||||
debug_diagram(bts, diag, "timeout UL-ASS");
|
||||
n3105++;
|
||||
if (n3105 == bts_data()->n3105) {
|
||||
LOGP(DRLCMAC, LOGL_NOTICE, "- N3105 exceeded\n");
|
||||
debug_diagram(bts, diag, "N3105 exceeded");
|
||||
tbf_new_state(this, GPRS_RLCMAC_RELEASING);
|
||||
tbf_timer_start(this, 3195, bts_data()->t3195, 0);
|
||||
return;
|
||||
|
|
@ -465,11 +457,9 @@ void gprs_rlcmac_tbf::poll_timeout()
|
|||
state_flags |= (1 << GPRS_RLCMAC_FLAG_TO_DL_ASS);
|
||||
}
|
||||
dl_ass_state = GPRS_RLCMAC_DL_ASS_NONE;
|
||||
debug_diagram(bts, diag, "timeout DL-ASS");
|
||||
n3105++;
|
||||
if (n3105 == bts->bts_data()->n3105) {
|
||||
LOGP(DRLCMAC, LOGL_NOTICE, "- N3105 exceeded\n");
|
||||
debug_diagram(bts, diag, "N3105 exceeded");
|
||||
tbf_new_state(this, GPRS_RLCMAC_RELEASING);
|
||||
tbf_timer_start(this, 3195, bts_data()->t3195, 0);
|
||||
return;
|
||||
|
|
@ -483,11 +473,9 @@ void gprs_rlcmac_tbf::poll_timeout()
|
|||
rlcmac_diag();
|
||||
state_flags |= (1 << GPRS_RLCMAC_FLAG_TO_DL_ACK);
|
||||
}
|
||||
debug_diagram(bts, diag, "timeout DL-ACK");
|
||||
n3105++;
|
||||
if (n3105 == bts->bts_data()->n3105) {
|
||||
LOGP(DRLCMAC, LOGL_NOTICE, "- N3105 exceeded\n");
|
||||
debug_diagram(bts, diag, "N3105 exceeded");
|
||||
tbf_new_state(this, GPRS_RLCMAC_RELEASING);
|
||||
tbf_timer_start(this, 3195, bts_data()->t3195, 0);
|
||||
return;
|
||||
|
|
@ -515,24 +503,6 @@ struct gprs_rlcmac_tbf *tbf_alloc(struct gprs_rlcmac_bts *bts,
|
|||
struct gprs_rlcmac_tbf *tbf;
|
||||
int rc;
|
||||
|
||||
#ifdef DEBUG_DIAGRAM
|
||||
/* hunt for first free number in diagram */
|
||||
int diagram_num;
|
||||
for (diagram_num = 0; ; diagram_num++) {
|
||||
llist_for_each_entry(tbf, &bts->ul_tbfs, list) {
|
||||
if (tbf->diag == diagram_num)
|
||||
goto next_diagram;
|
||||
}
|
||||
llist_for_each_entry(tbf, &bts->dl_tbfs, list) {
|
||||
if (tbf->diag == diagram_num)
|
||||
goto next_diagram;
|
||||
}
|
||||
break;
|
||||
next_diagram:
|
||||
continue;
|
||||
}
|
||||
#endif
|
||||
|
||||
LOGP(DRLCMAC, LOGL_DEBUG, "********** TBF starts here **********\n");
|
||||
LOGP(DRLCMAC, LOGL_INFO, "Allocating %s TBF: TFI=%d TRX=%d "
|
||||
"MS_CLASS=%d\n", (dir == GPRS_RLCMAC_UL_TBF) ? "UL" : "DL",
|
||||
|
|
@ -546,9 +516,6 @@ next_diagram:
|
|||
return NULL;
|
||||
|
||||
tbf->bts = bts->bts;
|
||||
#ifdef DEBUG_DIAGRAM
|
||||
tbf->diag = diagram_num;
|
||||
#endif
|
||||
tbf->direction = dir;
|
||||
tbf->m_tfi = tfi;
|
||||
tbf->trx = &bts->trx[trx];
|
||||
|
|
@ -586,11 +553,6 @@ next_diagram:
|
|||
tbf->bts->tbf_dl_created();
|
||||
}
|
||||
|
||||
debug_diagram(bts->bts, tbf->diag, "+-----------------+");
|
||||
debug_diagram(bts->bts, tbf->diag, "|NEW %s TBF TFI=%2d|",
|
||||
(dir == GPRS_RLCMAC_UL_TBF) ? "UL" : "DL", tfi);
|
||||
debug_diagram(bts->bts, tbf->diag, "+-----------------+");
|
||||
|
||||
return tbf;
|
||||
}
|
||||
|
||||
|
|
@ -637,8 +599,6 @@ void gprs_rlcmac_tbf::handle_timeout()
|
|||
rlcmac_diag();
|
||||
/* fall through */
|
||||
case 3193:
|
||||
if (T == 3193)
|
||||
debug_diagram(bts, diag, "T3193 timeout");
|
||||
LOGP(DRLCMAC, LOGL_DEBUG,
|
||||
"%s will be freed due to timeout\n", tbf_name(this));
|
||||
/* free TBF */
|
||||
|
|
@ -1169,14 +1129,6 @@ struct msgb *gprs_rlcmac_tbf::create_dl_acked_block(
|
|||
poll_state = GPRS_RLCMAC_POLL_SCHED;
|
||||
poll_fn = (fn + 13) % 2715648;
|
||||
|
||||
#ifdef DEBUG_DIAGRAM
|
||||
debug_diagram(bts, diag, "poll DL-ACK");
|
||||
if (first_fin_ack)
|
||||
debug_diagram(bts, diag, "(is first FINAL)");
|
||||
if (rh->fbi)
|
||||
debug_diagram(bts, diag, "(FBI is set)");
|
||||
#endif
|
||||
|
||||
/* set polling in header */
|
||||
rh->rrbp = 0; /* N+13 */
|
||||
rh->s_p = 1; /* Polling */
|
||||
|
|
@ -1282,7 +1234,6 @@ struct msgb *gprs_rlcmac_tbf::create_dl_ass(uint32_t fn)
|
|||
new_tbf->stop_timer();
|
||||
|
||||
}
|
||||
debug_diagram(bts, diag, "send DL-ASS");
|
||||
|
||||
return msg;
|
||||
}
|
||||
|
|
@ -1354,7 +1305,6 @@ struct msgb *gprs_rlcmac_tbf::create_ul_ass(uint32_t fn)
|
|||
tbf_new_state(new_tbf, GPRS_RLCMAC_FLOW);
|
||||
tbf_assign_control_ts(new_tbf);
|
||||
#endif
|
||||
debug_diagram(bts, diag, "send UL-ASS");
|
||||
|
||||
return msg;
|
||||
}
|
||||
|
|
@ -1407,7 +1357,6 @@ struct msgb *gprs_rlcmac_tbf::create_ul_ack(uint32_t fn)
|
|||
dir.ul.final_ack_sent = 1;
|
||||
} else
|
||||
ul_ack_state = GPRS_RLCMAC_UL_ACK_NONE;
|
||||
debug_diagram(bts->bts, diag, "send UL-ACK");
|
||||
|
||||
return msg;
|
||||
}
|
||||
|
|
@ -1506,7 +1455,6 @@ int gprs_rlcmac_tbf::snd_dl_ack(uint8_t final, uint8_t ssn, uint8_t *rbb)
|
|||
}
|
||||
|
||||
LOGP(DRLCMACDL, LOGL_DEBUG, "- Final ACK received.\n");
|
||||
debug_diagram(ts, diag, "got Final ACK");
|
||||
/* range V(A)..V(S)-1 */
|
||||
for (bsn = dir.dl.v_a; bsn != dir.dl.v_s;
|
||||
bsn = (bsn + 1) & mod_sns) {
|
||||
|
|
@ -1524,7 +1472,6 @@ int gprs_rlcmac_tbf::snd_dl_ack(uint8_t final, uint8_t ssn, uint8_t *rbb)
|
|||
LOGP(DRLCMACDL, LOGL_DEBUG, "- No new message, so we "
|
||||
"release.\n");
|
||||
/* start T3193 */
|
||||
debug_diagram(bts, diag, "start T3193");
|
||||
tbf_timer_start(this, 3193,
|
||||
bts_data()->t3193_msec / 1000,
|
||||
(bts_data()->t3193_msec % 1000) * 1000);
|
||||
|
|
@ -1776,17 +1723,6 @@ int gprs_rlcmac_tbf::rcv_data_block_acknowledged(const uint8_t *data, size_t len
|
|||
SEND_ACK_AFTER_FRAMES);
|
||||
}
|
||||
if (this->ul_ack_state == GPRS_RLCMAC_UL_ACK_NONE) {
|
||||
#ifdef DEBUG_DIAGRAM
|
||||
if (rh->si)
|
||||
debug_diagram(bts->bts, this->diag, "sched UL-ACK stall");
|
||||
if (rh->ti)
|
||||
debug_diagram(bts->bts, this->diag, "sched UL-ACK TLLI");
|
||||
if (this->state_is(GPRS_RLCMAC_FINISHED))
|
||||
debug_diagram(bts->bts, this->diag, "sched UL-ACK CV==0");
|
||||
if ((this->dir.ul.rx_counter % SEND_ACK_AFTER_FRAMES) == 0)
|
||||
debug_diagram(bts->bts, this->diag, "sched UL-ACK n=%d",
|
||||
this->dir.ul.rx_counter);
|
||||
#endif
|
||||
/* trigger sending at next RTS */
|
||||
this->ul_ack_state = GPRS_RLCMAC_UL_ACK_SEND_ACK;
|
||||
} else {
|
||||
|
|
|
|||
|
|
@ -215,11 +215,6 @@ struct gprs_rlcmac_tbf {
|
|||
|
||||
uint8_t cs; /* current coding scheme */
|
||||
|
||||
#ifdef DEBUG_DIAGRAM
|
||||
int diag; /* number where TBF is presented in diagram */
|
||||
int diag_new; /* used to format output of new TBF */
|
||||
#endif
|
||||
|
||||
/* these should become protected but only after gprs_rlcmac_data.c
|
||||
* stops to iterate over all tbf in its current form */
|
||||
enum gprs_rlcmac_tbf_state state;
|
||||
|
|
|
|||
Loading…
Reference in New Issue