rlcmac: add OSMO_GPRS_RLCMAC_L1CTL_PDCH_{ESTABLISH,RELEASE}.req

* Send the PDCH_ESTABLISH.req on receipt of RR IMM ASS,
* Sending of PDCH_RELEASE.req is to be implemented.

Change-Id: I2568c58646ce7511367275ac96cd55e7fdd7ec18
Related: OS#5500

5 files changed, 113 insertions, 0 deletions

diff --git a/include/osmocom/gprs/rlcmac/rlcmac_prim.h b/include/osmocom/gprs/rlcmac/rlcmac_prim.h
index fa1ee52..16d43d1 100644
--- a/include/osmocom/gprs/rlcmac/rlcmac_prim.h
+++ b/include/osmocom/gprs/rlcmac/rlcmac_prim.h
@@ -111,6 +111,8 @@ enum osmo_gprs_rlcmac_l1ctl_prim_type {
 	OSMO_GPRS_RLCMAC_L1CTL_PDCH_RTS,
 	OSMO_GPRS_RLCMAC_L1CTL_CFG_UL_TBF,
 	OSMO_GPRS_RLCMAC_L1CTL_CFG_DL_TBF,
+	OSMO_GPRS_RLCMAC_L1CTL_PDCH_ESTABLISH,
+	OSMO_GPRS_RLCMAC_L1CTL_PDCH_RELEASE,
 };
 
 extern const struct value_string osmo_gprs_rlcmac_l1ctl_prim_type_names[];
@@ -174,6 +176,22 @@ struct osmo_gprs_rlcmac_l1ctl_prim {
 			uint8_t dl_slotmask;
 			uint8_t dl_tfi; /* DL TFI for all PDCHs indicated in the slotmask */
 		} cfg_dl_tbf_req;
+		/* OSMO_GPRS_RLCMAC_L1CTL_PDCH_ESTABLISH | Req */
+		struct {
+			uint8_t ts_nr;	/* Timeslot Number */
+			uint8_t tsc;	/* Training Sequence Code */
+			uint8_t ta;	/* Timing Advance */
+			bool fh;	/* Frequency Hopping */
+			union {
+				uint16_t arfcn;
+				struct {
+					uint8_t hsn;
+					uint8_t maio;
+					uint8_t ma_len;
+					uint8_t ma[8];
+				} fhp; /* fh == true */
+			};
+		} pdch_est_req;
 	};
 };
 
@@ -211,3 +229,5 @@ struct osmo_gprs_rlcmac_prim *osmo_gprs_rlcmac_prim_alloc_l1ctl_pdch_data_ind(ui
 				uint8_t rx_lev, uint16_t ber10k, int16_t ci_cb,
 				uint8_t *data, uint8_t data_len);
 struct osmo_gprs_rlcmac_prim *osmo_gprs_rlcmac_prim_alloc_l1ctl_pdch_rts_ind(uint8_t ts_nr, uint32_t fn, uint8_t usf);
+struct osmo_gprs_rlcmac_prim *gprs_rlcmac_prim_alloc_l1ctl_pdch_est_req(uint8_t ts_nr, uint8_t tsc, uint8_t ta);
+struct osmo_gprs_rlcmac_prim *gprs_rlcmac_prim_alloc_l1ctl_pdch_rel_req(void);
diff --git a/src/rlcmac/rlcmac.c b/src/rlcmac/rlcmac.c
index 318e3a7..b026048 100644
--- a/src/rlcmac/rlcmac.c
+++ b/src/rlcmac/rlcmac.c
@@ -252,6 +252,7 @@ int gprs_rlcmac_handle_ccch_imm_ass(const struct gsm48_imm_ass *ia, uint32_t fn)
 	IA_RestOctets_t iaro;
 	const uint8_t *iaro_raw = ((uint8_t *)ia) + sizeof(*ia) + ia->mob_alloc_len;
 	size_t iaro_raw_len = GSM_MACBLOCK_LEN - (sizeof(*ia) + ia->mob_alloc_len);
