pespin has submitted this change. ( 
https://gerrit.osmocom.org/c/libosmo-gprs/+/31352 )

Change subject: rlcmac: Implement N3104
......................................................................

rlcmac: Implement N3104

Related: OS#5500
Change-Id: Ia8c35aad7a537ab76447187847f8cee8c379352c
---
M include/osmocom/gprs/rlcmac/tbf_ul.h
M include/osmocom/gprs/rlcmac/tbf_ul_fsm.h
M src/rlcmac/tbf_ul.c
M src/rlcmac/tbf_ul_fsm.c
M tests/rlcmac/rlcmac_prim_test.c
M tests/rlcmac/rlcmac_prim_test.err
M tests/rlcmac/rlcmac_prim_test.ok
7 files changed, 300 insertions(+), 1 deletion(-)

Approvals:
  Jenkins Builder: Verified
  pespin: Looks good to me, approved




diff --git a/include/osmocom/gprs/rlcmac/tbf_ul.h 
b/include/osmocom/gprs/rlcmac/tbf_ul.h
index f1b7128..c187938 100644
--- a/include/osmocom/gprs/rlcmac/tbf_ul.h
+++ b/include/osmocom/gprs/rlcmac/tbf_ul.h
@@ -46,7 +46,7 @@
 void gprs_rlcmac_ul_tbf_free(struct gprs_rlcmac_ul_tbf *ul_tbf);

 bool gprs_rlcmac_ul_tbf_in_contention_resolution(const struct 
gprs_rlcmac_ul_tbf *ul_tbf);
-
+unsigned int gprs_rlcmac_ul_tbf_n3104_max(const struct gprs_rlcmac_ul_tbf 
*ul_tbf);
 bool gprs_rlcmac_ul_tbf_data_rts(const struct gprs_rlcmac_ul_tbf *ul_tbf, 
const struct gprs_rlcmac_rts_block_ind *bi);
 bool gprs_rlcmac_ul_tbf_dummy_rts(const struct gprs_rlcmac_ul_tbf *ul_tbf, 
const struct gprs_rlcmac_rts_block_ind *bi);

diff --git a/include/osmocom/gprs/rlcmac/tbf_ul_fsm.h 
b/include/osmocom/gprs/rlcmac/tbf_ul_fsm.h
index 6957992..8cadf69 100644
--- a/include/osmocom/gprs/rlcmac/tbf_ul_fsm.h
+++ b/include/osmocom/gprs/rlcmac/tbf_ul_fsm.h
@@ -28,6 +28,7 @@
        GPRS_RLCMAC_TBF_UL_EV_UL_ASS_START,
        GPRS_RLCMAC_TBF_UL_EV_UL_ASS_COMPL,
        GPRS_RLCMAC_TBF_UL_EV_FIRST_UL_DATA_SENT,
+       GPRS_RLCMAC_TBF_UL_EV_N3104_MAX,
        GPRS_RLCMAC_TBF_UL_EV_CONTENTION_RESOLUTION_SUCCESS,
        GPRS_RLCMAC_TBF_UL_EV_LAST_UL_DATA_SENT,
        GPRS_RLCMAC_TBF_UL_EV_FINAL_ACK_RECVD,
diff --git a/src/rlcmac/tbf_ul.c b/src/rlcmac/tbf_ul.c
index ce7ac1f..d5067dc 100644
--- a/src/rlcmac/tbf_ul.c
+++ b/src/rlcmac/tbf_ul.c
@@ -112,6 +112,17 @@
        }
 }

+unsigned int gprs_rlcmac_ul_tbf_n3104_max(const struct gprs_rlcmac_ul_tbf 
*ul_tbf)
+{
+       /* 3GPP TS 44.060 13.3:
+        * N3104_MAX = 3 * (BS_CV_MAX + 3) * number of uplink timeslots 
assigned */
+       /* If we didn't receive SI13 yet, use maximum value bs_cv_max in range 
0..15 */
+       uint8_t bs_cv_max = g_ctx->si13_available ?
+                               
g_ctx->si13ro.u.PBCCH_Not_present.GPRS_Cell_Options.BS_CV_MAX :
+                               15;
+       return 3 * (bs_cv_max + 3) * ul_tbf->cur_alloc.num_ts;
+}
+
 /* Used by the scheduler to find out whether an Uplink Dummy Control Block can 
be transmitted. If
  * true, it will potentially call gprs_rlcmac_ul_tbf_dummy_create() to 
generate a new dummy message to transmit. */
 bool gprs_rlcmac_ul_tbf_dummy_rts(const struct gprs_rlcmac_ul_tbf *ul_tbf, 
const struct gprs_rlcmac_rts_block_ind *bi)
@@ -790,6 +801,15 @@
        if (ul_tbf->n3104 == 0)
                osmo_fsm_inst_dispatch(ul_tbf->state_fsm.fi, 
GPRS_RLCMAC_TBF_UL_EV_FIRST_UL_DATA_SENT, NULL);
        ul_tbf->n3104++;
