tbf: Add check_polling/set_polling

Currently the checks for and the actual polling is done in several
places by copy & paste of several lines of code. This hinders changes
of they polling is handled internally and also is likely source of
programming mistakes.

Separate this into a check_polling function, that checks whether
polling is possible and returns the FN and the RRBP to be used in
that case. Otherwise the cause is logged (LOGL_DEBUG) and a negative
error value is returned. There are no other side effect beside the
logging.

If the call is successful, the set_polling method can be used to
actually register the polling.

Extend the encoder functions' parameters lists by an rrbp parameter.

Sponsored-by: On-Waves ehf

8 files changed, 135 insertions, 77 deletions

diff --git a/src/encoding.cpp b/src/encoding.cpp
index a26a5db..a5e5064 100644
--- a/src/encoding.cpp
+++ b/src/encoding.cpp
@@ -169,7 +169,7 @@ void Encoding::write_packet_uplink_assignment(
 	struct gprs_rlcmac_bts *bts,
 	bitvec * dest, uint8_t old_tfi,
 	uint8_t old_downlink, uint32_t tlli, uint8_t use_tlli,
-	struct gprs_rlcmac_ul_tbf *tbf, uint8_t poll, uint8_t alpha,
+	struct gprs_rlcmac_ul_tbf *tbf, uint8_t poll, uint8_t rrbp, uint8_t alpha,
 	uint8_t gamma, int8_t ta_idx, int8_t use_egprs)
 {
 	// TODO We should use our implementation of encode RLC/MAC Control messages.
@@ -275,8 +275,8 @@ void Encoding::write_packet_uplink_assignment(
 /* generate downlink assignment */
 void Encoding::write_packet_downlink_assignment(RlcMacDownlink_t * block,
 	uint8_t old_tfi, uint8_t old_downlink, struct gprs_rlcmac_tbf *tbf,
-	uint8_t poll, uint8_t alpha, uint8_t gamma, int8_t ta_idx, uint8_t ta_ts,
-	bool use_egprs)
+	uint8_t poll, uint8_t rrbp, uint8_t alpha, uint8_t gamma, int8_t ta_idx,
+	uint8_t ta_ts, bool use_egprs)
 {
 	// Packet downlink assignment TS 44.060 11.2.7
 
@@ -286,7 +286,7 @@ void Encoding::write_packet_downlink_assignment(RlcMacDownlink_t * block,
 	unsigned int ws_enc;
 
 	block->PAYLOAD_TYPE = 0x1;  // RLC/MAC control block that does not include the optional octets of the RLC/MAC control header
-	block->RRBP         = 0x0;  // N+13
+	block->RRBP         = rrbp;  // 0: N+13
 	block->SP           = poll; // RRBP field is valid
 	block->USF          = 0x0;  // Uplink state flag
 
@@ -564,7 +564,8 @@ static void write_packet_uplink_ack_egprs(
 
 void Encoding::write_packet_uplink_ack(
 	struct gprs_rlcmac_bts *bts, bitvec * dest,
-	struct gprs_rlcmac_ul_tbf *tbf, bool is_final)
+	struct gprs_rlcmac_ul_tbf *tbf, bool is_final,
+	uint8_t rrbp)
 {
 	unsigned wp = 0;
 
@@ -572,7 +573,7 @@ void Encoding::write_packet_uplink_ack(
 		"(final=%d)\n", tbf_name(tbf), is_final);
 
 	bitvec_write_field(dest, wp, 0x1, 2);  // Payload Type
-	bitvec_write_field(dest, wp, 0x0, 2);  // Uplink block with TDMA framenumber (N+13)
+	bitvec_write_field(dest, wp, rrbp, 2);  // Uplink block with TDMA framenumber
 	bitvec_write_field(dest, wp, is_final, 1);  // Suppl/Polling Bit
 	bitvec_write_field(dest, wp, 0x0, 3);  // Uplink state flag
 	bitvec_write_field(dest, wp, 0x9, 6);  // MESSAGE TYPE Uplink Ack/Nack
diff --git a/src/encoding.h b/src/encoding.h
index 4c35757..6ee30ac 100644
--- a/src/encoding.h
+++ b/src/encoding.h
@@ -49,21 +49,23 @@ public:
 	static void write_packet_uplink_assignment(
 			struct gprs_rlcmac_bts *bts,
 			bitvec * dest, uint8_t old_tfi,
-			uint8_t old_downlink, uint32_t tlli, uint8_t use_tlli, 
-			struct gprs_rlcmac_ul_tbf *tbf, uint8_t poll, uint8_t alpha,
-			uint8_t gamma, int8_t ta_idx, int8_t use_egprs);
+			uint8_t old_downlink, uint32_t tlli, uint8_t use_tlli,
+			struct gprs_rlcmac_ul_tbf *tbf, uint8_t poll, uint8_t rrbp,
+			uint8_t alpha, uint8_t gamma, int8_t ta_idx,
+			int8_t use_egprs);
 
 	static void write_packet_downlink_assignment(RlcMacDownlink_t * block,
 			uint8_t old_tfi, uint8_t old_downlink,
-			struct gprs_rlcmac_tbf *tbf, uint8_t poll, uint8_t alpha,
-			uint8_t gamma, int8_t ta_idx, uint8_t ta_ts,
-			bool use_egprs);
+			struct gprs_rlcmac_tbf *tbf, uint8_t poll, uint8_t rrbp,
+			uint8_t alpha, uint8_t gamma,
+			int8_t ta_idx, uint8_t ta_ts, bool use_egprs);
 
 	static void encode_rbb(const char *show_rbb, uint8_t *rbb);
 
 	static void write_packet_uplink_ack(
 			struct gprs_rlcmac_bts *bts, bitvec * dest,
-			struct gprs_rlcmac_ul_tbf *tbf, bool is_final);
+			struct gprs_rlcmac_ul_tbf *tbf, bool is_final,
+			uint8_t rrbp);
 
 	static int write_paging_request(bitvec * dest, uint8_t *ptmsi, uint16_t ptmsi_len);
 
diff --git a/src/pcu_vty_functions.cpp b/src/pcu_vty_functions.cpp
index 6567962..3fcd3e6 100644
--- a/src/pcu_vty_functions.cpp
+++ b/src/pcu_vty_functions.cpp
@@ -51,7 +51,8 @@ static void tbf_print_vty_info(struct vty *vty, gprs_rlcmac_tbf *tbf)
 	vty_out(vty, " created=%lu state=%08x 1st_TS=%d 1st_cTS=%d ctrl_TS=%d "
 			"MS_CLASS=%d/%d%s",
 			tbf->created_ts(), tbf->state_flags, tbf->first_ts,
-			tbf->first_common_ts, tbf->control_ts, tbf->ms_class(),
+			tbf->first_common_ts, tbf->control_ts,
+			tbf->ms_class(),
 			tbf->ms() ? tbf->ms()->egprs_ms_class() : -1,
 			VTY_NEWLINE);
 	vty_out(vty, " TS_alloc=");
diff --git a/src/tbf.cpp b/src/tbf.cpp
index 6e51628..1694bbb 100644
--- a/src/tbf.cpp
+++ b/src/tbf.cpp
@@ -435,6 +435,49 @@ void gprs_rlcmac_tbf::stop_timer()
 	}
 }
 