+	struct osmo_gprs_rlcmac_prim *prim;
 
 	rc = rsl_dec_chan_nr(ia->chan_desc.chan_nr, &ch_type, &ch_subch, &ch_ts);
 	if (rc != 0) {
@@ -267,6 +268,43 @@ int gprs_rlcmac_handle_ccch_imm_ass(const struct gsm48_imm_ass *ia, uint32_t fn)
 		return rc;
 	}
 
+	prim = gprs_rlcmac_prim_alloc_l1ctl_pdch_est_req(ch_ts,
+							 ia->chan_desc.h0.tsc,
+							 ia->timing_advance);
+	if (!ia->chan_desc.h0.h) {
+		/* TODO: indirect encoding of hopping RF channel configuration
+		 * see 3GPP TS 44.018, section 10.5.2.25a */
+		if (ia->chan_desc.h0.spare & 0x02) {
+			LOGRLCMAC(LOGL_ERROR,
+				  "Indirect encoding of hopping RF channel "
+				  "configuration is not supported\n");
+			msgb_free(prim->oph.msg);
+			return -ENOTSUP;
+		}
+		/* non-hopping RF channel configuraion */
+		prim->l1ctl.pdch_est_req.fh = false;
+		prim->l1ctl.pdch_est_req.arfcn = (ia->chan_desc.h0.arfcn_low)
+					       | (ia->chan_desc.h0.arfcn_high << 8);
+	} else {
+		/* direct encoding of hopping RF channel configuration */
+		prim->l1ctl.pdch_est_req.fh = true;
+		prim->l1ctl.pdch_est_req.fhp.hsn = ia->chan_desc.h1.hsn;
+		prim->l1ctl.pdch_est_req.fhp.maio = (ia->chan_desc.h1.maio_low)
+						  | (ia->chan_desc.h1.maio_high << 2);
+
+		const size_t ma_len_max = sizeof(prim->l1ctl.pdch_est_req.fhp.ma);
+		prim->l1ctl.pdch_est_req.fhp.ma_len = OSMO_MIN(ia->mob_alloc_len, ma_len_max);
+		memcpy(&prim->l1ctl.pdch_est_req.fhp.ma[0], &ia->mob_alloc[0],
+		       prim->l1ctl.pdch_est_req.fhp.ma_len);
+	}
+
+	/* Request the lower layers to establish a PDCH channel */
+	rc = gprs_rlcmac_prim_call_down_cb(prim);
+	if (rc != 0) {
+		LOGRLCMAC(LOGL_ERROR, "PDCH channel establishment failed\n");
+		return rc;
+	}
+
 	switch (iaro.UnionType) {
 	case 0: /* iaro.u.ll.* (IA_RestOctetsLL_t) */
 		/* TODO: iaro.u.ll.Compressed_Inter_RAT_HO_INFO_IND */
diff --git a/src/rlcmac/rlcmac_prim.c b/src/rlcmac/rlcmac_prim.c
index a5f796a..5261a73 100644
--- a/src/rlcmac/rlcmac_prim.c
+++ b/src/rlcmac/rlcmac_prim.c
@@ -70,6 +70,8 @@ const struct value_string osmo_gprs_rlcmac_l1ctl_prim_type_names[] = {
 	{ OSMO_GPRS_RLCMAC_L1CTL_PDCH_RTS,	"PDCH_RTS" },
 	{ OSMO_GPRS_RLCMAC_L1CTL_CFG_UL_TBF,	"CFG_UL_TBF" },
 	{ OSMO_GPRS_RLCMAC_L1CTL_CFG_DL_TBF,	"CFG_DL_TBF" },
+	{ OSMO_GPRS_RLCMAC_L1CTL_PDCH_ESTABLISH, "PDCH_ESTABLISH" },
+	{ OSMO_GPRS_RLCMAC_L1CTL_PDCH_RELEASE,	"PDCH_RELEASE" },
 	{ 0, NULL }
 };
 
@@ -325,6 +327,25 @@ struct osmo_gprs_rlcmac_prim *gprs_rlcmac_prim_alloc_l1ctl_cfg_ul_tbf_req(uint8_
 	return rlcmac_prim;
 }
 
+/* L1CTL-PDCH_ESTABLISH.req */
+struct osmo_gprs_rlcmac_prim *gprs_rlcmac_prim_alloc_l1ctl_pdch_est_req(uint8_t ts_nr, uint8_t tsc, uint8_t ta)
+{
+	struct osmo_gprs_rlcmac_prim *rlcmac_prim;
+	rlcmac_prim = rlcmac_prim_l1ctl_alloc(OSMO_GPRS_RLCMAC_L1CTL_PDCH_ESTABLISH, PRIM_OP_REQUEST, 0);
+	rlcmac_prim->l1ctl.pdch_est_req.ts_nr = ts_nr;
+	rlcmac_prim->l1ctl.pdch_est_req.tsc = tsc;
+	rlcmac_prim->l1ctl.pdch_est_req.ta = ta;
+	return rlcmac_prim;
+}
+
+/* L1CTL-PDCH_RELEASE.req */
+struct osmo_gprs_rlcmac_prim *gprs_rlcmac_prim_alloc_l1ctl_pdch_rel_req(void)
+{
+	struct osmo_gprs_rlcmac_prim *rlcmac_prim;
+	rlcmac_prim = rlcmac_prim_l1ctl_alloc(OSMO_GPRS_RLCMAC_L1CTL_PDCH_RELEASE, PRIM_OP_REQUEST, 0);
+	return rlcmac_prim;
+}
+
 int gprs_rlcmac_prim_handle_unsupported(struct osmo_gprs_rlcmac_prim *rlcmac_prim)
 {
 	LOGRLCMAC(LOGL_ERROR, "Unsupported rlcmac_prim! %s\n", osmo_gprs_rlcmac_prim_name(rlcmac_prim));
diff --git a/tests/rlcmac/rlcmac_prim_test.err b/tests/rlcmac/rlcmac_prim_test.err
index 2d68abc..ea4d2e5 100644
--- a/tests/rlcmac/rlcmac_prim_test.err
+++ b/tests/rlcmac/rlcmac_prim_test.err
@@ -10,6 +10,7 @@ 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 DEBUG Tx to lower layers: L1CTL-PDCH_ESTABLISH.request
 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
@@ -81,6 +82,7 @@ DLGLOBAL INFO UL_TBF_ASS{IDLE}: Send RACH.req ra=0x79
 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 DEBUG Tx to lower layers: L1CTL-PDCH_ESTABLISH.request
 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
@@ -102,6 +104,7 @@ DLGLOBAL INFO UL_TBF_ASS{IDLE}: Send RACH.req ra=0x7b
 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 DEBUG Tx to lower layers: L1CTL-PDCH_ESTABLISH.request
 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
@@ -123,6 +126,7 @@ DLGLOBAL INFO UL_TBF_ASS{IDLE}: Send RACH.req ra=0x79
 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 DEBUG Tx to lower layers: L1CTL-PDCH_ESTABLISH.request
 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
@@ -144,6 +148,7 @@ DLGLOBAL INFO UL_TBF_ASS{IDLE}: Send RACH.req ra=0x78
 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 DEBUG Tx to lower layers: L1CTL-PDCH_ESTABLISH.request
 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
@@ -173,6 +178,7 @@ DLGLOBAL INFO UL_TBF_ASS{IDLE}: Send RACH.req ra=0x7a
 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 DEBUG Tx to lower layers: L1CTL-PDCH_ESTABLISH.request
 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
@@ -208,6 +214,7 @@ DLGLOBAL INFO UL_TBF_ASS{IDLE}: Send RACH.req ra=0x7c
 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 DEBUG Tx to lower layers: L1CTL-PDCH_ESTABLISH.request
 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
@@ -240,6 +247,7 @@ DLGLOBAL INFO UL_TBF_ASS{IDLE}: Send RACH.req ra=0x79
 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 DEBUG Tx to lower layers: L1CTL-PDCH_ESTABLISH.request
 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
@@ -272,6 +280,7 @@ DLGLOBAL INFO UL_TBF_ASS{IDLE}: Send RACH.req ra=0x7d
 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 DEBUG Tx to lower layers: L1CTL-PDCH_ESTABLISH.request
 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
@@ -315,6 +324,7 @@ DLGLOBAL DEBUG Tx to lower layers: L1CTL-RACH.request
 DLGLOBAL INFO UL_TBF_ASS{IDLE}: state_chg to WAIT_CCCH_IMM_ASS
 DLGLOBAL INFO Rx from upper layers: GRR-UNITDATA.request
 DLGLOBAL DEBUG Rx from lower layers: L1CTL-CCCH_DATA.indication
+DLGLOBAL DEBUG Tx to lower layers: L1CTL-PDCH_ESTABLISH.request
 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
@@ -458,6 +468,7 @@ DLGLOBAL DEBUG Tx to lower layers: L1CTL-RACH.request
 DLGLOBAL INFO UL_TBF_ASS{IDLE}: state_chg to WAIT_CCCH_IMM_ASS
 DLGLOBAL DEBUG Tx to lower layers: L1CTL-PDCH_DATA.request
 DLGLOBAL DEBUG Rx from lower layers: L1CTL-CCCH_DATA.indication
+DLGLOBAL DEBUG Tx to lower layers: L1CTL-PDCH_ESTABLISH.request
 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
@@ -484,6 +495,7 @@ DLGLOBAL INFO UL_TBF_ASS{IDLE}: Send RACH.req ra=0x7a
 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 DEBUG Tx to lower layers: L1CTL-PDCH_ESTABLISH.request
 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
@@ -548,6 +560,7 @@ DLGLOBAL INFO UL_TBF_ASS{IDLE}: Send RACH.req ra=0x7b
 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 DEBUG Tx to lower layers: L1CTL-PDCH_ESTABLISH.request
 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
@@ -658,6 +671,7 @@ DLGLOBAL INFO UL_TBF_ASS{IDLE}: Send RACH.req ra=0x7b
 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 DEBUG Tx to lower layers: L1CTL-PDCH_ESTABLISH.request
 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
@@ -766,6 +780,7 @@ 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 DEBUG Tx to lower layers: L1CTL-PDCH_ESTABLISH.request
 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
@@ -830,6 +845,7 @@ DLGLOBAL INFO Rx from upper layers: GMMRR-ASSIGN.request
 DLGLOBAL INFO GMMRR-ASSIGN.req: creating new entity TLLI=0x00000001
 DLGLOBAL INFO DL_TBF_ASS{IDLE}: Allocated
 DLGLOBAL DEBUG Rx from lower layers: L1CTL-CCCH_DATA.indication
+DLGLOBAL DEBUG Tx to lower layers: L1CTL-PDCH_ESTABLISH.request
 DLGLOBAL INFO DL_TBF_ASS{IDLE}: Received Event RX_CCCH_IMM_ASS
 DLGLOBAL INFO DL_TBF_ASS{IDLE}: Got PCH IMM_ASS (DL_TBF): DL_TFI=0 TS=7
 DLGLOBAL INFO DL_TBF_ASS{IDLE}: state_chg to COMPLETED
@@ -866,6 +882,7 @@ DLGLOBAL INFO Rx from upper layers: GMMRR-ASSIGN.request
 DLGLOBAL INFO GMMRR-ASSIGN.req: creating new entity TLLI=0x00000001
 DLGLOBAL INFO DL_TBF_ASS{IDLE}: Allocated
 DLGLOBAL DEBUG Rx from lower layers: L1CTL-CCCH_DATA.indication
+DLGLOBAL DEBUG Tx to lower layers: L1CTL-PDCH_ESTABLISH.request
 DLGLOBAL INFO DL_TBF_ASS{IDLE}: Received Event RX_CCCH_IMM_ASS
 DLGLOBAL INFO DL_TBF_ASS{IDLE}: Got PCH IMM_ASS (DL_TBF): DL_TFI=0 TS=7
 DLGLOBAL INFO DL_TBF_ASS{IDLE}: state_chg to COMPLETED
diff --git a/tests/rlcmac/rlcmac_prim_test.ok b/tests/rlcmac/rlcmac_prim_test.ok
index bf3732e..12e5ece 100644
--- a/tests/rlcmac/rlcmac_prim_test.ok
+++ b/tests/rlcmac/rlcmac_prim_test.ok
@@ -1,6 +1,7 @@
 === test_ul_tbf_attach 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-PDCH_ESTABLISH.request
 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 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 ]
@@ -11,21 +12,25 @@ test_rlcmac_prim_down_cb(): Rx L1CTL-CFG_UL_TBF.request ul_tbf_nr=0 ul_slotmask=
 === test_ul_tbf_t3164_timeout start ===
 sys={0.000000}, mono={0.000000}: clock_override_set
 test_rlcmac_prim_down_cb(): Rx L1CTL-RACH.request ra=0x79
+test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_ESTABLISH.request
 test_rlcmac_prim_down_cb(): Rx L1CTL-CFG_UL_TBF.request ul_tbf_nr=0 ul_slotmask=0x80
 sys={5.000000}, mono={5.000000}: clock_override_add
 sys={5.000000}, mono={5.000000}: Expect T3164 timeout
 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_ESTABLISH.request
 test_rlcmac_prim_down_cb(): Rx L1CTL-CFG_UL_TBF.request ul_tbf_nr=0 ul_slotmask=0x80
 sys={10.000000}, mono={10.000000}: clock_override_add
 sys={10.000000}, mono={10.000000}: Expect T3164 timeout
 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=0x79
+test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_ESTABLISH.request
 test_rlcmac_prim_down_cb(): Rx L1CTL-CFG_UL_TBF.request ul_tbf_nr=0 ul_slotmask=0x80
 sys={15.000000}, mono={15.000000}: clock_override_add
 sys={15.000000}, mono={15.000000}: Expect T3164 timeout
 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=0x78
+test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_ESTABLISH.request
 test_rlcmac_prim_down_cb(): Rx L1CTL-CFG_UL_TBF.request ul_tbf_nr=0 ul_slotmask=0x80
 sys={20.000000}, mono={20.000000}: clock_override_add
 sys={20.000000}, mono={20.000000}: Expect T3164 timeout
@@ -34,6 +39,7 @@ test_rlcmac_prim_down_cb(): Rx L1CTL-CFG_UL_TBF.request ul_tbf_nr=0 ul_slotmask=
 === test_ul_tbf_t3166_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-PDCH_ESTABLISH.request
 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 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 ]