+       if (gprs_rlcmac_ul_tbf_in_contention_resolution(ul_tbf)) {
+               unsigned int n3104_max = gprs_rlcmac_ul_tbf_n3104_max(ul_tbf);
+               if (ul_tbf->n3104 >= n3104_max) {
+                       LOGPTBFUL(ul_tbf, LOGL_NOTICE, "N3104_MAX (%u) 
reached\n", n3104_max);
+                       osmo_fsm_inst_dispatch(ul_tbf->state_fsm.fi, 
GPRS_RLCMAC_TBF_UL_EV_N3104_MAX, NULL);
+               } else {
+                       LOGPTBFUL(ul_tbf, LOGL_DEBUG, "N3104 inc (%u)\n", 
ul_tbf->n3104);
+               }
+       }
        return msg;
 }

diff --git a/src/rlcmac/tbf_ul_fsm.c b/src/rlcmac/tbf_ul_fsm.c
index 19d352d..a84859d 100644
--- a/src/rlcmac/tbf_ul_fsm.c
+++ b/src/rlcmac/tbf_ul_fsm.c
@@ -34,6 +34,7 @@
        { GPRS_RLCMAC_TBF_UL_EV_UL_ASS_START,                   "UL_ASS_START" 
},
        { GPRS_RLCMAC_TBF_UL_EV_UL_ASS_COMPL,                   "UL_ASS_COMPL" 
},
        { GPRS_RLCMAC_TBF_UL_EV_FIRST_UL_DATA_SENT,             
"FIRST_UL_DATA_SENT" },
+       { GPRS_RLCMAC_TBF_UL_EV_N3104_MAX,                      "N3104_MAX" },
        { GPRS_RLCMAC_TBF_UL_EV_CONTENTION_RESOLUTION_SUCCESS,  
"CONTENTION_RESOLUTION_SUCCESS" },
        { GPRS_RLCMAC_TBF_UL_EV_LAST_UL_DATA_SENT,              
"LAST_UL_DATA_SENT" },
        { GPRS_RLCMAC_TBF_UL_EV_FINAL_ACK_RECVD,                
"FINAL_ACK_RECVD" },
@@ -149,6 +150,9 @@
                        osmo_timer_schedule(&fi->timer, val_sec, 0);
                }
                break;