+int gprs_rlcmac_tbf::check_polling(uint32_t fn, uint8_t ts,
+	uint32_t *poll_fn_, unsigned int *rrbp_)
+{
+	uint32_t fn_offs = 13;
+	uint32_t new_poll_fn = (fn + fn_offs) % 2715648;
+
+	if (!is_control_ts(ts)) {
+		LOGP(DRLCMAC, LOGL_DEBUG, "Polling cannot be "
+			"scheduled in this TS %d (first control TS %d)\n",
+			ts, control_ts);
+		return -EINVAL;
+	}
+	if (poll_state != GPRS_RLCMAC_POLL_NONE) {
+		LOGP(DRLCMAC, LOGL_DEBUG,
+			"Polling is already scheduled for %s\n",
+			name());
+		return -EBUSY;
+	}
+	if (bts->sba()->find(trx->trx_no, ts, (fn + 13) % 2715648)) {
+		LOGP(DRLCMAC, LOGL_DEBUG, "%s: Polling is already scheduled "
+			"for single block allocation at FN %d TS %d ...\n",
+			name(), new_poll_fn, ts);
+		return -EBUSY;
+	}
+
+	*poll_fn_ = new_poll_fn;
+	*rrbp_ = 0;
+
+	return 0;
+}
+
+void gprs_rlcmac_tbf::set_polling(uint32_t new_poll_fn, uint8_t ts)
+{
+	LOGP(DRLCMAC, LOGL_DEBUG,
+		"%s: Scheduling polling at FN %d TS %d\n",
+		name(), new_poll_fn, ts);
+
+	/* schedule polling */
+	poll_state = GPRS_RLCMAC_POLL_SCHED;
+	poll_fn = new_poll_fn;
+	poll_ts = ts;
+}
+
 void gprs_rlcmac_tbf::poll_timeout()
 {
 	LOGP(DRLCMAC, LOGL_NOTICE, "%s poll timeout for FN=%d, TS=%d (curr FN %d)\n",
@@ -861,6 +904,9 @@ struct msgb *gprs_rlcmac_tbf::create_dl_ass(uint32_t fn, uint8_t ts)
 	struct msgb *msg;
 	struct gprs_rlcmac_dl_tbf *new_dl_tbf = NULL;
 	int poll_ass_dl = 1;
+	unsigned int rrbp = 0;
+	uint32_t new_poll_fn = 0;
+	int rc;
 
 	if (direction == GPRS_RLCMAC_DL_TBF && !is_control_ts(ts)) {
 		LOGP(DRLCMAC, LOGL_NOTICE, "Cannot poll for downlink "
@@ -870,17 +916,17 @@ struct msgb *gprs_rlcmac_tbf::create_dl_ass(uint32_t fn, uint8_t ts)
 		poll_ass_dl = 0;
 	}
 	if (poll_ass_dl) {
-		if (poll_state != GPRS_RLCMAC_POLL_NONE) {
-			LOGP(DRLCMAC, LOGL_DEBUG, "Polling is already sheduled "
-				"for %s, so we must wait for downlink "
-				"assignment...\n", tbf_name(this));
-				return NULL;
-		}
-		if (bts->sba()->find(trx->trx_no, ts, (fn + 13) % 2715648)) {
+		if (poll_state == GPRS_RLCMAC_POLL_SCHED &&
+			ul_ass_state == GPRS_RLCMAC_UL_ASS_WAIT_ACK)
+		{
 			LOGP(DRLCMACUL, LOGL_DEBUG, "Polling is already "
-				"scheduled for single block allocation...\n");
+				"scheduled for %s, so we must wait for the uplink "
+				"assignment...\n", tbf_name(this));
 			return NULL;
 		}
+		rc = check_polling(fn, ts, &new_poll_fn, &rrbp);
+		if (rc < 0)
+			return NULL;
 	}
 
 	/* on uplink TBF we get the downlink TBF to be assigned. */
@@ -923,7 +969,7 @@ struct msgb *gprs_rlcmac_tbf::create_dl_ass(uint32_t fn, uint8_t ts)
 	RlcMacDownlink_t * mac_control_block = (RlcMacDownlink_t *)talloc_zero(tall_pcu_ctx, RlcMacDownlink_t);
 	Encoding::write_packet_downlink_assignment(mac_control_block, m_tfi,
 		(direction == GPRS_RLCMAC_DL_TBF), new_dl_tbf,
-		poll_ass_dl, bts_data()->alpha, bts_data()->gamma, -1, 0,
+		poll_ass_dl, rrbp, bts_data()->alpha, bts_data()->gamma, -1, 0,
 		is_egprs_enabled());
 	LOGP(DRLCMAC, LOGL_DEBUG, "+++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++\n");
 	encode_gsm_rlcmac_downlink(ass_vec, mac_control_block);
@@ -934,9 +980,7 @@ struct msgb *gprs_rlcmac_tbf::create_dl_ass(uint32_t fn, uint8_t ts)
 	talloc_free(mac_control_block);
 
 	if (poll_ass_dl) {
-		poll_state = GPRS_RLCMAC_POLL_SCHED;
-		poll_fn = (fn + 13) % 2715648;
-		poll_ts = ts;
+		set_polling(new_poll_fn, ts);
 		dl_ass_state = GPRS_RLCMAC_DL_ASS_WAIT_ACK;
 		LOGP(DRLCMACDL, LOGL_INFO,
 			"%s Scheduled DL Assignment polling on FN=%d, TS=%d\n",
@@ -957,18 +1001,21 @@ struct msgb *gprs_rlcmac_tbf::create_ul_ass(uint32_t fn, uint8_t ts)
 {
 	struct msgb *msg;
 	struct gprs_rlcmac_ul_tbf *new_tbf = NULL;
+	int rc;
+	unsigned int rrbp;
+	uint32_t new_poll_fn;
 
-	if (poll_state != GPRS_RLCMAC_POLL_NONE) {
+	if (poll_state == GPRS_RLCMAC_POLL_SCHED &&
+		ul_ass_state == GPRS_RLCMAC_UL_ASS_WAIT_ACK) {
 		LOGP(DRLCMACUL, LOGL_DEBUG, "Polling is already "
-			"sheduled for %s, so we must wait for uplink "
+			"scheduled for %s, so we must wait for the uplink "
 			"assignment...\n", tbf_name(this));
 			return NULL;
 	}
-	if (bts->sba()->find(trx->trx_no, ts, (fn + 13) % 2715648)) {
-		LOGP(DRLCMACUL, LOGL_DEBUG, "Polling is already scheduled for "
-			"single block allocation...\n");
-			return NULL;
-	}
+
+	rc = check_polling(fn, ts, &new_poll_fn, &rrbp);
+	if (rc < 0)
+		return NULL;
 
 	if (ms())
 		new_tbf = ms()->ul_tbf();
@@ -993,7 +1040,7 @@ struct msgb *gprs_rlcmac_tbf::create_ul_ass(uint32_t fn, uint8_t ts)
 		"2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b");
 	Encoding::write_packet_uplink_assignment(bts_data(), ass_vec, m_tfi,
 		(direction == GPRS_RLCMAC_DL_TBF), tlli(),
-		is_tlli_valid(), new_tbf, 1, bts_data()->alpha,
+		is_tlli_valid(), new_tbf, 1, rrbp, bts_data()->alpha,
 		bts_data()->gamma, -1, is_egprs_enabled());
 	bitvec_pack(ass_vec, msgb_put(msg, 23));
 	RlcMacDownlink_t * mac_control_block = (RlcMacDownlink_t *)talloc_zero(tall_pcu_ctx, RlcMacDownlink_t);
@@ -1004,9 +1051,7 @@ struct msgb *gprs_rlcmac_tbf::create_ul_ass(uint32_t fn, uint8_t ts)
 	bitvec_free(ass_vec);
 	talloc_free(mac_control_block);
 
-	poll_state = GPRS_RLCMAC_POLL_SCHED;
-	poll_fn = (fn + 13) % 2715648;
-	poll_ts = ts;
+	set_polling(new_poll_fn, ts);
 	ul_ass_state = GPRS_RLCMAC_UL_ASS_WAIT_ACK;
 	LOGP(DRLCMACDL, LOGL_INFO,
 		"%s Scheduled UL Assignment polling on FN=%d, TS=%d\n",
diff --git a/src/tbf.h b/src/tbf.h
index d23cf93..edb8280 100644
--- a/src/tbf.h
+++ b/src/tbf.h
@@ -119,6 +119,9 @@ struct gprs_rlcmac_tbf {
 	void stop_t3191();
 	int establish_dl_tbf_on_pacch();
 
+	int check_polling(uint32_t fn, uint8_t ts,
+		uint32_t *poll_fn, unsigned int *rrbp);
+	void set_polling(uint32_t poll_fn, uint8_t ts);
 	void poll_timeout();
 
 	/** tlli handling */
diff --git a/src/tbf_dl.cpp b/src/tbf_dl.cpp
index 10b376f..03f0cc4 100644
--- a/src/tbf_dl.cpp
+++ b/src/tbf_dl.cpp
@@ -527,6 +527,9 @@ struct msgb *gprs_rlcmac_dl_tbf::create_dl_acked_block(
 	bool need_poll;
 	/* TODO: support MCS-7 - MCS-9, where data_block_idx can be 1 */
 	unsigned int data_block_idx = 0;
+	unsigned int rrbp;
+	uint32_t new_poll_fn;
+	int rc;
 
 	gprs_rlc_data_info rlc;
 	GprsCodingScheme cs;
@@ -570,32 +573,18 @@ struct msgb *gprs_rlcmac_dl_tbf::create_dl_acked_block(
 				"polling, because %d blocks sent.\n",
 				POLL_ACK_AFTER_FRAMES);
 		}
-		/* scheduling not possible, because: */
-		if (poll_state != GPRS_RLCMAC_POLL_NONE)
-			LOGP(DRLCMACDL, LOGL_DEBUG, "Polling is already "
-				"sheduled for %s, so we must wait for "
-				"requesting downlink ack\n", tbf_name(this));
-		else if (!is_control_ts(ts))
-			LOGP(DRLCMACDL, LOGL_DEBUG, "Polling cannot be "
-				"sheduled in this TS %d, waiting for "
-				"TS %d\n", ts, control_ts);
-		else if (bts->sba()->find(trx->trx_no, ts, (fn + 13) % 2715648))
-			LOGP(DRLCMACDL, LOGL_DEBUG, "Polling cannot be "
-				"sheduled, because single block alllocation "
-				"already exists\n");
-		else  {
-			LOGP(DRLCMACDL, LOGL_DEBUG, "Polling sheduled in this "
+
+		rc = check_polling(fn, ts, &new_poll_fn, &rrbp);
+		if (rc >= 0) {
+			set_polling(new_poll_fn, ts);
+
+			LOGP(DRLCMACDL, LOGL_DEBUG, "Polling scheduled in this "
 				"TS %d\n", ts);
 			m_tx_counter = 0;
 			/* start timer whenever we send the final block */
 			if (rdbi->cv == 0)
 				tbf_timer_start(this, 3191, bts_data()->t3191, 0);
 
-			/* schedule polling */
-			poll_state = GPRS_RLCMAC_POLL_SCHED;
-			poll_fn = (fn + 13) % 2715648;
-			poll_ts = ts;
-
 			/* Clear poll timeout flag */
 			state_flags &= ~(1 << GPRS_RLCMAC_FLAG_TO_DL_ACK);
 
@@ -603,7 +592,7 @@ struct msgb *gprs_rlcmac_dl_tbf::create_dl_acked_block(
 			m_dl_ack_requested = false;
 
 			/* set polling in header */
-			rlc.rrbp = 0; /* N+13 */
+			rlc.rrbp = rrbp;
 			rlc.es_p = 1; /* Polling */
 
 			m_last_dl_poll_fn = poll_fn;
diff --git a/src/tbf_ul.cpp b/src/tbf_ul.cpp
index 4754e11..9e763f4 100644
--- a/src/tbf_ul.cpp
+++ b/src/tbf_ul.cpp
@@ -91,19 +91,22 @@ struct msgb *gprs_rlcmac_ul_tbf::create_ul_ack(uint32_t fn, uint8_t ts)
 {
 	int final = (state_is(GPRS_RLCMAC_FINISHED));
 	struct msgb *msg;
+	int rc;
+	unsigned int rrbp = 0;
+	uint32_t new_poll_fn = 0;
 
 	if (final) {
-		if (poll_state != GPRS_RLCMAC_POLL_NONE) {
+		if (poll_state == GPRS_RLCMAC_POLL_SCHED &&
+			ul_ack_state == GPRS_RLCMAC_UL_ACK_WAIT_ACK) {
 			LOGP(DRLCMACUL, LOGL_DEBUG, "Polling is already "
-				"sheduled for %s, so we must wait for "
-				"final uplink ack...\n", tbf_name(this));
+				"scheduled for %s, so we must wait for "
+				"the final uplink ack...\n", tbf_name(this));
 			return NULL;
 		}
-		if (bts->sba()->find(trx->trx_no, ts, (fn + 13) % 2715648)) {
-			LOGP(DRLCMACUL, LOGL_DEBUG, "Polling is already "
-				"scheduled for single block allocation...\n");
+
+		rc = check_polling(fn, ts, &new_poll_fn, &rrbp);
+		if (rc < 0)
 			return NULL;
-		}
 	}
 
 	msg = msgb_alloc(23, "rlcmac_ul_ack");
@@ -116,7 +119,7 @@ struct msgb *gprs_rlcmac_ul_tbf::create_ul_ack(uint32_t fn, uint8_t ts)
 	}
 	bitvec_unhex(ack_vec,
 		"2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b2b");
-	Encoding::write_packet_uplink_ack(bts_data(), ack_vec, this, final);
+	Encoding::write_packet_uplink_ack(bts_data(), ack_vec, this, final, rrbp);
 	bitvec_pack(ack_vec, msgb_put(msg, 23));
 	bitvec_free(ack_vec);
 
@@ -125,9 +128,7 @@ struct msgb *gprs_rlcmac_ul_tbf::create_ul_ack(uint32_t fn, uint8_t ts)
 	m_contention_resolution_done = 1;
 
 	if (final) {
-		poll_state = GPRS_RLCMAC_POLL_SCHED;
-		poll_fn = (fn + 13) % 2715648;
-		poll_ts = ts;
+		set_polling(new_poll_fn, ts);
 		/* waiting for final acknowledge */
 		ul_ack_state = GPRS_RLCMAC_UL_ACK_WAIT_ACK;
 		m_final_ack_sent = 1;
diff --git a/tests/tbf/TbfTest.err b/tests/tbf/TbfTest.err
index 80f3f85..177a5b5 100644
--- a/tests/tbf/TbfTest.err
+++ b/tests/tbf/TbfTest.err
@@ -61,6 +61,7 @@ TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FLOW) append
 TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FLOW)  start Packet Downlink Assignment (PACCH)
 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++
 ------------------------- TX : Packet Downlink Assignment -------------------------
+TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FLOW): Scheduling polling at FN 13 TS 4
 TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FLOW) Scheduled DL Assignment polling on FN=13, TS=4
 Scheduling control message at RTS for TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FLOW) (TRX=0, TS=4)
 Sending data request: trx=0 ts=4 sapi=5 arfcn=0 fn=0 block=0 data=4f 08 20 00 44 02 00 02 08 04 00 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 
@@ -142,6 +143,7 @@ TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FLOW) append
 TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FLOW)  start Packet Downlink Assignment (PACCH)
 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++
 ------------------------- TX : Packet Downlink Assignment -------------------------
+TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FLOW): Scheduling polling at FN 13 TS 4
 TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FLOW) Scheduled DL Assignment polling on FN=13, TS=4
 Scheduling control message at RTS for TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FLOW) (TRX=0, TS=4)
 Sending data request: trx=0 ts=4 sapi=5 arfcn=0 fn=0 block=0 data=4f 08 20 00 44 02 00 02 08 04 00 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 
@@ -223,6 +225,7 @@ TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FLOW) append
 TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FLOW)  start Packet Downlink Assignment (PACCH)
 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++
 ------------------------- TX : Packet Downlink Assignment -------------------------
+TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FLOW): Scheduling polling at FN 13 TS 4
 TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FLOW) Scheduled DL Assignment polling on FN=13, TS=4
 Scheduling control message at RTS for TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FLOW) (TRX=0, TS=4)
 Sending data request: trx=0 ts=4 sapi=5 arfcn=0 fn=0 block=0 data=4f 08 20 00 44 02 00 02 08 04 00 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 