@@ -41,18 +47,21 @@ sys={5.000000}, mono={5.000000}: clock_override_add
 sys={5.000000}, mono={5.000000}: Expect T3166 timeout
 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=0x7c
+test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_ESTABLISH.request
 test_rlcmac_prim_down_cb(): Rx L1CTL-CFG_UL_TBF.request ul_tbf_nr=0 ul_slotmask=0x80
 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 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 ]
 sys={10.000000}, mono={10.000000}: clock_override_add
 sys={10.000000}, mono={10.000000}: Expect T3166 timeout
 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=0x79
+test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_ESTABLISH.request
 test_rlcmac_prim_down_cb(): Rx L1CTL-CFG_UL_TBF.request ul_tbf_nr=0 ul_slotmask=0x80
 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 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 ]
 sys={15.000000}, mono={15.000000}: clock_override_add
 sys={15.000000}, mono={15.000000}: Expect T3166 timeout
 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=0x7d
+test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_ESTABLISH.request
 test_rlcmac_prim_down_cb(): Rx L1CTL-CFG_UL_TBF.request ul_tbf_nr=0 ul_slotmask=0x80
 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 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 ]
 sys={20.000000}, mono={20.000000}: clock_override_add
@@ -62,6 +71,7 @@ test_rlcmac_prim_down_cb(): Rx L1CTL-CFG_UL_TBF.request ul_tbf_nr=0 ul_slotmask=
 === 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-PDCH_ESTABLISH.request
 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_up_cb(): Rx GMMRR-LLC_TRANSMITTED.indication TLLI=0x00002342
