pespin has uploaded this change for review.

View Change

WIP: countdown procedure

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, 478 insertions(+), 66 deletions(-)

git pull ssh://gerrit.osmocom.org:29418/libosmo-gprs refs/changes/95/33095/1
diff --git a/include/osmocom/gprs/rlcmac/llc_queue.h b/include/osmocom/gprs/rlcmac/llc_queue.h
index 80016e0..371cc3a 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, const 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..31972f5 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 countdown_procedure {
+ 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..a37e4d8 100644
--- a/src/rlcmac/llc_queue.c
+++ b/src/rlcmac/llc_queue.c
@@ -227,3 +227,9 @@
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, const struct gprs_rlcmac_llc_queue *old_q)
+{
+ /* TODO: for each array item (llist), llist_add (prepend) to the gre list (passing ownseship of message) */
+}
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..c7c00cc 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,189 @@
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;
+ /* TODO: talloc steal/repearent? */
+ 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 +563,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 +591,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 +607,6 @@
}

do {
- bool is_final;
int payload_written = 0;

if (msgb_length(ul_tbf->llc_tx_msg) == 0) {
@@ -424,14 +623,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 +633,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 +647,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 +1037,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.

Gerrit-Project: libosmo-gprs
Gerrit-Branch: master
Gerrit-Change-Id: If043c86a0c2b89d0ac0b8174de39fbcb22bed8cb
Gerrit-Change-Number: 33095
Gerrit-PatchSet: 1
Gerrit-Owner: pespin <pespin@sysmocom.de>
Gerrit-MessageType: newchange