@@ -382,7 +385,7 @@ Complete DL frame for TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FLOW)len=200
 Complete DL frame for TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FLOW)len=16
 data block (BSN 20, CS-1): 0a 41 c6 c7 43 c0 01 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 
 - Scheduling Ack/Nack polling, because is was requested explicitly (e.g. first final block sent).
-Polling is already sheduled for TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FLOW), so we must wait for requesting downlink ack
+Polling is already scheduled for TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FLOW)
 msg block (BSN 20, CS-1): 07 00 28 0a 41 c6 c7 43 c0 01 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 
 Sending data request: trx=0 ts=4 sapi=5 arfcn=0 fn=91 block=9 data=07 00 28 0a 41 c6 c7 43 c0 01 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 
 TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FLOW) downlink acknowledge
@@ -419,7 +422,7 @@ TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FLOW) downlink (V(A)==21 .. V(S)==21)
 Complete DL frame for TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FLOW)len=19
 data block (BSN 21, CS-1): 4d 43 c0 01 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 
 - Scheduling Ack/Nack polling, because is was requested explicitly (e.g. first final block sent).
-Polling is already sheduled for TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FLOW), so we must wait for requesting downlink ack
+Polling is already scheduled for TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FLOW)
 msg block (BSN 21, CS-1): 07 00 2a 4d 43 c0 01 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 
 Sending data request: trx=0 ts=4 sapi=5 arfcn=0 fn=95 block=10 data=07 00 2a 4d 43 c0 01 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 
 TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FLOW) downlink acknowledge
