diff --git a/src/cmdu_ackq.c b/src/cmdu_ackq.c index 30d233f31223b81f0d403ec6c9b4c46e3abaa067..92e1abab02a6b823fd0427486a9902e9a1482efa 100644 --- a/src/cmdu_ackq.c +++ b/src/cmdu_ackq.c @@ -88,8 +88,9 @@ struct cmdu_ackq_entry *cmdu_ackq_create_msg(uint16_t type, uint16_t mid, memcpy(msg->origin, dest, 6); msg->resend_cnt = resend_cnt; msg->cookie = cookie; - dbg(" CREATE msg: type = 0x%04x mid = %hu origin = " MACFMT " timeout = { %u ms (%lu:%lu) }\n", + dbg(" CREATE msg: type = 0x%04x mid = %hu origin = " MACFMT " timeout = { %u ms (now = %lu.%lu, when = %lu.%lu) }\n", type, mid, MAC2STR(dest), msg->ageing_time, + tsp.tv_sec, tsp.tv_usec / 1000, msg->ageing_tmo.tv_sec, msg->ageing_tmo.tv_usec / 1000); return msg; @@ -124,13 +125,13 @@ static void cmdu_ackq_ageout_entry(struct cmdu_ackq *st, struct hlist_head *head int action = CMDU_ACKQ_TMO_NONE; struct timeval new_next_tmo = { 0 }; - loud("%s(): check entry msg->ageout? (%lu.%lu), now = (%lu.%lu)\n", + dbg("%s(): check entry msg->ageout? (when = %lu.%lu), now = (%lu.%lu)\n", __func__, msg->ageing_tmo.tv_sec, msg->ageing_tmo.tv_usec, now.tv_sec, now.tv_usec); if (!timercmp(&msg->ageing_tmo, &now, >)) { - dbg("No response from " MACFMT " with CMDU 0x%x mid = %hu\n", - MAC2STR(msg->origin), msg->type, msg->mid); + dbg("%s(): No response from " MACFMT " with CMDU 0x%x mid = %hu\n", + __func__, MAC2STR(msg->origin), msg->type, msg->mid); if (st->timeout_cb) { action = st->timeout_cb(st, msg); @@ -149,6 +150,8 @@ static void cmdu_ackq_ageout_entry(struct cmdu_ackq *st, struct hlist_head *head case CMDU_ACKQ_TMO_DELETE: st->pending_cnt--; hlist_del(&msg->hlist, head); + dbg("DEQ: type = 0x%04x mid = %hu origin = " MACFMT " (reason: timeout)\n", + msg->type, msg->mid, MAC2STR(msg->origin)); cmdu_ackq_delete_msg(st, msg); break; case CMDU_ACKQ_TMO_REARM: @@ -188,18 +191,19 @@ static void cmdu_ackq_ageing_timer_run(atimer_t *t) } remain_cnt = st->pending_cnt; - st->next_tmo.tv_sec = min_next_tmo.tv_sec; - st->next_tmo.tv_usec = min_next_tmo.tv_usec; + timeradd(&nu, &min_next_tmo, &st->next_tmo); - loud("\n ----Next timer adjusted ---- next_tmo = %lu.%lu, msg-cnt = %d\n", - st->next_tmo.tv_sec, st->next_tmo.tv_usec, remain_cnt); + dbg("\n ----Next timer ---- when = %lu.%lu, after = %lu.%lu, msg-cnt = %d\n", + st->next_tmo.tv_sec, st->next_tmo.tv_usec, + min_next_tmo.tv_sec, min_next_tmo.tv_usec, + remain_cnt); if (remain_cnt) { uint32_t tmo_msecs = - st->next_tmo.tv_sec * 1000 + st->next_tmo.tv_usec / 1000; + min_next_tmo.tv_sec * 1000 + min_next_tmo.tv_usec / 1000; if (tmo_msecs > 0) { - loud("Set timer after %u ms, msg-cnt = %d\n", tmo_msecs, remain_cnt); + dbg(" ----Next timer set after %u ms, msg-cnt = %d\n", tmo_msecs, remain_cnt); timer_set(&st->ageing_timer, tmo_msecs); } } @@ -325,8 +329,8 @@ int cmdu_ackq_dequeue(void *cmdu_q, uint16_t type, uint16_t mid, uint8_t *src, v hlist_del(&msg->hlist, &q->table[idx]); q->pending_cnt--; - dbg("DEQ: type = 0x%04x mid = %hu origin = " MACFMT "\n", - type, mid, MAC2STR(src)); + dbg("DEQ: type = 0x%04x mid = %hu origin = " MACFMT " (reason: response)\n", + type, mid, MAC2STR(src)); /* After returning cookie back to user, we can safely delete the msg */