+       case GPRS_RLCMAC_TBF_UL_EV_N3104_MAX:
+               reinit_pkt_acces_procedure(ctx);
+               break;
        case GPRS_RLCMAC_TBF_UL_EV_CONTENTION_RESOLUTION_SUCCESS:
                LOGPFSML(ctx->fi, LOGL_INFO, "Contention resolution succeeded, 
stop T3166\n");
                OSMO_ASSERT(ctx->ul_tbf->ul_ass_fsm.ass_type == 
GPRS_RLCMAC_TBF_UL_ASS_TYPE_1PHASE);
@@ -168,6 +172,9 @@
 {
        struct gprs_rlcmac_tbf_ul_fsm_ctx *ctx = (struct 
gprs_rlcmac_tbf_ul_fsm_ctx *)fi->priv;
        switch (event) {
+       case GPRS_RLCMAC_TBF_UL_EV_N3104_MAX:
+               reinit_pkt_acces_procedure(ctx);
+               break;
        case GPRS_RLCMAC_TBF_UL_EV_CONTENTION_RESOLUTION_SUCCESS:
                LOGPFSML(ctx->fi, LOGL_INFO, "Contention resolution succeeded, 
stop T3166\n");
                OSMO_ASSERT(ctx->ul_tbf->ul_ass_fsm.ass_type == 
GPRS_RLCMAC_TBF_UL_ASS_TYPE_1PHASE);
@@ -204,6 +211,7 @@
        [GPRS_RLCMAC_TBF_UL_ST_FLOW] = {
                .in_event_mask =
                        X(GPRS_RLCMAC_TBF_UL_EV_FIRST_UL_DATA_SENT) |
+                       X(GPRS_RLCMAC_TBF_UL_EV_N3104_MAX) |
                        X(GPRS_RLCMAC_TBF_UL_EV_CONTENTION_RESOLUTION_SUCCESS) |
                        X(GPRS_RLCMAC_TBF_UL_EV_LAST_UL_DATA_SENT),
                .out_state_mask =
@@ -214,6 +222,7 @@
        },
        [GPRS_RLCMAC_TBF_UL_ST_FINISHED] = {
                .in_event_mask =
+                       X(GPRS_RLCMAC_TBF_UL_EV_N3104_MAX) |
                        X(GPRS_RLCMAC_TBF_UL_EV_CONTENTION_RESOLUTION_SUCCESS) |
                        X(GPRS_RLCMAC_TBF_UL_EV_FINAL_ACK_RECVD),
                .out_state_mask =
diff --git a/tests/rlcmac/rlcmac_prim_test.c b/tests/rlcmac/rlcmac_prim_test.c
index 09fa3c4..cc33c4c 100644
--- a/tests/rlcmac/rlcmac_prim_test.c
+++ b/tests/rlcmac/rlcmac_prim_test.c
@@ -24,6 +24,8 @@
 #include <osmocom/core/timer.h>
 #include <osmocom/core/timer_compat.h>
 #include <osmocom/core/select.h>
+#include <osmocom/gsm/protocol/gsm_04_08.h>
+#include <osmocom/gsm/gsm48_rest_octets.h>

 #include <osmocom/gprs/rlcmac/rlcmac.h>
 #include <osmocom/gprs/rlcmac/csn1_defs.h>
@@ -293,6 +295,63 @@
                
ack_desc->RECEIVED_BLOCK_BITMAP[sizeof(ack_desc->RECEIVED_BLOCK_BITMAP) - idx/8 
- 1] &= ~(1 << (idx & 0x03));
 }

+static uint8_t *create_si13(uint8_t bs_cv_max /* 0..15 */)
+{
+       static uint8_t si13_buf[GSM_MACBLOCK_LEN];
+       struct gsm48_system_information_type_13 *si13 = (struct 
gsm48_system_information_type_13 *)&si13_buf[0];
+       struct osmo_gsm48_si13_info si13_info;
+       int ret;
+
+       memset(si13, GSM_MACBLOCK_PADDING, GSM_MACBLOCK_LEN);
+
+       si13->header.rr_protocol_discriminator = GSM48_PDISC_RR;
+       si13->header.skip_indicator = 0;
+       si13->header.system_information = GSM48_MT_RR_SYSINFO_13;
+
+       si13_info = (struct osmo_gsm48_si13_info){
+               .cell_opts = {
+                       .nmo            = GPRS_NMO_II,
+                       .t3168          = 2000,
+                       .t3192          = 1500,
+                       .drx_timer_max  = 3,
+                       .bs_cv_max      = bs_cv_max,
+                       .ctrl_ack_type_use_block = 1,
+                       .ext_info_present = true,
+                       .ext_info = {
+                               .egprs_supported = 1,
+                               .use_egprs_p_ch_req = 1,
+                               .bep_period = 5,
+                               .pfc_supported = 0,
+                               .dtm_supported = 0,
+                               .bss_paging_coordination = 1,
+                               .ccn_active = true,
+                       },
+               },
+               .pwr_ctrl_pars = {
+                       .alpha          = 0,    /* a = 0.0 */
+                       .t_avg_w        = 16,
+                       .t_avg_t        = 16,
+                       .pc_meas_chan   = 0,    /* downling measured on CCCH */
+                       .n_avg_i        = 8,
+               },
+               .bcch_change_mark       = 1, /* Information about the other SIs 
*/
+               .si_change_field        = 0,
+               .rac            = 33,
+               .spgc_ccch_sup  = 0,
+               .net_ctrl_ord   = 1 /* NC1 */,
+               .prio_acc_thr   = 6,
+       };
+
+       ret = osmo_gsm48_rest_octets_si13_encode(si13->rest_octets, &si13_info);
+       if (ret < 0)
+               return NULL;
+
+       /* length is coded in bit 2 an up */
+       si13->header.l2_plen = 0x01;
+
+       return &si13_buf[0];
+}
+
 static int test_rlcmac_prim_up_cb(struct osmo_gprs_rlcmac_prim *rlcmac_prim, 
void *user_data)
 {
        const char *pdu_name = osmo_gprs_rlcmac_prim_name(rlcmac_prim);
@@ -524,6 +583,55 @@
        cleanup_test();
 }

+static void test_ul_tbf_n3104_timeout(void)
+{
+       struct osmo_gprs_rlcmac_prim *rlcmac_prim;
+       int rc;
+
+       printf("=== %s start ===\n", __func__);
+       prepare_test();
+       uint32_t tlli = 0x2342;
+       uint8_t ts_nr = 7;
+       uint8_t usf = 0;
+       uint32_t rts_fn = 4;
+       unsigned int i;
+       const unsigned int bs_cv_max = 0;
+       const unsigned int num_ts = 1;
+       const unsigned int n3104_max = 3 * (bs_cv_max + 3) * num_ts;
+
+       /* Submit an SI13 with bs_cv_max=0: */
+       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);
+
+       rlcmac_prim = osmo_gprs_rlcmac_prim_alloc_grr_unitdata_req(tlli, 
pdu_llc_gmm_att_req,
+                                           sizeof(pdu_llc_gmm_att_req));
+       rlcmac_prim->grr.unitdata_req.sapi = OSMO_GPRS_RLCMAC_LLC_SAPI_GMM;
+       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);
+
+       for (i = 0; i < n3104_max; i++) {
+               rts_fn = fn_next_block(rts_fn);
+               printf("RTS %u: FN=%u\n", i, rts_fn);
+               /* Trigger transmission of LLC data (GMM Attach) (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);
+       }
+
+       /* After N3104 triggers, MS re-tries pkt access: */
+       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);
+
+       printf("=== %s end ===\n", __func__);
+       cleanup_test();
+}
+
 /* PCU allocates a DL TBF through PCH ImmAss for MS (when in packet-idle) */
 static void test_dl_tbf_ccch_assign(void)
 {
@@ -593,6 +701,7 @@
        test_ul_tbf_attach();
        test_ul_tbf_t3164_timeout();
        test_ul_tbf_t3166_timeout();
+       test_ul_tbf_n3104_timeout();
        test_dl_tbf_ccch_assign();

        talloc_free(tall_ctx);
diff --git a/tests/rlcmac/rlcmac_prim_test.err 
b/tests/rlcmac/rlcmac_prim_test.err
index 26deb79..cd154f1 100644
--- a/tests/rlcmac/rlcmac_prim_test.err
+++ b/tests/rlcmac/rlcmac_prim_test.err
@@ -28,6 +28,7 @@
 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 INFO 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 3 is less than remaining space (30): add 
length header to delimit LLC frame
@@ -40,6 +41,7 @@
 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) msg block (BSN 1, CS-2): 00 00 02 0d 
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 2b 
2b 2b 2b 00
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) N3104 inc (2)
 DLGLOBAL INFO Rx from lower layers: L1CTL-PDCH_DATA.indication
 DLGLOBAL INFO TS=7 FN=8 Rx Pkt UL ACK/NACK
 DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Got GPRS UL ACK bitmap: SSN: 1, BSN 
0 to 2 - 1 (2 blocks), "RR"
@@ -160,6 +162,7 @@
 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 INFO UL_TBF{FLOW}: Timeout of T3166
 DLGLOBAL INFO UL_TBF{FLOW}: T3166 timeout attempts=1
 DLGLOBAL INFO UL_TBF{FLOW}: state_chg to NEW
@@ -187,6 +190,7 @@
 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 INFO UL_TBF{FLOW}: Timeout of T3166
 DLGLOBAL INFO UL_TBF{FLOW}: T3166 timeout attempts=2
 DLGLOBAL INFO UL_TBF{FLOW}: state_chg to NEW
@@ -214,6 +218,7 @@
 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 INFO UL_TBF{FLOW}: Timeout of T3166
 DLGLOBAL INFO UL_TBF{FLOW}: T3166 timeout attempts=3
 DLGLOBAL INFO UL_TBF{FLOW}: state_chg to NEW
@@ -241,11 +246,130 @@
 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 INFO UL_TBF{FLOW}: Timeout of T3166
 DLGLOBAL INFO UL_TBF{FLOW}: T3166 timeout attempts=4
 DLGLOBAL NOTICE UL_TBF{FLOW}: TBF establishment failure (T3166 timeout 
attempts=4)
 DLGLOBAL INFO UL_TBF_ASS{IDLE}: Deallocated
 DLGLOBAL INFO UL_TBF{FLOW}: Deallocated
+DLGLOBAL INFO 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 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=0x7a
+DLGLOBAL INFO UL_TBF_ASS{IDLE}: state_chg to WAIT_CCCH_IMM_ASS
+DLGLOBAL INFO 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 initial CS=CS-2
+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-CF_UL_TBF.req ul_slotmask=0x80
+DLGLOBAL INFO UL_TBF{ASSIGN}: state_chg to FLOW
+DLGLOBAL INFO UL_TBF_ASS{COMPLETED}: state_chg to IDLE
+DLGLOBAL INFO 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=33)
+DLGLOBAL DEBUG -- Chunk with length 33 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 0, CS-2): 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 11 e5 10 00
+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) msg block (BSN 0, CS-2): 3c 00 01 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 11 
e5 10 00 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 INFO 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 3 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 INFO UL_TBF{FLOW}: Received Event LAST_UL_DATA_SENT
+DLGLOBAL INFO UL_TBF{FLOW}: state_chg to FINISHED
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) data block (BSN 1, CS-2): 0d 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 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) msg block (BSN 1, CS-2): 00 00 02 0d 
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 2b 
2b 2b 2b 00
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) N3104 inc (2)
+DLGLOBAL INFO Rx from lower layers: L1CTL-PDCH_RTS.indication
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Restarting at BSN 0, because all 
blocks have been transmitted.
+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) msg block (BSN 0, CS-2): 3c 00 01 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 11 
e5 10 00 00
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) N3104 inc (3)
+DLGLOBAL INFO Rx from lower layers: L1CTL-PDCH_RTS.indication
+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) msg block (BSN 1, CS-2): 00 00 02 0d 
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 2b 
2b 2b 2b 00
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) N3104 inc (4)
+DLGLOBAL INFO Rx from lower layers: L1CTL-PDCH_RTS.indication
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Restarting at BSN 0, because all 
blocks have been transmitted.
+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) msg block (BSN 0, CS-2): 3c 00 01 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 11 
e5 10 00 00
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) N3104 inc (5)
+DLGLOBAL INFO Rx from lower layers: L1CTL-PDCH_RTS.indication
+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) msg block (BSN 1, CS-2): 00 00 02 0d 
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 2b 
2b 2b 2b 00
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) N3104 inc (6)
+DLGLOBAL INFO Rx from lower layers: L1CTL-PDCH_RTS.indication
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Restarting at BSN 0, because all 
blocks have been transmitted.
+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) msg block (BSN 0, CS-2): 3c 00 01 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 11 
e5 10 00 00
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) N3104 inc (7)
+DLGLOBAL INFO Rx from lower layers: L1CTL-PDCH_RTS.indication
+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) msg block (BSN 1, CS-2): 00 00 02 0d 
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 2b 
2b 2b 2b 00
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) N3104 inc (8)
+DLGLOBAL INFO Rx from lower layers: L1CTL-PDCH_RTS.indication
+DLGLOBAL DEBUG TBF(UL:NR-0:TLLI-00002342) Restarting at BSN 0, because all 
blocks have been transmitted.
+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) msg block (BSN 0, CS-2): 3c 00 01 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 11 
e5 10 00 00
+DLGLOBAL NOTICE TBF(UL:NR-0:TLLI-00002342) N3104_MAX (9) reached
+DLGLOBAL INFO UL_TBF{FINISHED}: Received Event N3104_MAX
+DLGLOBAL INFO UL_TBF{FINISHED}: state_chg to NEW
+DLGLOBAL INFO UL_TBF{NEW}: Send L1CTL-CF_UL_TBF.req ul_slotmask=0x00
+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=0x7b
+DLGLOBAL INFO UL_TBF_ASS{IDLE}: state_chg to WAIT_CCCH_IMM_ASS
+DLGLOBAL INFO 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 initial CS=CS-2
+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-CF_UL_TBF.req ul_slotmask=0x80
+DLGLOBAL INFO UL_TBF{ASSIGN}: state_chg to FLOW
+DLGLOBAL INFO UL_TBF_ASS{COMPLETED}: state_chg to IDLE
+DLGLOBAL INFO UL_TBF_ASS{IDLE}: Deallocated
+DLGLOBAL INFO UL_TBF{FLOW}: Deallocated
 DLGLOBAL INFO Rx from upper layers: GMMRR-ASSIGN.request
 DLGLOBAL INFO GMMRR-ASSIGN.req: creating new entity TLLI=0x00000001
 DLGLOBAL INFO Rx from lower layers: L1CTL-CCCH_DATA.indication