@@ -437,7 +440,7 @@ Complete DL frame for TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FLOW)len=19
 TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FLOW) changes state from FLOW to FINISHED
 data block (BSN 22, CS-1): 4d 43 c0 01 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 
 - Scheduling Ack/Nack polling, because is was requested explicitly (e.g. first final block sent).
-Polling is already sheduled for TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FINISHED), so we must wait for requesting downlink ack
+Polling is already scheduled for TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FINISHED)
 msg block (BSN 22, CS-1): 07 01 2c 4d 43 c0 01 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 
 Sending data request: trx=0 ts=4 sapi=5 arfcn=0 fn=203 block=11 data=07 01 2c 4d 43 c0 01 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 
 TBF(TFI=0 TLLI=0xffeeddcc DIR=DL STATE=FINISHED) downlink acknowledge
@@ -1433,7 +1436,7 @@ Complete DL frame for TBF(TFI=0 TLLI=0xc0123456 DIR=DL STATE=ASSIGN)len=19
 TBF(TFI=0 TLLI=0xc0123456 DIR=DL STATE=ASSIGN) changes state from ASSIGN to FINISHED
 data block (BSN 2, CS-1): 4d 03 03 03 03 03 03 03 03 03 03 03 03 03 03 03 03 03 03 03 
 - Scheduling Ack/Nack polling, because is was requested explicitly (e.g. first final block sent).
