pespin submitted this change.
rlcmac: Implement UL TBF Countdown procedure
The Countdown procedure (decreasing CV field in UL RLCMAC data blocks)
is defined in TS 44.060 9.3.1.
It is implemented by means of counting/calculating the amount of RLC/MAC
blocks to be transmitted based on the LLC frames in the several LLC
queues, without actually generating the RLC/MAC blocks. The blocks
cannot be generated ahead of time because that wouldn't allow recreating
them in case Tx UL CS changes, or if a higher priority LLC frames
arrives.
The functions calculating the required amount of RLC/MAC blocks are
coded so that they early return to avoid spending more time than
necessary counting blocks (< BS_CV_MAX).
An extra heuristic optimization to be used when LLC queues are long is left
documented as a TODO, in order to test further the general non-optimized
path for now. Once the counting is proved to work reliably, that and
other heuristic optimizations ca be implemented, like keeping and
decreasing CV cached counter while no Tx CS change occurs or no new LLC
frames are enqueued.
Change-Id: If043c86a0c2b89d0ac0b8174de39fbcb22bed8cb
---
M include/osmocom/gprs/rlcmac/llc_queue.h
M include/osmocom/gprs/rlcmac/rlcmac_enc.h
M include/osmocom/gprs/rlcmac/tbf_ul.h
M src/rlcmac/llc_queue.c
M src/rlcmac/rlcmac_enc.c
M src/rlcmac/tbf_ul.c
M tests/rlcmac/rlcmac_prim_test.c
M tests/rlcmac/rlcmac_prim_test.err
M tests/rlcmac/rlcmac_prim_test.ok
9 files changed, 518 insertions(+), 66 deletions(-)
diff --git a/include/osmocom/gprs/rlcmac/llc_queue.h b/include/osmocom/gprs/rlcmac/llc_queue.h
index 80016e0..842969e 100644
--- a/include/osmocom/gprs/rlcmac/llc_queue.h
+++ b/include/osmocom/gprs/rlcmac/llc_queue.h
@@ -54,6 +54,8 @@
struct msgb *gprs_rlcmac_llc_queue_dequeue(struct gprs_rlcmac_llc_queue *q);
uint8_t gprs_rlcmac_llc_queue_highest_radio_prio_pending(struct gprs_rlcmac_llc_queue *q);
+void gprs_rlcmac_llc_queue_merge_prepend(struct gprs_rlcmac_llc_queue *q, struct gprs_rlcmac_llc_queue *old_q);
+
static inline size_t gprs_rlcmac_llc_queue_size(const struct gprs_rlcmac_llc_queue *q)
{
return q->queue_size;
diff --git a/include/osmocom/gprs/rlcmac/rlcmac_enc.h b/include/osmocom/gprs/rlcmac/rlcmac_enc.h
index 406109a..298d364 100644
--- a/include/osmocom/gprs/rlcmac/rlcmac_enc.h
+++ b/include/osmocom/gprs/rlcmac/rlcmac_enc.h
@@ -29,7 +29,7 @@
struct gprs_rlcmac_rlc_block_info *rdbi,
enum gprs_rlcmac_coding_scheme cs,
struct msgb *llc_msg, int *offset, int *num_chunks,
- uint8_t *data_block, bool is_final, int *count_payload);
+ uint8_t *data_block, int *count_payload);
void gprs_rlcmac_rlc_data_to_ul_append_egprs_li_padding(const struct gprs_rlcmac_rlc_block_info *rdbi,
int *offset, int *num_chunks, uint8_t *data_block);
diff --git a/include/osmocom/gprs/rlcmac/tbf_ul.h b/include/osmocom/gprs/rlcmac/tbf_ul.h
index e5cfa91..660cf5a 100644
--- a/include/osmocom/gprs/rlcmac/tbf_ul.h
+++ b/include/osmocom/gprs/rlcmac/tbf_ul.h
@@ -40,6 +40,13 @@
/* (M)CS used to transmit uplink blocks, assigned by PCU: */
enum gprs_rlcmac_coding_scheme tx_cs;
+
+ /* Whether the UL TBF entered the countdown procedure (TS 44.060 9.3.1)*/
+ struct {
+ bool active;
+ uint8_t cv;
+ struct gprs_rlcmac_llc_queue *llc_queue;
+ } countdown_proc;
};
struct gprs_rlcmac_ul_tbf *gprs_rlcmac_ul_tbf_alloc(struct gprs_rlcmac_entity *gre);
diff --git a/src/rlcmac/llc_queue.c b/src/rlcmac/llc_queue.c
index 47cb1e9..3ff80d9 100644
--- a/src/rlcmac/llc_queue.c
+++ b/src/rlcmac/llc_queue.c
@@ -227,3 +227,31 @@
OSMO_ASSERT(prioq);
return prioq->radio_prio;
}
+
+/* Merge old_q messages into q, prepending them. old_q must be freed by the caller. */
+void gprs_rlcmac_llc_queue_merge_prepend(struct gprs_rlcmac_llc_queue *q, struct gprs_rlcmac_llc_queue *old_q)
+{
+ unsigned int i, j;
+
+ /* Nothing to do: */
+ if (old_q->queue_size == 0)
+ return;
+
+ for (i = 0; i < ARRAY_SIZE(old_q->pq); i++) {
+ for (j = 0; j < ARRAY_SIZE(old_q->pq[i]); j++) {
+ struct llist_head *old_pq = &old_q->pq[i][j].queue;
+ struct llist_head *pq = &q->pq[i][j].queue;
+ struct llist_head *it;
+
+ /* Remove from old_pq and prepend to pq: */
+ while ((it = old_pq->next) != old_pq)
+ llist_move(it, pq);
+ }
+ }
+
+ q->queue_size += old_q->queue_size;
+ q->queue_octets += old_q->queue_octets;
+
+ old_q->queue_size = 0;
+ old_q->queue_octets = 0;
+}
diff --git a/src/rlcmac/rlcmac_enc.c b/src/rlcmac/rlcmac_enc.c
index 1c849a1..1e10d3a 100644
--- a/src/rlcmac/rlcmac_enc.c
+++ b/src/rlcmac/rlcmac_enc.c
@@ -67,12 +67,13 @@
struct gprs_rlcmac_rlc_block_info *rdbi,
enum gprs_rlcmac_coding_scheme cs,
struct msgb *llc_msg, int *offset, int *num_chunks,
- uint8_t *data_block, bool is_final, int *count_payload)
+ uint8_t *data_block, int *count_payload)
{
int chunk;
int space;
struct gprs_rlcmac_rlc_li_field *li;
uint8_t *delimiter, *data, *e_pointer;
+ const bool is_final = rdbi->cv == 0;
data = data_block + *offset;
delimiter = data_block + *num_chunks;
@@ -117,7 +118,6 @@
*count_payload = space;
*offset = rdbi->data_len;
(*num_chunks)++;
- rdbi->cv = 0;
return GPRS_RLCMAC_AR_COMPLETED_BLOCK_FILLED;
}
/* if chunk would fit exactly in space left */
@@ -191,7 +191,6 @@
/* if we don't have more LLC frames */
if (is_final) {
LOGRLCMAC(LOGL_DEBUG, "-- Final block, so we done.\n");
- rdbi->cv = 0;
return GPRS_RLCMAC_AR_COMPLETED_BLOCK_FILLED;
}
/* we have no space left */
diff --git a/src/rlcmac/tbf_ul.c b/src/rlcmac/tbf_ul.c
index b38c750..6bea79e 100644
--- a/src/rlcmac/tbf_ul.c
+++ b/src/rlcmac/tbf_ul.c
@@ -72,6 +72,13 @@
if (!ul_tbf)
return;
+ if (ul_tbf->countdown_proc.llc_queue) {
+ gprs_rlcmac_llc_queue_merge_prepend(ul_tbf->tbf.gre->llc_queue,
+ ul_tbf->countdown_proc.llc_queue);
+ gprs_rlcmac_llc_queue_free(ul_tbf->countdown_proc.llc_queue);
+ ul_tbf->countdown_proc.llc_queue = NULL;
+ }
+
if (ul_tbf->tbf.gre->ul_tbf == ul_tbf)
ul_tbf->tbf.gre->ul_tbf = NULL;
@@ -146,7 +153,7 @@
return false;
/* the mobile station has new data to transmit */
- if (!gprs_rlcmac_ul_tbf_have_data(ul_tbf))
+ if (!gprs_rlcmac_entity_have_tx_data_queued(ul_tbf->tbf.gre))
return false;
/* "the mobile station has no other ongoing downlink TBFs */
@@ -312,8 +319,12 @@
bool gprs_rlcmac_ul_tbf_have_data(const struct gprs_rlcmac_ul_tbf *ul_tbf)
{
- return (ul_tbf->llc_tx_msg && msgb_length(ul_tbf->llc_tx_msg) > 0) ||
- gprs_rlcmac_entity_have_tx_data_queued(ul_tbf->tbf.gre);
+ if (ul_tbf->llc_tx_msg && msgb_length(ul_tbf->llc_tx_msg) > 0)
+ return true;
+ if (ul_tbf->countdown_proc.active)
+ return gprs_rlcmac_llc_queue_size(ul_tbf->countdown_proc.llc_queue) > 0;
+ else
+ return gprs_rlcmac_entity_have_tx_data_queued(ul_tbf->tbf.gre);
}
bool gprs_rlcmac_ul_tbf_shall_keep_open(const struct gprs_rlcmac_ul_tbf *ul_tbf, const struct gprs_rlcmac_rts_block_ind *bi)
@@ -331,13 +342,20 @@
void gprs_rlcmac_ul_tbf_schedule_next_llc_frame(struct gprs_rlcmac_ul_tbf *ul_tbf)
{
struct osmo_gprs_rlcmac_prim *rlcmac_prim_tx;
+ struct gprs_rlcmac_llc_queue *llc_queue;
if (ul_tbf->llc_tx_msg && msgb_length(ul_tbf->llc_tx_msg))
return;
msgb_free(ul_tbf->llc_tx_msg);
+
+ if (ul_tbf->countdown_proc.active)
+ llc_queue = ul_tbf->countdown_proc.llc_queue;
+ else
+ llc_queue = ul_tbf->tbf.gre->llc_queue;
+
/* dequeue next LLC frame, if any */
- ul_tbf->llc_tx_msg = gprs_rlcmac_llc_queue_dequeue(ul_tbf->tbf.gre->llc_queue);
+ ul_tbf->llc_tx_msg = gprs_rlcmac_llc_queue_dequeue(llc_queue);
if (!ul_tbf->llc_tx_msg)
return;
@@ -354,9 +372,188 @@
gprs_rlcmac_prim_call_up_cb(rlcmac_prim_tx);
}
+/* TS 44.060 9.3.1.1 Countdown procedure */
+struct blk_count_state {
+ const struct gprs_rlcmac_ul_tbf *ul_tbf;
+ uint8_t blk_data_len; /* length of usable data block (single data unit w/o header) */
+ uint8_t bs_cv_max;
+ uint8_t nts;
+ uint8_t k;
+ uint8_t nts_x_k;
+ unsigned blk_count;
+ uint8_t offset; /* offset in bytes in the current blk */
+ bool extra_li0; /* if last appended chunk is an LI=0 case */
+};
+static void blk_count_state_init(struct blk_count_state *st, const struct gprs_rlcmac_ul_tbf *ul_tbf)
+{
+ OSMO_ASSERT(ul_tbf->cur_alloc.num_ts > 0);
+ memset(st, 0, sizeof(*st));
+ st->ul_tbf = ul_tbf;
+ st->blk_data_len = gprs_rlcmac_mcs_max_data_block_bytes(ul_tbf->tx_cs);
+ st->bs_cv_max = g_rlcmac_ctx->si13ro.u.PBCCH_Not_present.GPRS_Cell_Options.BS_CV_MAX;
+ st->nts = ul_tbf->cur_alloc.num_ts;
+ st->blk_count = 0;
+ st->offset = 0;
+
+ if (gprs_rlcmac_ul_tbf_in_contention_resolution(ul_tbf))
+ st->blk_data_len -= 4;
+
+ switch (ul_tbf->tx_cs) {
+ case GPRS_RLCMAC_MCS_7:
+ case GPRS_RLCMAC_MCS_8:
+ case GPRS_RLCMAC_MCS_9:
+ st->k = 2;
+ break;
+ default:
+ st->k = 1;
+ }
+ st->nts_x_k = st->nts * st->k;
+}
+
+static inline unsigned blk_count_to_x(const struct blk_count_state *st)
+{
+ if (st->blk_count == 0)
+ return 0;
+ return (st->blk_count + (st->nts_x_k - 1) - 1) / st->nts_x_k;
+}
+
+static void blk_count_append_llc(struct blk_count_state *st, unsigned int llc_payload_len)
+{
+ int chunk = llc_payload_len;
+ int space = st->blk_data_len - st->offset;
+ OSMO_ASSERT(st->offset < st->blk_data_len);
+
+ if (chunk == 0)
+ return; /* Should not happen in here? */
+
+ /* reset flag: */
+ st->extra_li0 = false;
+
+ /* if chunk will exceed block limit */
+ if (chunk > space) {
+ st->blk_count++;
+ st->offset = 0;
+ chunk -= space;
+ blk_count_append_llc(st, chunk);
+ return;
+ }
+ if (chunk == space) {
+ st->blk_count++;
+ st->offset = 0;
+ chunk -= space - 1; /* Extra LI=0 */
+ blk_count_append_llc(st, chunk);
+ /* case is_final==true (CV==0) has no extra LI=0. Store the
+ * context to subtract if this was the last step. */
+ st->extra_li0 = true;
+ return;
+ }
+ /* chunk < space */
+ /* Append a new LI byte */
+ st->offset++;
+ st->offset += chunk;
+ if (st->blk_data_len - st->offset == 0) {
+ st->blk_count++;
+ st->offset = 0;
+ }
+}
+
+/* Returned as early return from function when amount of RLC blocks goes clearly over BS_CV_MAX */
+#define BLK_COUNT_TOOMANY 0xff
+/* We cannot early-check if extra_li0=true, since there may temporarily have too many rlc blocks: */
+#define BLK_COUNT_EARLY_CHECK_TOOMANY(st) (!(st)->extra_li0) && blk_count_to_x(st) > (st)->bs_cv_max)
+static uint8_t blk_count_append_llc_prio_queue(struct blk_count_state *st, const struct gprs_llc_prio_queue *pq)
+{
+ struct msgb *msg;
+
+ llist_for_each_entry(msg, &pq->queue, list) {
+ blk_count_append_llc(st, msgb_l2len(msg));
+ /* We cannot early-check if extra_li0=true, since there may temporarily have too many rlc blocks. */
+ if (BLK_COUNT_EARLY_CHECK_TOOMANY(st)
+ return BLK_COUNT_TOOMANY; /* early return, not entering countdown procedure */
+ }
+ return 0;
+}
+
+/* return BLK_COUNT_TOOMANY: not entering countdown procedure, X > BS_CV_MAX.
+_* return 0: check blk_count_to_x(st) */
+static uint8_t gprs_rlcmac_ul_tbf_calculate_cv(const struct gprs_rlcmac_ul_tbf *ul_tbf)
+{
+ struct blk_count_state st;
+ const struct gprs_rlcmac_llc_queue *q = ul_tbf->tbf.gre->llc_queue;
+ unsigned int i, j;
+ unsigned x;
+
+ blk_count_state_init(&st, ul_tbf);
+
+ /* TODO: Here we could do an heuristic optimization by doing a rough calculation
+ * using gprs_rlcmac_llc_queue_size() and gprs_rlcmac_llc_queue_octets()
+ * for cases were we are clearly above BS_CV_MAX. This is specially useful
+ * when the LLC queue is long since we skip iterating counting lots of
+ * data.
+ * if (blk_count_herustic_toomany(&st))
+ * return 15;
+ */
+
+ /* First of all, the current LLC frame in progress: */
+ if (ul_tbf->llc_tx_msg) {
+ blk_count_append_llc(&st, msgb_length(ul_tbf->llc_tx_msg));
+ if (BLK_COUNT_EARLY_CHECK_TOOMANY(&st)
+ goto done; /* early return, not entering countdown procedure */
+ }
+
+ for (i = 0; i < ARRAY_SIZE(q->pq); i++) {
+ for (j = 0; j < ARRAY_SIZE(q->pq[i]); j++) {
+ int rc;
+ if (llist_empty(&q->pq[i][j].queue))
+ continue;
+ rc = blk_count_append_llc_prio_queue(&st, &q->pq[i][j]);
+ if (rc == BLK_COUNT_TOOMANY)
+ goto done; /* early return, not entering countdown procedure */
+ }
+ }
+
+done:
+ /* In final block (CV==0), a chunk filling exactly an RLC block doesn't
+ * have the LI=0 and 2 bytes (1 LI + 1 data) spanning next block. Fix calculation: */
+ if (st.extra_li0) {
+ OSMO_ASSERT(st.offset == 2);
+ st.offset -= 2;
+ }
+ /* Remaining one would already be a block. Include it before calculating "X": */
+ if (st.offset > 0) {
+ st.blk_count++;
+ st.offset = 0;
+ }
+ x = blk_count_to_x(&st);
+ return x <= st.bs_cv_max ? (uint8_t)x : 15;
+}
+
+static void gprs_rlcmac_ul_tbf_steal_llc_queue_from_gre(struct gprs_rlcmac_ul_tbf *ul_tbf)
+{
+ ul_tbf->countdown_proc.llc_queue = ul_tbf->tbf.gre->llc_queue;
+ ul_tbf->tbf.gre->llc_queue = gprs_rlcmac_llc_queue_alloc(ul_tbf->tbf.gre);
+}
+
+static void gprs_rlcmac_ul_tbf_check_countdown_proc(struct gprs_rlcmac_ul_tbf *ul_tbf, const struct gprs_rlcmac_rts_block_ind *bi)
+{
+
+ if (ul_tbf->countdown_proc.active)
+ return;
+ ul_tbf->countdown_proc.cv = gprs_rlcmac_ul_tbf_calculate_cv(ul_tbf);
+ if (ul_tbf->countdown_proc.cv < 15) {
+ if (gprs_rlcmac_ul_tbf_shall_keep_open(ul_tbf, bi)) {
+ LOGPTBFUL(ul_tbf, LOGL_INFO, "Delaying start Countdown procedure CV=%u\n", ul_tbf->countdown_proc.cv);
+ ul_tbf->countdown_proc.cv = 15;
+ return;
+ }
+ LOGPTBFUL(ul_tbf, LOGL_DEBUG, "Entering Countdown procedure CV=%u\n", ul_tbf->countdown_proc.cv);
+ ul_tbf->countdown_proc.active = true;
+ gprs_rlcmac_ul_tbf_steal_llc_queue_from_gre(ul_tbf);
+ }
+}
+
static int create_new_bsn(struct gprs_rlcmac_ul_tbf *ul_tbf, const struct gprs_rlcmac_rts_block_ind *bi, enum gprs_rlcmac_coding_scheme cs)
{
- struct gprs_rlcmac_llc_queue *llc_queue = ul_tbf->tbf.gre->llc_queue;
const uint16_t bsn = gprs_rlcmac_rlc_ul_window_v_s(ul_tbf->ulw);
struct gprs_rlcmac_rlc_block *blk;
struct gprs_rlcmac_rlc_block_info *rdbi;
@@ -365,6 +562,8 @@
int write_offset = 0;
enum gpr_rlcmac_append_result ar;
+ gprs_rlcmac_ul_tbf_check_countdown_proc(ul_tbf, bi);
+
if (!ul_tbf->llc_tx_msg || msgb_length(ul_tbf->llc_tx_msg) == 0)
gprs_rlcmac_ul_tbf_schedule_next_llc_frame(ul_tbf);
OSMO_ASSERT(ul_tbf->llc_tx_msg);
@@ -391,7 +590,7 @@
rdbi->data_len = block_data_len;
rdbi->ti = gprs_rlcmac_ul_tbf_in_contention_resolution(ul_tbf);
- rdbi->cv = 15; /* Final Block Indicator, set late, if true */
+ rdbi->cv = ul_tbf->countdown_proc.cv--;
rdbi->bsn = bsn; /* Block Sequence Number */
rdbi->e = 1; /* Extension bit, maybe set later (1: no extension) */
@@ -407,7 +606,6 @@
}
do {
- bool is_final;
int payload_written = 0;
if (msgb_length(ul_tbf->llc_tx_msg) == 0) {
@@ -424,14 +622,6 @@
"LLC queue completely drained and there's "
"still %d free bytes in rlcmac data block\n", space);
- /* We may need to update fbi in header here
- * since ul_tbf->last_ul_drained_fn was updated above
- * Specially important when X2031 is 0. */
- is_final = gprs_rlcmac_llc_queue_size(llc_queue) == 0 &&
- !gprs_rlcmac_ul_tbf_shall_keep_open(ul_tbf, bi);
- if (is_final)
- rdbi->cv = 0;
-
if (gprs_rlcmac_mcs_is_edge(cs)) {
/* in EGPRS there's no M bit, so we need
* to flag padding with LI=127 */
@@ -442,12 +632,8 @@
}
}
- is_final = gprs_rlcmac_llc_queue_size(llc_queue) == 0 &&
- !gprs_rlcmac_ul_tbf_shall_keep_open(ul_tbf, bi);
-
- ar = gprs_rlcmac_enc_append_ul_data(rdbi, cs, ul_tbf->llc_tx_msg,
- &write_offset, &num_chunks, data,
- is_final, &payload_written);
+ ar = gprs_rlcmac_enc_append_ul_data(rdbi, cs, ul_tbf->llc_tx_msg, &write_offset,
+ &num_chunks, data, &payload_written);
if (ar == GPRS_RLCMAC_AR_NEED_MORE_BLOCKS)
break;
@@ -460,8 +646,8 @@
gprs_rlcmac_ul_tbf_schedule_next_llc_frame(ul_tbf);
} while (ar == GPRS_RLCMAC_AR_COMPLETED_SPACE_LEFT);
- LOGPTBFUL(ul_tbf, LOGL_DEBUG, "data block (BSN %d, %s): %s\n",
- bsn, gprs_rlcmac_mcs_name(blk->cs_last),
+ LOGPTBFUL(ul_tbf, LOGL_DEBUG, "data block (BSN=%d, %s, CV=%u): %s\n",
+ bsn, gprs_rlcmac_mcs_name(blk->cs_last), rdbi->cv,
osmo_hexdump(blk->buf, block_data_len));
/* raise send state and set ack state array */
gprs_rlcmac_rlc_v_b_mark_unacked(&ul_tbf->ulw->v_b, bsn);
@@ -850,8 +1036,8 @@
rdbi->bsn = bsn;
is_final = is_final || rdbi->cv == 0;
- LOGPTBFUL(ul_tbf, LOGL_DEBUG, "Copying data unit %d (BSN %d)\n",
- data_block_idx, bsn);
+ LOGPTBFUL(ul_tbf, LOGL_DEBUG, "Copying data unit %d (BSN=%d CV=%d)\n",
+ data_block_idx, bsn, rdbi->cv);
gprs_rlcmac_rlc_copy_from_aligned_buffer(&rlc, data_block_idx, msg_data, block_data);
}
diff --git a/tests/rlcmac/rlcmac_prim_test.c b/tests/rlcmac/rlcmac_prim_test.c
index c8d1616..ba06fab 100644
--- a/tests/rlcmac/rlcmac_prim_test.c
+++ b/tests/rlcmac/rlcmac_prim_test.c
@@ -934,6 +934,71 @@
cleanup_test();
}
+/* 9.3.1 Countdown procedure */
+static void test_ul_tbf_countdown_procedure(void)
+{
+ struct osmo_gprs_rlcmac_prim *rlcmac_prim;
+ int rc;
+
+ printf("=== %s start ===\n", __func__);
+ prepare_test();
+ uint32_t tlli = 0x2342;
+ uint8_t ul_tfi = 0;
+ uint8_t ts_nr = 7;
+ uint8_t usf = 0;
+ uint32_t rts_fn = 4;
+ uint8_t bs_cv_max = 4;
+ unsigned int i;
+ RlcMacDownlink_t dl_block;
+ struct msgb *llc_msg = msgb_alloc(200, "llc_msg");
+ Ack_Nack_Description_t *ack_desc = &dl_block.u.Packet_Uplink_Ack_Nack.u.PU_AckNack_GPRS_Struct.Ack_Nack_Description;
+
+ /* Submit an SI13 with bs_cv_max: */
+ rlcmac_prim = osmo_gprs_rlcmac_prim_alloc_l1ctl_ccch_data_ind(0, create_si13(bs_cv_max));
+ rc = osmo_gprs_rlcmac_prim_lower_up(rlcmac_prim);
+ OSMO_ASSERT(rc == 0);
+
+
+ /* Submit LLC bytes */
+ msgb_put(llc_msg, msgb_tailroom(llc_msg));
+ memset(msgb_data(llc_msg), 0xab, msgb_length(llc_msg));
+ rlcmac_prim = osmo_gprs_rlcmac_prim_alloc_grr_unitdata_req(tlli, msgb_data(llc_msg), msgb_length(llc_msg));
+ rlcmac_prim->grr.unitdata_req.sapi = OSMO_GPRS_RLCMAC_LLC_SAPI_SNDCP3;
+ rc = osmo_gprs_rlcmac_prim_upper_down(rlcmac_prim);
+
+ ccch_imm_ass_pkt_ul_tbf_normal[7] = last_rach_req_ra; /* Update RA to match */
+ rlcmac_prim = osmo_gprs_rlcmac_prim_alloc_l1ctl_ccch_data_ind(0, ccch_imm_ass_pkt_ul_tbf_normal);
+ rc = osmo_gprs_rlcmac_prim_lower_up(rlcmac_prim);
+ OSMO_ASSERT(rc == 0);
+
+ /* Trigger transmission of LLC data (first part) */
+ rlcmac_prim = osmo_gprs_rlcmac_prim_alloc_l1ctl_pdch_rts_ind(ts_nr, rts_fn, usf);
+ rc = osmo_gprs_rlcmac_prim_lower_up(rlcmac_prim);
+ OSMO_ASSERT(rc == 0);
+
+ /* PCU acks it: */
+ ul_ack_nack_init(&dl_block, ul_tfi, GPRS_RLCMAC_CS_2);
+ ack_desc->STARTING_SEQUENCE_NUMBER = 1;
+ ack_desc->FINAL_ACK_INDICATION = 0;
+ ul_ack_nack_mark(ack_desc, 0, true);
+ rlcmac_prim = create_dl_ctrl_block(&dl_block, ts_nr, rts_fn);
+ rc = osmo_gprs_rlcmac_prim_lower_up(rlcmac_prim);
+ OSMO_ASSERT(rc == 0);
+
+ for (i = 0; i < 6; i++) {
+ rts_fn = fn_next_block(rts_fn);
+ printf("RTS %u: FN=%u\n", i, rts_fn);
+ /* Trigger transmission of LLC data (GMM Attach) (second part) */
+ rlcmac_prim = osmo_gprs_rlcmac_prim_alloc_l1ctl_pdch_rts_ind(ts_nr, rts_fn, usf);
+ rc = osmo_gprs_rlcmac_prim_lower_up(rlcmac_prim);
+ OSMO_ASSERT(rc == 0);
+ }
+
+ printf("=== %s end ===\n", __func__);
+ msgb_free(llc_msg);
+ cleanup_test();
+}
+
/* PCU allocates a DL TBF through PCH ImmAss for MS (when in packet-idle) */
static void test_dl_tbf_ccch_assign(void)
{
@@ -1128,6 +1193,7 @@
test_ul_tbf_n3104_timeout();
test_ul_tbf_t3182_timeout();
test_ul_tbf_last_data_cv0_retrans_max();
+ test_ul_tbf_countdown_procedure();
test_ul_tbf_request_another_ul_tbf();
test_dl_tbf_ccch_assign();
test_dl_tbf_ccch_assign_requests_ul_tbf_pacch();
diff --git a/tests/rlcmac/rlcmac_prim_test.err b/tests/rlcmac/rlcmac_prim_test.err
index a02739a..120458a 100644
--- a/tests/rlcmac/rlcmac_prim_test.err
+++ b/tests/rlcmac/rlcmac_prim_test.err
@@ -23,10 +23,10 @@
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Sending new block at BSN 0, CS=CS-2
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Dequeue next LLC (len=33)
DLGLOBAL DEBUG -- Chunk with length 33 larger than space (26) left in block: copy only remaining space, and we are done
-DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) data block (BSN 0, CS-2): 00 00 23 42 01 c0 00 08 01 01 d5 71 00 00 08 29 26 24 00 00 00 00 71 62 f2 24 6c 84 44 04
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) data block (BSN=0, CS-2, CV=15): 00 00 23 42 01 c0 00 08 01 01 d5 71 00 00 08 29 26 24 00 00 00 00 71 62 f2 24 6c 84 44 04
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) need_padding 0 spb_status 0 spb 0 (BSN1 0 BSN2 -1)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying 1 RLC blocks, 1 BSNs
-DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN 0)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN=0 CV=15)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 0, CS-2): 3c 01 01 00 00 23 42 01 c0 00 08 01 01 d5 71 00 00 08 29 26 24 00 00 00 00 71 62 f2 24 6c 84 44 04 00
DLGLOBAL INFO UL_TBF{FLOW}: Received Event FIRST_UL_DATA_SENT
DLGLOBAL INFO UL_TBF{FLOW}: First UL block sent, stop T3164
@@ -35,13 +35,14 @@
DLGLOBAL DEBUG Tx to lower layers: L1CTL-PDCH_DATA.request
DLGLOBAL DEBUG Rx from lower layers: L1CTL-PDCH_RTS.indication
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Sending new block at BSN 1, CS=CS-2
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Entering Countdown procedure CV=0
DLGLOBAL DEBUG -- Chunk with length 7 is less than remaining space (26): add length header to delimit LLC frame
DLGLOBAL DEBUG -- Final block, so we done.
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Complete UL frame, len=0
-DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) data block (BSN 1, CS-2): 1d 00 00 23 42 11 e5 10 00 e2 18 f2 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) data block (BSN=1, CS-2, CV=0): 1d 00 00 23 42 11 e5 10 00 e2 18 f2 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) need_padding 0 spb_status 0 spb 0 (BSN1 1 BSN2 -1)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying 1 RLC blocks, 1 BSNs
-DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN 1)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN=1 CV=0)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 1, CS-2): 00 01 02 1d 00 00 23 42 11 e5 10 00 e2 18 f2 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 00
DLGLOBAL INFO UL_TBF{FLOW}: Received Event LAST_UL_DATA_SENT
DLGLOBAL INFO UL_TBF{FLOW}: state_chg to FINISHED
@@ -185,10 +186,10 @@
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Sending new block at BSN 0, CS=CS-2
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Dequeue next LLC (len=33)
DLGLOBAL DEBUG -- Chunk with length 33 larger than space (26) left in block: copy only remaining space, and we are done
-DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) data block (BSN 0, CS-2): 00 00 23 42 01 c0 00 08 01 01 d5 71 00 00 08 29 26 24 00 00 00 00 71 62 f2 24 6c 84 44 04
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) data block (BSN=0, CS-2, CV=15): 00 00 23 42 01 c0 00 08 01 01 d5 71 00 00 08 29 26 24 00 00 00 00 71 62 f2 24 6c 84 44 04
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) need_padding 0 spb_status 0 spb 0 (BSN1 0 BSN2 -1)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying 1 RLC blocks, 1 BSNs
-DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN 0)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN=0 CV=15)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 0, CS-2): 3c 01 01 00 00 23 42 01 c0 00 08 01 01 d5 71 00 00 08 29 26 24 00 00 00 00 71 62 f2 24 6c 84 44 04 00
DLGLOBAL INFO UL_TBF{FLOW}: Received Event FIRST_UL_DATA_SENT
DLGLOBAL INFO UL_TBF{FLOW}: First UL block sent, stop T3164
@@ -220,7 +221,7 @@
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Resending BSN 0
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) need_padding 0 spb_status 0 spb 0 (BSN1 0 BSN2 -1)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying 1 RLC blocks, 1 BSNs
-DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN 0)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN=0 CV=15)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 0, CS-2): 3c 01 01 00 00 23 42 01 c0 00 08 01 01 d5 71 00 00 08 29 26 24 00 00 00 00 71 62 f2 24 6c 84 44 04 00
DLGLOBAL INFO UL_TBF{FLOW}: Received Event FIRST_UL_DATA_SENT
DLGLOBAL INFO UL_TBF{FLOW}: First UL block sent, stop T3164
@@ -252,7 +253,7 @@
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Resending BSN 0
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) need_padding 0 spb_status 0 spb 0 (BSN1 0 BSN2 -1)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying 1 RLC blocks, 1 BSNs
-DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN 0)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN=0 CV=15)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 0, CS-2): 3c 01 01 00 00 23 42 01 c0 00 08 01 01 d5 71 00 00 08 29 26 24 00 00 00 00 71 62 f2 24 6c 84 44 04 00
DLGLOBAL INFO UL_TBF{FLOW}: Received Event FIRST_UL_DATA_SENT
DLGLOBAL INFO UL_TBF{FLOW}: First UL block sent, stop T3164
@@ -284,7 +285,7 @@
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Resending BSN 0
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) need_padding 0 spb_status 0 spb 0 (BSN1 0 BSN2 -1)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying 1 RLC blocks, 1 BSNs
-DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN 0)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN=0 CV=15)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 0, CS-2): 3c 01 01 00 00 23 42 01 c0 00 08 01 01 d5 71 00 00 08 29 26 24 00 00 00 00 71 62 f2 24 6c 84 44 04 00
DLGLOBAL INFO UL_TBF{FLOW}: Received Event FIRST_UL_DATA_SENT
DLGLOBAL INFO UL_TBF{FLOW}: First UL block sent, stop T3164
@@ -326,10 +327,10 @@
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Sending new block at BSN 0, CS=CS-2
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Dequeue next LLC (len=33)
DLGLOBAL DEBUG -- Chunk with length 33 larger than space (26) left in block: copy only remaining space, and we are done
-DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) data block (BSN 0, CS-2): 00 00 23 42 01 c0 00 08 01 01 d5 71 00 00 08 29 26 24 00 00 00 00 71 62 f2 24 6c 84 44 04
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) data block (BSN=0, CS-2, CV=15): 00 00 23 42 01 c0 00 08 01 01 d5 71 00 00 08 29 26 24 00 00 00 00 71 62 f2 24 6c 84 44 04
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) need_padding 0 spb_status 0 spb 0 (BSN1 0 BSN2 -1)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying 1 RLC blocks, 1 BSNs
-DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN 0)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN=0 CV=15)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 0, CS-2): 3c 01 01 00 00 23 42 01 c0 00 08 01 01 d5 71 00 00 08 29 26 24 00 00 00 00 71 62 f2 24 6c 84 44 04 00
DLGLOBAL INFO UL_TBF{FLOW}: Received Event FIRST_UL_DATA_SENT
DLGLOBAL INFO UL_TBF{FLOW}: First UL block sent, stop T3164
@@ -338,13 +339,14 @@
DLGLOBAL DEBUG Tx to lower layers: L1CTL-PDCH_DATA.request
DLGLOBAL DEBUG Rx from lower layers: L1CTL-PDCH_RTS.indication
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Sending new block at BSN 1, CS=CS-2
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Entering Countdown procedure CV=0
DLGLOBAL DEBUG -- Chunk with length 7 is less than remaining space (26): add length header to delimit LLC frame
DLGLOBAL DEBUG -- Final block, so we done.
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Complete UL frame, len=0
-DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) data block (BSN 1, CS-2): 1d 00 00 23 42 11 e5 10 00 e2 18 f2 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) data block (BSN=1, CS-2, CV=0): 1d 00 00 23 42 11 e5 10 00 e2 18 f2 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) need_padding 0 spb_status 0 spb 0 (BSN1 1 BSN2 -1)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying 1 RLC blocks, 1 BSNs
-DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN 1)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN=1 CV=0)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 1, CS-2): 00 01 02 1d 00 00 23 42 11 e5 10 00 e2 18 f2 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 00
DLGLOBAL INFO UL_TBF{FLOW}: Received Event LAST_UL_DATA_SENT
DLGLOBAL INFO UL_TBF{FLOW}: state_chg to FINISHED
@@ -355,7 +357,7 @@
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Resending BSN 0
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) need_padding 0 spb_status 0 spb 0 (BSN1 0 BSN2 -1)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying 1 RLC blocks, 1 BSNs
-DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN 0)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN=0 CV=15)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 0, CS-2): 3c 01 01 00 00 23 42 01 c0 00 08 01 01 d5 71 00 00 08 29 26 24 00 00 00 00 71 62 f2 24 6c 84 44 04 00
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) N3104 inc (3)
DLGLOBAL DEBUG Tx to lower layers: L1CTL-PDCH_DATA.request
@@ -363,7 +365,7 @@
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Resending BSN 1
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) need_padding 0 spb_status 0 spb 0 (BSN1 1 BSN2 -1)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying 1 RLC blocks, 1 BSNs
-DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN 1)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN=1 CV=0)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 1, CS-2): 00 01 02 1d 00 00 23 42 11 e5 10 00 e2 18 f2 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 00
DLGLOBAL INFO UL_TBF{FINISHED}: Received Event LAST_UL_DATA_SENT
DLGLOBAL INFO UL_TBF{FINISHED}: Data block with CV=0 retransmit attempts=1
@@ -374,7 +376,7 @@
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Resending BSN 0
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) need_padding 0 spb_status 0 spb 0 (BSN1 0 BSN2 -1)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying 1 RLC blocks, 1 BSNs
-DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN 0)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN=0 CV=15)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 0, CS-2): 3c 01 01 00 00 23 42 01 c0 00 08 01 01 d5 71 00 00 08 29 26 24 00 00 00 00 71 62 f2 24 6c 84 44 04 00
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) N3104 inc (5)
DLGLOBAL DEBUG Tx to lower layers: L1CTL-PDCH_DATA.request
@@ -382,7 +384,7 @@
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Resending BSN 1
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) need_padding 0 spb_status 0 spb 0 (BSN1 1 BSN2 -1)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying 1 RLC blocks, 1 BSNs
-DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN 1)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN=1 CV=0)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 1, CS-2): 00 01 02 1d 00 00 23 42 11 e5 10 00 e2 18 f2 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 00
DLGLOBAL INFO UL_TBF{FINISHED}: Received Event LAST_UL_DATA_SENT
DLGLOBAL INFO UL_TBF{FINISHED}: Data block with CV=0 retransmit attempts=2
@@ -393,7 +395,7 @@
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Resending BSN 0
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) need_padding 0 spb_status 0 spb 0 (BSN1 0 BSN2 -1)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying 1 RLC blocks, 1 BSNs
-DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN 0)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN=0 CV=15)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 0, CS-2): 3c 01 01 00 00 23 42 01 c0 00 08 01 01 d5 71 00 00 08 29 26 24 00 00 00 00 71 62 f2 24 6c 84 44 04 00
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) N3104 inc (7)
DLGLOBAL DEBUG Tx to lower layers: L1CTL-PDCH_DATA.request
@@ -401,7 +403,7 @@
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Resending BSN 1
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) need_padding 0 spb_status 0 spb 0 (BSN1 1 BSN2 -1)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying 1 RLC blocks, 1 BSNs
-DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN 1)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN=1 CV=0)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 1, CS-2): 00 01 02 1d 00 00 23 42 11 e5 10 00 e2 18 f2 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 00
DLGLOBAL INFO UL_TBF{FINISHED}: Received Event LAST_UL_DATA_SENT
DLGLOBAL INFO UL_TBF{FINISHED}: Data block with CV=0 retransmit attempts=3
@@ -412,7 +414,7 @@
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Resending BSN 0
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) need_padding 0 spb_status 0 spb 0 (BSN1 0 BSN2 -1)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying 1 RLC blocks, 1 BSNs
-DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN 0)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN=0 CV=15)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 0, CS-2): 3c 01 01 00 00 23 42 01 c0 00 08 01 01 d5 71 00 00 08 29 26 24 00 00 00 00 71 62 f2 24 6c 84 44 04 00
DLGLOBAL NOTICE TBF(UL:NR-0:TLLI-00002342) N3104_MAX (9) reached
DLGLOBAL INFO UL_TBF{FINISHED}: Received Event N3104_MAX
@@ -466,10 +468,10 @@
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Sending new block at BSN 0, CS=CS-2
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Dequeue next LLC (len=33)
DLGLOBAL DEBUG -- Chunk with length 33 larger than space (26) left in block: copy only remaining space, and we are done
-DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) data block (BSN 0, CS-2): 00 00 23 42 01 c0 00 08 01 01 d5 71 00 00 08 29 26 24 00 00 00 00 71 62 f2 24 6c 84 44 04
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) data block (BSN=0, CS-2, CV=15): 00 00 23 42 01 c0 00 08 01 01 d5 71 00 00 08 29 26 24 00 00 00 00 71 62 f2 24 6c 84 44 04
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) need_padding 0 spb_status 0 spb 0 (BSN1 0 BSN2 -1)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying 1 RLC blocks, 1 BSNs
-DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN 0)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN=0 CV=15)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 0, CS-2): 3c 01 01 00 00 23 42 01 c0 00 08 01 01 d5 71 00 00 08 29 26 24 00 00 00 00 71 62 f2 24 6c 84 44 04 00
DLGLOBAL INFO UL_TBF{FLOW}: Received Event FIRST_UL_DATA_SENT
DLGLOBAL INFO UL_TBF{FLOW}: First UL block sent, stop T3164
@@ -486,13 +488,14 @@
DLGLOBAL INFO UL_TBF{FLOW}: Contention resolution succeeded, stop T3166
DLGLOBAL DEBUG Rx from lower layers: L1CTL-PDCH_RTS.indication
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Sending new block at BSN 1, CS=CS-2
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Entering Countdown procedure CV=0
DLGLOBAL DEBUG -- Chunk with length 7 is less than remaining space (30): add length header to delimit LLC frame
DLGLOBAL DEBUG -- Final block, so we done.
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Complete UL frame, len=0
-DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) data block (BSN 1, CS-2): 1d 11 e5 10 00 e2 18 f2 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) data block (BSN=1, CS-2, CV=0): 1d 11 e5 10 00 e2 18 f2 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) need_padding 0 spb_status 0 spb 0 (BSN1 1 BSN2 -1)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying 1 RLC blocks, 1 BSNs
-DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN 1)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN=1 CV=0)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 1, CS-2): 00 00 02 1d 11 e5 10 00 e2 18 f2 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 00
DLGLOBAL INFO UL_TBF{FLOW}: Received Event LAST_UL_DATA_SENT
DLGLOBAL INFO UL_TBF{FLOW}: Last UL block sent (CV=0), start T3182
@@ -529,10 +532,10 @@
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Sending new block at BSN 0, CS=CS-2
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Dequeue next LLC (len=33)
DLGLOBAL DEBUG -- Chunk with length 33 larger than space (26) left in block: copy only remaining space, and we are done
-DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) data block (BSN 0, CS-2): 00 00 23 42 01 c0 00 08 01 01 d5 71 00 00 08 29 26 24 00 00 00 00 71 62 f2 24 6c 84 44 04
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) data block (BSN=0, CS-2, CV=15): 00 00 23 42 01 c0 00 08 01 01 d5 71 00 00 08 29 26 24 00 00 00 00 71 62 f2 24 6c 84 44 04
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) need_padding 0 spb_status 0 spb 0 (BSN1 0 BSN2 -1)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying 1 RLC blocks, 1 BSNs
-DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN 0)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN=0 CV=15)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 0, CS-2): 3c 01 01 00 00 23 42 01 c0 00 08 01 01 d5 71 00 00 08 29 26 24 00 00 00 00 71 62 f2 24 6c 84 44 04 00
DLGLOBAL INFO UL_TBF{FLOW}: Received Event FIRST_UL_DATA_SENT
DLGLOBAL INFO UL_TBF{FLOW}: First UL block sent, stop T3164
@@ -549,13 +552,14 @@
DLGLOBAL INFO UL_TBF{FLOW}: Contention resolution succeeded, stop T3166
DLGLOBAL DEBUG Rx from lower layers: L1CTL-PDCH_RTS.indication
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Sending new block at BSN 1, CS=CS-2
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Entering Countdown procedure CV=0
DLGLOBAL DEBUG -- Chunk with length 7 is less than remaining space (30): add length header to delimit LLC frame
DLGLOBAL DEBUG -- Final block, so we done.
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Complete UL frame, len=0
-DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) data block (BSN 1, CS-2): 1d 11 e5 10 00 e2 18 f2 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) data block (BSN=1, CS-2, CV=0): 1d 11 e5 10 00 e2 18 f2 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) need_padding 0 spb_status 0 spb 0 (BSN1 1 BSN2 -1)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying 1 RLC blocks, 1 BSNs
-DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN 1)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN=1 CV=0)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 1, CS-2): 00 00 02 1d 11 e5 10 00 e2 18 f2 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 00
DLGLOBAL INFO UL_TBF{FLOW}: Received Event LAST_UL_DATA_SENT
DLGLOBAL INFO UL_TBF{FLOW}: Last UL block sent (CV=0), start T3182
@@ -566,7 +570,7 @@
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Resending BSN 1
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) need_padding 0 spb_status 0 spb 0 (BSN1 1 BSN2 -1)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying 1 RLC blocks, 1 BSNs
-DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN 1)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN=1 CV=0)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 1, CS-2): 00 00 02 1d 11 e5 10 00 e2 18 f2 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 00
DLGLOBAL INFO UL_TBF{FINISHED}: Received Event LAST_UL_DATA_SENT
DLGLOBAL INFO UL_TBF{FINISHED}: Data block with CV=0 retransmit attempts=1
@@ -577,7 +581,7 @@
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Resending BSN 1
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) need_padding 0 spb_status 0 spb 0 (BSN1 1 BSN2 -1)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying 1 RLC blocks, 1 BSNs
-DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN 1)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN=1 CV=0)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 1, CS-2): 00 00 02 1d 11 e5 10 00 e2 18 f2 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 00
DLGLOBAL INFO UL_TBF{FINISHED}: Received Event LAST_UL_DATA_SENT
DLGLOBAL INFO UL_TBF{FINISHED}: Data block with CV=0 retransmit attempts=2
@@ -588,7 +592,7 @@
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Resending BSN 1
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) need_padding 0 spb_status 0 spb 0 (BSN1 1 BSN2 -1)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying 1 RLC blocks, 1 BSNs
-DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN 1)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN=1 CV=0)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 1, CS-2): 00 00 02 1d 11 e5 10 00 e2 18 f2 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 00
DLGLOBAL INFO UL_TBF{FINISHED}: Received Event LAST_UL_DATA_SENT
DLGLOBAL INFO UL_TBF{FINISHED}: Data block with CV=0 retransmit attempts=3
@@ -599,7 +603,7 @@
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Resending BSN 1
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) need_padding 0 spb_status 0 spb 0 (BSN1 1 BSN2 -1)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying 1 RLC blocks, 1 BSNs
-DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN 1)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN=1 CV=0)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 1, CS-2): 00 00 02 1d 11 e5 10 00 e2 18 f2 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 00
DLGLOBAL INFO UL_TBF{FINISHED}: Received Event LAST_UL_DATA_SENT
DLGLOBAL INFO UL_TBF{FINISHED}: Data block with CV=0 retransmit attempts=4
@@ -611,6 +615,8 @@
DLGLOBAL INFO UL_TBF{FINISHED}: Deallocated
DLGLOBAL DEBUG Tx to lower layers: L1CTL-PDCH_DATA.request
DLGLOBAL INFO DL_TBF_ASS{IDLE}: Deallocated
+DLGLOBAL DEBUG Rx from lower layers: L1CTL-CCCH_DATA.indication
+DLGLOBAL DEBUG Rx SI13 from lower layers
DLGLOBAL INFO Rx from upper layers: GRR-UNITDATA.request
DLGLOBAL INFO TLLI=0x00002342 not found, creating entity on the fly
DLGLOBAL INFO DL_TBF_ASS{IDLE}: Allocated
@@ -634,14 +640,123 @@
DLGLOBAL INFO UL_TBF_ASS{COMPLETED}: state_chg to IDLE
DLGLOBAL DEBUG Rx from lower layers: L1CTL-PDCH_RTS.indication
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Sending new block at BSN 0, CS=CS-2
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Dequeue next LLC (len=200)
+DLGLOBAL DEBUG -- Chunk with length 200 larger than space (26) left in block: copy only remaining space, and we are done
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) data block (BSN=0, CS-2, CV=15): 00 00 23 42 ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) need_padding 0 spb_status 0 spb 0 (BSN1 0 BSN2 -1)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying 1 RLC blocks, 1 BSNs
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN=0 CV=15)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 0, CS-2): 3c 01 01 00 00 23 42 ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab 00
+DLGLOBAL INFO UL_TBF{FLOW}: Received Event FIRST_UL_DATA_SENT
+DLGLOBAL INFO UL_TBF{FLOW}: First UL block sent, stop T3164
+DLGLOBAL INFO UL_TBF{FLOW}: First UL block sent (1 phase access), start T3166
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) N3104 inc (1)
+DLGLOBAL DEBUG Tx to lower layers: L1CTL-PDCH_DATA.request
+DLGLOBAL DEBUG Rx from lower layers: L1CTL-PDCH_DATA.indication
+DLGLOBAL INFO TS=7 FN=4 Rx Pkt UL ACK/NACK
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Got GPRS UL ACK bitmap: SSN: 1, BSN 0 to 1 - 1 (1 blocks), "R"
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) ack: (BSN=0)"R"(BSN=0) R=ACK I=NACK
+DLGLOBAL DEBUG - got ack for BSN=0
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) V(B): (V(A)=1)""(V(S)-1=0) A=Acked N=Nacked U=Unacked X=Resend-Unacked I=Invalid
+DLGLOBAL INFO UL_TBF{FLOW}: Received Event RX_UL_ACK_NACK
+DLGLOBAL INFO UL_TBF{FLOW}: Contention resolution succeeded, stop T3166
+DLGLOBAL DEBUG Rx from lower layers: L1CTL-PDCH_RTS.indication
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Sending new block at BSN 1, CS=CS-2
+DLGLOBAL DEBUG -- Chunk with length 174 larger than space (30) left in block: copy only remaining space, and we are done
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) data block (BSN=1, CS-2, CV=15): ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) need_padding 0 spb_status 0 spb 0 (BSN1 1 BSN2 -1)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying 1 RLC blocks, 1 BSNs
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN=1 CV=15)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 1, CS-2): 3c 00 03 ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab 00
+DLGLOBAL DEBUG Tx to lower layers: L1CTL-PDCH_DATA.request
+DLGLOBAL DEBUG Rx from lower layers: L1CTL-PDCH_RTS.indication
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Sending new block at BSN 2, CS=CS-2
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Entering Countdown procedure CV=4
+DLGLOBAL DEBUG -- Chunk with length 144 larger than space (30) left in block: copy only remaining space, and we are done
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) data block (BSN=2, CS-2, CV=4): ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) need_padding 0 spb_status 0 spb 0 (BSN1 2 BSN2 -1)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying 1 RLC blocks, 1 BSNs
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN=2 CV=4)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 2, CS-2): 10 00 05 ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab 00
+DLGLOBAL DEBUG Tx to lower layers: L1CTL-PDCH_DATA.request
+DLGLOBAL DEBUG Rx from lower layers: L1CTL-PDCH_RTS.indication
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Sending new block at BSN 3, CS=CS-2
+DLGLOBAL DEBUG -- Chunk with length 114 larger than space (30) left in block: copy only remaining space, and we are done
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) data block (BSN=3, CS-2, CV=3): ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) need_padding 0 spb_status 0 spb 0 (BSN1 3 BSN2 -1)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying 1 RLC blocks, 1 BSNs
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN=3 CV=3)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 3, CS-2): 0c 00 07 ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab 00
+DLGLOBAL DEBUG Tx to lower layers: L1CTL-PDCH_DATA.request
+DLGLOBAL DEBUG Rx from lower layers: L1CTL-PDCH_RTS.indication
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Sending new block at BSN 4, CS=CS-2
+DLGLOBAL DEBUG -- Chunk with length 84 larger than space (30) left in block: copy only remaining space, and we are done
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) data block (BSN=4, CS-2, CV=2): ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) need_padding 0 spb_status 0 spb 0 (BSN1 4 BSN2 -1)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying 1 RLC blocks, 1 BSNs
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN=4 CV=2)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 4, CS-2): 08 00 09 ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab 00
+DLGLOBAL DEBUG Tx to lower layers: L1CTL-PDCH_DATA.request
+DLGLOBAL DEBUG Rx from lower layers: L1CTL-PDCH_RTS.indication
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Sending new block at BSN 5, CS=CS-2
+DLGLOBAL DEBUG -- Chunk with length 54 larger than space (30) left in block: copy only remaining space, and we are done
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) data block (BSN=5, CS-2, CV=1): ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) need_padding 0 spb_status 0 spb 0 (BSN1 5 BSN2 -1)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying 1 RLC blocks, 1 BSNs
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN=5 CV=1)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 5, CS-2): 04 00 0b ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab 00
+DLGLOBAL DEBUG Tx to lower layers: L1CTL-PDCH_DATA.request
+DLGLOBAL DEBUG Rx from lower layers: L1CTL-PDCH_RTS.indication
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Sending new block at BSN 6, CS=CS-2
+DLGLOBAL DEBUG -- Chunk with length 24 is less than remaining space (30): add length header to delimit LLC frame
+DLGLOBAL DEBUG -- Final block, so we done.
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Complete UL frame, len=0
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) data block (BSN=6, CS-2, CV=0): 61 ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab 2b 2b 2b 2b 2b
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) need_padding 0 spb_status 0 spb 0 (BSN1 6 BSN2 -1)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying 1 RLC blocks, 1 BSNs
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN=6 CV=0)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 6, CS-2): 00 00 0c 61 ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab 2b 2b 2b 2b 2b 00
+DLGLOBAL INFO UL_TBF{FLOW}: Received Event LAST_UL_DATA_SENT
+DLGLOBAL INFO UL_TBF{FLOW}: Last UL block sent (CV=0), start T3182
+DLGLOBAL INFO UL_TBF{FLOW}: state_chg to FINISHED
+DLGLOBAL DEBUG Tx to lower layers: L1CTL-PDCH_DATA.request
+DLGLOBAL INFO DL_TBF_ASS{IDLE}: Deallocated
+DLGLOBAL INFO UL_TBF_ASS{IDLE}: Deallocated
+DLGLOBAL INFO UL_TBF{FINISHED}: Send L1CTL-CFG_UL_TBF.req ul_tbf_nr=0 (release)
+DLGLOBAL DEBUG Tx to lower layers: L1CTL-CFG_UL_TBF.request
+DLGLOBAL INFO UL_TBF{FINISHED}: Deallocated
+DLGLOBAL INFO Rx from upper layers: GRR-UNITDATA.request
+DLGLOBAL INFO TLLI=0x00002342 not found, creating entity on the fly
+DLGLOBAL INFO DL_TBF_ASS{IDLE}: Allocated
+DLGLOBAL INFO UL_TBF{NEW}: Allocated
+DLGLOBAL INFO UL_TBF_ASS{IDLE}: Allocated
+DLGLOBAL INFO UL_TBF_ASS{IDLE}: Received Event START
+DLGLOBAL INFO UL_TBF{NEW}: Received Event UL_ASS_START
+DLGLOBAL INFO UL_TBF{NEW}: state_chg to ASSIGN
+DLGLOBAL INFO UL_TBF_ASS{IDLE}: Send RACH.req ra=0x7e
+DLGLOBAL DEBUG Tx to lower layers: L1CTL-RACH.request
+DLGLOBAL INFO UL_TBF_ASS{IDLE}: state_chg to WAIT_CCCH_IMM_ASS
+DLGLOBAL DEBUG Rx from lower layers: L1CTL-CCCH_DATA.indication
+DLGLOBAL INFO UL_TBF_ASS{WAIT_CCCH_IMM_ASS}: Received Event RX_CCCH_IMM_ASS
+DLGLOBAL INFO UL_TBF_ASS{WAIT_CCCH_IMM_ASS}: ImmAss TFI=0 initCS=CS-2 startTimeFN=0
+DLGLOBAL INFO UL_TBF_ASS{WAIT_CCCH_IMM_ASS}: ImmAss DynamicAlloc (1phase access) ts_nr=7 usf=0
+DLGLOBAL INFO UL_TBF_ASS{WAIT_CCCH_IMM_ASS}: state_chg to COMPLETED
+DLGLOBAL INFO UL_TBF{ASSIGN}: Received Event UL_ASS_COMPL
+DLGLOBAL INFO UL_TBF{ASSIGN}: Send L1CTL-CFG_UL_TBF.req ul_tbf_nr=0 ul_slotmask=0x80
+DLGLOBAL DEBUG Tx to lower layers: L1CTL-CFG_UL_TBF.request
+DLGLOBAL INFO UL_TBF{ASSIGN}: state_chg to FLOW
+DLGLOBAL INFO UL_TBF_ASS{COMPLETED}: state_chg to IDLE
+DLGLOBAL DEBUG Rx from lower layers: L1CTL-PDCH_RTS.indication
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Sending new block at BSN 0, CS=CS-2
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Entering Countdown procedure CV=0
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Dequeue next LLC (len=14)
DLGLOBAL DEBUG -- Chunk with length 14 is less than remaining space (26): add length header to delimit LLC frame
DLGLOBAL DEBUG -- Final block, so we done.
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Complete UL frame, len=0
-DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) data block (BSN 0, CS-2): 39 00 00 23 42 01 c0 00 08 01 01 d5 71 00 00 08 29 26 24 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) data block (BSN=0, CS-2, CV=0): 39 00 00 23 42 01 c0 00 08 01 01 d5 71 00 00 08 29 26 24 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) need_padding 0 spb_status 0 spb 0 (BSN1 0 BSN2 -1)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying 1 RLC blocks, 1 BSNs
-DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN 0)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Copying data unit 0 (BSN=0 CV=0)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) msg block (BSN 0, CS-2): 00 01 00 39 00 00 23 42 01 c0 00 08 01 01 d5 71 00 00 08 29 26 24 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 00
DLGLOBAL INFO UL_TBF{FLOW}: Received Event FIRST_UL_DATA_SENT
DLGLOBAL INFO UL_TBF{FLOW}: First UL block sent, stop T3164
@@ -775,14 +890,15 @@
DLGLOBAL DEBUG Tx to lower layers: L1CTL-PDCH_DATA.request
DLGLOBAL DEBUG Rx from lower layers: L1CTL-PDCH_RTS.indication
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00000001) Sending new block at BSN 0, CS=CS-2
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00000001) Entering Countdown procedure CV=0
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00000001) Dequeue next LLC (len=14)
DLGLOBAL DEBUG -- Chunk with length 14 is less than remaining space (30): add length header to delimit LLC frame
DLGLOBAL DEBUG -- Final block, so we done.
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00000001) Complete UL frame, len=0
-DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00000001) data block (BSN 0, CS-2): 39 01 c0 00 08 01 01 d5 71 00 00 08 29 26 24 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00000001) data block (BSN=0, CS-2, CV=0): 39 01 c0 00 08 01 01 d5 71 00 00 08 29 26 24 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00000001) need_padding 0 spb_status 0 spb 0 (BSN1 0 BSN2 -1)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00000001) Copying 1 RLC blocks, 1 BSNs
-DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00000001) Copying data unit 0 (BSN 0)
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00000001) Copying data unit 0 (BSN=0 CV=0)
DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00000001) msg block (BSN 0, CS-2): 00 06 00 39 01 c0 00 08 01 01 d5 71 00 00 08 29 26 24 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 00
DLGLOBAL INFO UL_TBF{FLOW}: Received Event FIRST_UL_DATA_SENT
DLGLOBAL INFO UL_TBF{FLOW}: First UL block sent, stop T3164
diff --git a/tests/rlcmac/rlcmac_prim_test.ok b/tests/rlcmac/rlcmac_prim_test.ok
index 100749a..b555cbe 100644
--- a/tests/rlcmac/rlcmac_prim_test.ok
+++ b/tests/rlcmac/rlcmac_prim_test.ok
@@ -115,11 +115,31 @@
test_rlcmac_prim_down_cb(): Rx L1CTL-CFG_UL_TBF.request ul_tbf_nr=0 ul_slotmask=0x00
test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_DATA.request fn=26 ts=7 data_len=34 data=[00 00 02 1d 11 e5 10 00 e2 18 f2 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 00 ]
=== test_ul_tbf_last_data_cv0_retrans_max end ===
-=== test_ul_tbf_request_another_ul_tbf start ===
+=== test_ul_tbf_countdown_procedure start ===
sys={0.000000}, mono={0.000000}: clock_override_set
test_rlcmac_prim_down_cb(): Rx L1CTL-RACH.request ra=0x7b
test_rlcmac_prim_down_cb(): Rx L1CTL-CFG_UL_TBF.request ul_tbf_nr=0 ul_slotmask=0x80
test_rlcmac_prim_up_cb(): Rx GMMRR-LLC_TRANSMITTED.indication TLLI=0x00002342
+test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_DATA.request fn=4 ts=7 data_len=34 data=[3c 01 01 00 00 23 42 ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab 00 ]
+RTS 0: FN=8
+test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_DATA.request fn=8 ts=7 data_len=34 data=[3c 00 03 ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab 00 ]
+RTS 1: FN=13
+test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_DATA.request fn=13 ts=7 data_len=34 data=[10 00 05 ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab 00 ]
+RTS 2: FN=17
+test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_DATA.request fn=17 ts=7 data_len=34 data=[0c 00 07 ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab 00 ]
+RTS 3: FN=21
+test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_DATA.request fn=21 ts=7 data_len=34 data=[08 00 09 ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab 00 ]
+RTS 4: FN=26
+test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_DATA.request fn=26 ts=7 data_len=34 data=[04 00 0b ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab 00 ]
+RTS 5: FN=30
+test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_DATA.request fn=30 ts=7 data_len=34 data=[00 00 0c 61 ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab ab 2b 2b 2b 2b 2b 00 ]
+=== test_ul_tbf_countdown_procedure end ===
+test_rlcmac_prim_down_cb(): Rx L1CTL-CFG_UL_TBF.request ul_tbf_nr=0 ul_slotmask=0x00
+=== test_ul_tbf_request_another_ul_tbf start ===
+sys={0.000000}, mono={0.000000}: clock_override_set
+test_rlcmac_prim_down_cb(): Rx L1CTL-RACH.request ra=0x7e
+test_rlcmac_prim_down_cb(): Rx L1CTL-CFG_UL_TBF.request ul_tbf_nr=0 ul_slotmask=0x80
+test_rlcmac_prim_up_cb(): Rx GMMRR-LLC_TRANSMITTED.indication TLLI=0x00002342
test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_DATA.request fn=4 ts=7 data_len=34 data=[00 01 00 39 00 00 23 42 01 c0 00 08 01 01 d5 71 00 00 08 29 26 24 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 00 ]
test_rlcmac_prim_down_cb(): Rx L1CTL-CFG_UL_TBF.request ul_tbf_nr=0 ul_slotmask=0x00
test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_DATA.request fn=17 ts=7 data_len=23 data=[40 16 40 00 08 d0 a0 bc 00 00 00 00 00 00 70 00 38 00 00 2b 2b 2b 2b ]
To view, visit change 33095. To unsubscribe, or for help writing mail filters, visit settings.