@@ -91,12 +101,14 @@ RTS 11: FN=56
 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=56 ts=7 data_len=34 data=[00 01 04 3d 00 00 23 42 71 62 f2 24 6c 84 44 04 11 e5 10 00 e2 18 f2 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 00 ]
+test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_ESTABLISH.request
 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_rlcmac_prim_down_cb(): Rx L1CTL-CFG_UL_TBF.request ul_tbf_nr=0 ul_slotmask=0x00
 === test_ul_tbf_t3182_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-PDCH_ESTABLISH.request
 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 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 ]
@@ -108,6 +120,7 @@ test_rlcmac_prim_down_cb(): Rx L1CTL-CFG_UL_TBF.request ul_tbf_nr=0 ul_slotmask=
 === test_ul_tbf_last_data_cv0_retrans_max 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-PDCH_ESTABLISH.request
 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 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 ]
@@ -125,6 +138,7 @@ test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_DATA.request fn=26 ts=7 data_len=34 da
 === 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-PDCH_ESTABLISH.request
 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 ]
@@ -145,6 +159,7 @@ test_rlcmac_prim_down_cb(): Rx L1CTL-CFG_UL_TBF.request ul_tbf_nr=0 ul_slotmask=
 === 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-PDCH_ESTABLISH.request
 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 ]