-Polling cannot be sheduled in this TS 7, waiting for TS 4
+Polling cannot be scheduled in this TS 7 (first control TS 4)
 msg block (BSN 2, CS-1): 07 01 04 4d 03 03 03 03 03 03 03 03 03 03 03 03 03 03 03 03 03 03 03 
 MSG = 07 01 04 4d 03 03 03 03 03 03 03 03 03 03 03 03 03 03 03 03 03 03 03 
 Searching for first unallocated TFI: TRX=0
@@ -1549,6 +1552,7 @@ Change control TS to 7 until assinment is complete.
 TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=ASSIGN)s start Packet Uplink Assignment (PACCH)
 +++++++++++++++++++++++++ TX : Packet Uplink Assignment +++++++++++++++++++++++++
 ------------------------- TX : Packet Uplink Assignment -------------------------
+TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=ASSIGN): Scheduling polling at FN 2654283 TS 7
 TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=ASSIGN) Scheduled UL Assignment polling on FN=2654283, TS=7
 Scheduling control message at RTS for TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=ASSIGN) (TRX=0, TS=7)
 Sending data request: trx=0 ts=7 sapi=5 arfcn=0 fn=2654270 block=8 data=4f 28 5e 24 46 68 8f 1d 00 00 88 00 08 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 