diff --git a/tests/rlcmac/rlcmac_prim_test.ok b/tests/rlcmac/rlcmac_prim_test.ok
index 9c61988..3db040a 100644
--- a/tests/rlcmac/rlcmac_prim_test.ok
+++ b/tests/rlcmac/rlcmac_prim_test.ok
@@ -53,6 +53,32 @@
 sys={20.000000}, mono={20.000000}: clock_override_add
 sys={20.000000}, mono={20.000000}: Expect T3166 timeout
 === test_ul_tbf_t3166_timeout end ===
+=== test_ul_tbf_n3104_timeout start ===
+sys={0.000000}, mono={0.000000}: clock_override_set
+test_rlcmac_prim_down_cb(): Rx L1CTL-RACH.request ra=0x7a
+test_rlcmac_prim_down_cb(): Rx L1CTL-CFG_UL_TBF.request ul_tbf_nr=0 
ul_slotmask=0x80
+RTS 0: FN=8
+test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_DATA.request fn=8 ts=7 data_len=34 
data=[3c 00 01 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 11 e5 10 00 00 ]
+RTS 1: FN=13
+test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_DATA.request fn=13 ts=7 data_len=34 
data=[00 00 02 0d 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 2b 2b 2b 2b 00 ]
+RTS 2: FN=17
+test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_DATA.request fn=17 ts=7 data_len=34 
data=[3c 00 01 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 11 e5 10 00 00 ]
+RTS 3: FN=21
+test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_DATA.request fn=21 ts=7 data_len=34 
data=[00 00 02 0d 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 2b 2b 2b 2b 00 ]
+RTS 4: FN=26
+test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_DATA.request fn=26 ts=7 data_len=34 
data=[3c 00 01 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 11 e5 10 00 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 02 0d 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 2b 2b 2b 2b 00 ]
+RTS 6: FN=34
+test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_DATA.request fn=34 ts=7 data_len=34 
data=[3c 00 01 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 11 e5 10 00 00 ]
+RTS 7: FN=39
+test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_DATA.request fn=39 ts=7 data_len=34 
data=[00 00 02 0d 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 2b 2b 2b 2b 00 ]
+RTS 8: FN=43
+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-RACH.request ra=0x7b
+test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_DATA.request fn=43 ts=7 data_len=34 
data=[3c 00 01 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 11 e5 10 00 00 ]
+test_rlcmac_prim_down_cb(): Rx L1CTL-CFG_UL_TBF.request ul_tbf_nr=0 
ul_slotmask=0x80
+=== test_ul_tbf_n3104_timeout end ===
 === test_dl_tbf_ccch_assign start ===
 sys={0.000000}, mono={0.000000}: clock_override_set
 test_rlcmac_prim_down_cb(): Rx L1CTL-CFG_DL_TBF.request dl_tbf_nr=0 
dl_slotmask=0x80 dl_tfi=0

--
To view, visit https://gerrit.osmocom.org/c/libosmo-gprs/+/31352
To unsubscribe, or for help writing mail filters, visit 
https://gerrit.osmocom.org/settings

Gerrit-Project: libosmo-gprs
Gerrit-Branch: master
Gerrit-Change-Id: Ia8c35aad7a537ab76447187847f8cee8c379352c
Gerrit-Change-Number: 31352
Gerrit-PatchSet: 4
Gerrit-Owner: pespin <[email protected]>
Gerrit-Reviewer: Jenkins Builder
Gerrit-Reviewer: pespin <[email protected]>
Gerrit-MessageType: merged

Reply via email to