@@ -154,12 +169,14 @@ test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_DATA.request fn=17 ts=7 data_len=23 da
 test_rlcmac_prim_down_cb(): Rx L1CTL-CFG_UL_TBF.request ul_tbf_nr=1 ul_slotmask=0x00
 === test_dl_tbf_ccch_assign start ===
 sys={0.000000}, mono={0.000000}: clock_override_set
+test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_ESTABLISH.request
 test_rlcmac_prim_down_cb(): Rx L1CTL-CFG_DL_TBF.request dl_tbf_nr=0 dl_slotmask=0x80 dl_tfi=0
 test_rlcmac_prim_up_cb(): Rx GRR-UNITDATA.indication TLLI=0x00000001 ll=[43 c0 01 2b 2b 2b ]
 test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_DATA.request fn=21 ts=7 data_len=23 data=[40 08 10 20 00 00 00 00 00 00 00 20 00 00 03 2b 2b 2b 2b 2b 2b 2b 2b ]
 === test_dl_tbf_ccch_assign end ===
 === test_dl_tbf_ccch_assign_requests_ul_tbf_pacch start ===
 sys={0.000000}, mono={0.000000}: clock_override_set
+test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_ESTABLISH.request
 test_rlcmac_prim_down_cb(): Rx L1CTL-CFG_DL_TBF.request dl_tbf_nr=0 dl_slotmask=0x80 dl_tfi=0
 test_rlcmac_prim_up_cb(): Rx GRR-UNITDATA.indication TLLI=0x00000001 ll=[43 c0 01 2b 2b 2b ]
 test_rlcmac_prim_down_cb(): Rx L1CTL-PDCH_DATA.request fn=21 ts=7 data_len=23 data=[40 08 10 20 00 00 00 00 00 00 00 30 40 00 00 00 00 03 2b 2b 2b 2b 2b ]