@@ -1633,6 +1637,7 @@ Change control TS to 7 until assinment is complete.
 TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=ASSIGN)s start Packet Uplink Assignment (PACCH)
 +++++++++++++++++++++++++ TX : Packet Uplink Assignment +++++++++++++++++++++++++
 ------------------------- TX : Packet Uplink Assignment -------------------------
+TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=ASSIGN): Scheduling polling at FN 2654283 TS 7
 TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=ASSIGN) Scheduled UL Assignment polling on FN=2654283, TS=7
 Scheduling control message at RTS for TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=ASSIGN) (TRX=0, TS=7)
 Sending data request: trx=0 ts=7 sapi=5 arfcn=0 fn=2654270 block=8 data=4f 28 5e 24 46 68 8f 1d 00 00 88 00 08 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 
@@ -1683,6 +1688,7 @@ Received RTS for PDCH: TRX=0 TS=7 FN=2654275 block_nr=9 scheduling USF=0 for req
 TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=ASSIGN)  start Packet Downlink Assignment (PACCH)
 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++
 ------------------------- TX : Packet Downlink Assignment -------------------------
+TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=FLOW): Scheduling polling at FN 2654288 TS 7
 TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=FLOW) Scheduled DL Assignment polling on FN=2654288, TS=7
 Scheduling control message at RTS for TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=FLOW) (TRX=0, TS=7)
 Sending data request: trx=0 ts=7 sapi=5 arfcn=0 fn=2654275 block=9 data=48 08 00 00 0c 72 00 02 08 00 80 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 
@@ -1711,7 +1717,8 @@ Complete DL frame for TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=FLOW)len=10
 TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=FLOW) changes state from FLOW to FINISHED
 data block (BSN 0, CS-4): 29 52 41 55 5f 41 43 43 45 50 54 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 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 
 - Scheduling Ack/Nack polling, because is was requested explicitly (e.g. first final block sent).
-Polling sheduled in this TS 7
+TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=FINISHED): Scheduling polling at FN 2654292 TS 7
+Polling scheduled in this TS 7
 TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=FINISHED) starting timer 3191.
 TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=FINISHED) Scheduled Ack/Nack polling on FN=2654292, TS=7
 msg block (BSN 0, CS-4): 0f 01 00 29 52 41 55 5f 41 43 43 45 50 54 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 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 00 
@@ -1765,6 +1772,7 @@ Received RTS for PDCH: TRX=0 TS=7 FN=2654335 block_nr=11 scheduling USF=0 for re
 TBF(TFI=1 TLLI=0xf5667788 DIR=UL STATE=ASSIGN)s start Packet Uplink Assignment (PACCH)
 +++++++++++++++++++++++++ TX : Packet Uplink Assignment +++++++++++++++++++++++++
 ------------------------- TX : Packet Uplink Assignment -------------------------
+TBF(TFI=1 TLLI=0xf5667788 DIR=UL STATE=ASSIGN): Scheduling polling at FN 2654348 TS 7
 TBF(TFI=1 TLLI=0xf5667788 DIR=UL STATE=ASSIGN) Scheduled UL Assignment polling on FN=2654348, TS=7
 Scheduling control message at RTS for TBF(TFI=1 TLLI=0xf5667788 DIR=UL STATE=ASSIGN) (TRX=0, TS=7)
 Sending data request: trx=0 ts=7 sapi=5 arfcn=0 fn=2654335 block=11 data=48 28 5e ac ce f1 0f 1d 00 00 88 40 09 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 
@@ -1835,6 +1843,7 @@ Change control TS to 7 until assinment is complete.
 TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=ASSIGN)s start Packet Uplink Assignment (PACCH)
 +++++++++++++++++++++++++ TX : Packet Uplink Assignment +++++++++++++++++++++++++
 ------------------------- TX : Packet Uplink Assignment -------------------------
+TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=ASSIGN): Scheduling polling at FN 2654283 TS 7
 TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=ASSIGN) Scheduled UL Assignment polling on FN=2654283, TS=7
 Scheduling control message at RTS for TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=ASSIGN) (TRX=0, TS=7)
 Sending data request: trx=0 ts=7 sapi=5 arfcn=0 fn=2654270 block=8 data=4f 28 5e 24 46 68 83 1d 00 00 88 00 08 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 
@@ -1930,6 +1939,7 @@ Change control TS to 7 until assinment is complete.
 TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=ASSIGN)s start Packet Uplink Assignment (PACCH)
 +++++++++++++++++++++++++ TX : Packet Uplink Assignment +++++++++++++++++++++++++
 ------------------------- TX : Packet Uplink Assignment -------------------------
+TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=ASSIGN): Scheduling polling at FN 2654340 TS 7
 TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=ASSIGN) Scheduled UL Assignment polling on FN=2654340, TS=7
 Scheduling control message at RTS for TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=ASSIGN) (TRX=0, TS=7)
 Sending data request: trx=0 ts=7 sapi=5 arfcn=0 fn=2654327 block=9 data=4f 28 5e 24 46 68 83 1d 00 00 88 00 08 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 
@@ -2010,6 +2020,7 @@ Change control TS to 7 until assinment is complete.
 TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=ASSIGN)s start Packet Uplink Assignment (PACCH)
 +++++++++++++++++++++++++ TX : Packet Uplink Assignment +++++++++++++++++++++++++
 ------------------------- TX : Packet Uplink Assignment -------------------------
+TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=ASSIGN): Scheduling polling at FN 2654283 TS 7
 TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=ASSIGN) Scheduled UL Assignment polling on FN=2654283, TS=7
 Scheduling control message at RTS for TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=ASSIGN) (TRX=0, TS=7)
 Sending data request: trx=0 ts=7 sapi=5 arfcn=0 fn=2654270 block=8 data=4f 28 5e 24 46 68 83 1d 00 00 88 00 08 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 
@@ -2163,6 +2174,7 @@ Change control TS to 7 until assinment is complete.
 TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=ASSIGN)s start Packet Uplink Assignment (PACCH)
 +++++++++++++++++++++++++ TX : Packet Uplink Assignment +++++++++++++++++++++++++
 ------------------------- TX : Packet Uplink Assignment -------------------------
+TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=ASSIGN): Scheduling polling at FN 2654283 TS 7
 TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=ASSIGN) Scheduled UL Assignment polling on FN=2654283, TS=7
 Scheduling control message at RTS for TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=ASSIGN) (TRX=0, TS=7)
 Sending data request: trx=0 ts=7 sapi=5 arfcn=0 fn=2654270 block=8 data=4f 28 5e 24 46 68 83 1d 00 00 88 00 08 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 
@@ -2252,6 +2264,7 @@ Received RTS for PDCH: TRX=0 TS=7 FN=2654275 block_nr=9 scheduling USF=0 for req
 TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=ASSIGN)  start Packet Downlink Assignment (PACCH)
 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++
 ------------------------- TX : Packet Downlink Assignment -------------------------
+TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=FLOW): Scheduling polling at FN 2654288 TS 7
 TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=FLOW) Scheduled DL Assignment polling on FN=2654288, TS=7
 Scheduling control message at RTS for TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=FLOW) (TRX=0, TS=7)
 Sending data request: trx=0 ts=7 sapi=5 arfcn=0 fn=2654275 block=9 data=48 08 00 00 0c 72 00 02 08 00 80 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 
@@ -2667,7 +2680,8 @@ Complete DL frame for TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=FLOW)len=13
 - Dequeue next LLC for TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=FLOW) (len=13)
 data block (BSN 20, CS-1): 16 35 45 54 20 32 38 4c 4c 43 20 50 41 43 4b 45 54 20 32 39 
 - Scheduling Ack/Nack polling, because 20 blocks sent.
-Polling sheduled in this TS 7
+TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=FLOW): Scheduling polling at FN 2654379 TS 7
+Polling scheduled in this TS 7
 TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=FLOW) Scheduled Ack/Nack polling on FN=2654379, TS=7
 msg block (BSN 20, CS-1): 0f 00 28 16 35 45 54 20 32 38 4c 4c 43 20 50 41 43 4b 45 54 20 32 39 
 Sending data request: trx=0 ts=7 sapi=5 arfcn=0 fn=2654366 block=6 data=08 00 28 16 35 45 54 20 32 38 4c 4c 43 20 50 41 43 4b 45 54 20 32 39 
@@ -2805,7 +2819,7 @@ Complete DL frame for TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=FLOW)len=13
 TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=FLOW) changes state from FLOW to FINISHED
 data block (BSN 27, CS-1): 16 35 45 54 20 33 38 4c 4c 43 20 50 41 43 4b 45 54 20 33 39 
 - Scheduling Ack/Nack polling, because is was requested explicitly (e.g. first final block sent).
-Polling is already sheduled for TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=FINISHED), so we must wait for requesting downlink ack
+Polling is already scheduled for TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=FINISHED)
 msg block (BSN 27, CS-1): 07 01 36 16 35 45 54 20 33 38 4c 4c 43 20 50 41 43 4b 45 54 20 33 39 
 Sending data request: trx=0 ts=7 sapi=5 arfcn=0 fn=2654396 block=1 data=00 01 36 16 35 45 54 20 33 38 4c 4c 43 20 50 41 43 4b 45 54 20 33 39 
 TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=FINISHED) append
@@ -2881,6 +2895,7 @@ Received RTS for PDCH: TRX=0 TS=7 FN=2654400 block_nr=2 scheduling USF=0 for req
 TBF(TFI=1 TLLI=0xf1223344 DIR=DL STATE=ASSIGN)  start Packet Downlink Assignment (PACCH)
 +++++++++++++++++++++++++ TX : Packet Downlink Assignment +++++++++++++++++++++++++
 ------------------------- TX : Packet Downlink Assignment -------------------------
+TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=WAIT RELEASE): Scheduling polling at FN 2654413 TS 7
 TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=WAIT RELEASE) Scheduled DL Assignment polling on FN=2654413, TS=7
 Scheduling control message at RTS for TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=WAIT RELEASE) (TRX=0, TS=7)
 Sending data request: trx=0 ts=7 sapi=5 arfcn=0 fn=2654400 block=2 data=48 08 20 08 0c 72 00 02 18 00 80 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 
@@ -3092,7 +3107,8 @@ Complete DL frame for TBF(TFI=1 TLLI=0xf1223344 DIR=DL STATE=FLOW)len=21
 TBF(TFI=1 TLLI=0xf1223344 DIR=DL STATE=FLOW) changes state from FLOW to FINISHED
 data block (BSN 10, CS-1): 4d 43 20 50 41 43 4b 45 54 20 30 39 20 28 54 42 46 20 32 29 
 - Scheduling Ack/Nack polling, because is was requested explicitly (e.g. first final block sent).
-Polling sheduled in this TS 7
+TBF(TFI=1 TLLI=0xf1223344 DIR=DL STATE=FINISHED): Scheduling polling at FN 2654461 TS 7
+Polling scheduled in this TS 7
 TBF(TFI=1 TLLI=0xf1223344 DIR=DL STATE=FINISHED) starting timer 3191.
 TBF(TFI=1 TLLI=0xf1223344 DIR=DL STATE=FINISHED) Scheduled Ack/Nack polling on FN=2654461, TS=7
 msg block (BSN 10, CS-1): 0f 03 14 4d 43 20 50 41 43 4b 45 54 20 30 39 20 28 54 42 46 20 32 29