From e9c0635dae253c4d1d7837c3b577008671e30052 Mon Sep 17 00:00:00 2001 From: Vadim Yanitskiy Date: Sat, 20 Jun 2020 01:30:58 +0700 Subject: library/RSL_Emulation: implement waiting queue for DChan messages Since change [1] has been merged, we see multiple regressions in ttcn3-bsc-test (all LCLS test cases) and ttcn3-bsc-test-sccplite (sporadic failures). In all failed cases, the reason is similar: RSL for unknown Dchan BSC_Tests.ttcn:4501 BSC_Tests control part BSC_Tests.ttcn:2176 TC_assignment_codec_fr testcase The mentioned change enables TCP_NODELAY option for all IPA based connections, including both OML and RSL. This option disables Nagle's algorithm [2], so we get less delays on IPA based links. It took me a lot of time to investigate, and finally, I figured out what is actually causing those regressions. The TCP_NODELAY itself is not a problem, of course. As it turned out, the problem is here, in our TTCN-3 test case framework. Each test case involves several components (actors) running in parallel. One of them is RSL_Emulation_CT, which is responsible for handling and routing of RSL messages between the connected components. A test case may register dedicated channel handlers by calling f_rslem_register(), so DCHAN/RLL/IPACCESS messages will be matched by RslChannelNr/TrxNr and routed to the corresponding one. If no handler is found for a given RSL message, the RSL_Emulation_CT would abort the test case execution. And that's where the problem is. Given that all components are running in parallel, it may happen that a received RSL message would be processed by the RSL emulation component faster than the test case would call f_rslem_register(). The test case would be aborted due to "RSL for unknown Dchan". Speaking in context of the failing BSC test cases, a test case calls f_rslem_register() on receipt of an Assignment Command as it contains all the assignment parameters. After that we expect to receive an RSL ip.access CRCX for that channel. The problem is that both Assignment Command and ip.access CRCX messages are sent by the BSC simultaneously, so the later may be handled faster than the first one. Race condition! Let's work this around by maintaining a waiting queue, where the messages, for which no handler was found, will be kept until the corresponding dedicated channel is registered. This is an optional feature that needs to be enabled explicitly by calling f_rslem_dchan_queue_enable(), and then explicitly disabled by calling f_rslem_dchan_queue_disable(). If at the moment of calling f_rslem_dchan_queue_disable() the waiting queue is not empty, e.g. because the IUT sent us more messages than we expected, test execution will be terminated. The actial fix for the LCLS test cases will be submitted next. [1] Ia3d4c41bf0659e682f0b7ae5f3d58ed0f28edb58 [2] https://en.wikipedia.org/wiki/Nagle%27s_algorithm Change-Id: I25e10e28de174337233e6a3bb32cc16f2d7d614e Related: OS#4619 --- library/RSL_Emulation.ttcn | 76 +++++++++++++++++++++++++++++++++++++++++++++- 1 file changed, 75 insertions(+), 1 deletion(-) diff --git a/library/RSL_Emulation.ttcn b/library/RSL_Emulation.ttcn index 9cc77ba0..41c689f3 100644 --- a/library/RSL_Emulation.ttcn +++ b/library/RSL_Emulation.ttcn @@ -103,10 +103,13 @@ type port RSL_CCHAN_PT message { signature RSLEM_register(uint8_t trx_nr, RslChannelNr chan_nr, RSL_DchanHdlr hdlr); signature RSLEM_unregister(uint8_t trx_nr, RslChannelNr chan_nr, RSL_DchanHdlr hdlr); signature RSLEM_suspend(boolean suspend); +signature RSLEM_wait_queue(boolean enable); signature RSLEM_get_last_act(in uint8_t trx_nr, in RslChannelNr chan_nr, out RSL_Message chan_act); type port RSLEM_PROC_PT procedure { - inout RSLEM_register, RSLEM_unregister, RSLEM_suspend, RSLEM_get_last_act; + inout RSLEM_register, RSLEM_unregister, + RSLEM_suspend, RSLEM_wait_queue, + RSLEM_get_last_act; } with { extension "internal" }; /*********************************************************************** @@ -415,6 +418,8 @@ runs on RSL_Emulation_CT { testcase.stop("Failed to patch IPA stream ID in ASP RSL UD: ", ud); } +private type record of ASP_RSL_Unitdata ASP_RSL_UDList; + type component RSL_Emulation_CT { /* port facing down towards IPA emulation */ port IPA_RSL_PT IPA_PT; @@ -428,6 +433,9 @@ type component RSL_Emulation_CT { /* state of all concurrent connections / dedicated channels */ var ConnectionData ConnectionTable[64]; + /* RSL messages for which no handler is currently registered */ + var ASP_RSL_UDList WaitingQueue := { }; + /* last RSL CHAN ACT for each chan_nr */ var LastActData LastActTable[64]; @@ -466,6 +474,10 @@ function main(boolean bts_role := true) runs on RSL_Emulation_CT { var integer i; /* special synchronization handling during hand-over */ var boolean dchan_suspended := false; + /* Whether to keep RSL messages, for which no handler is found in ConnectionTable, + * in a queue. These messages will remain in the queue until the appropriate + * connection handler is registered. */ + var boolean wait_queue_enabled := false; f_conn_table_init(); f_trx_conn_map_init(); @@ -584,6 +596,9 @@ function main(boolean bts_role := true) runs on RSL_Emulation_CT { rx_rsl.rsl.ies[0].body.chan_nr); if (cid != -1) { CLIENT_PT.send(rx_rsl.rsl) to ConnectionTable[cid].comp_ref; + } else if (wait_queue_enabled) { + log("Storing an RSL message in the waiting queue"); + WaitingQueue := WaitingQueue & { rx_rsl }; } else { setverdict(fail, "RSL for unknown Dchan"); mtc.stop; @@ -650,6 +665,26 @@ function main(boolean bts_role := true) runs on RSL_Emulation_CT { RSL_PROC.reply(RSLEM_suspend:{false}) to vc_conn; } + [not wait_queue_enabled] RSL_PROC.getcall(RSLEM_wait_queue:{true}) -> sender vc_conn { + wait_queue_enabled := true; + log("Enabled queueing of DChan messages"); + RSL_PROC.reply(RSLEM_wait_queue:{wait_queue_enabled}) to vc_conn; + } + + [wait_queue_enabled] RSL_PROC.getcall(RSLEM_wait_queue:{false}) -> sender vc_conn { + /* Dispatch stalled messages (if any) */ + f_WaitingQueue_dispatch(); + + wait_queue_enabled := false; + log("Disabled queueing of DChan messages"); + RSL_PROC.reply(RSLEM_wait_queue:{wait_queue_enabled}) to vc_conn; + } + + [] RSL_PROC.getcall(RSLEM_wait_queue:{?}) -> sender vc_conn { + log("Queueing of DChan messages is already enabled/disabled"); + RSL_PROC.reply(RSLEM_wait_queue:{wait_queue_enabled}) to vc_conn; + } + [] RSL_PROC.getcall(RSLEM_get_last_act:{?,?,?}) -> param(trx_nr, chan_nr) sender vc_conn { var RSL_Message last_chan_act := f_lookup_last_act(trx_nr, chan_nr); RSL_PROC.reply(RSLEM_get_last_act:{trx_nr, chan_nr, last_chan_act}) to vc_conn; @@ -668,6 +703,27 @@ runs on RSL_Emulation_CT { } } +private function f_WaitingQueue_dispatch() +runs on RSL_Emulation_CT { + var integer cid; + + for (var integer i := 0; i < lengthof(WaitingQueue); i := i + 1) { + cid := f_cid_by_chan_nr(f_trx_by_streamId(WaitingQueue[i].streamId), + WaitingQueue[i].rsl.ies[0].body.chan_nr); + if (cid == -1) { + setverdict(fail, "No Dchan handler found for: ", WaitingQueue[i]); + mtc.stop; + break; + } + + /* Dispatch a stalled message to the appropriate handler */ + CLIENT_PT.send(WaitingQueue[i].rsl) to ConnectionTable[cid].comp_ref; + } + + /* All messages dispatched, clear the queue */ + WaitingQueue := { }; +} + /* client/conn_hdlr side function to use procedure port to register stream_id/chan_nr */ function f_rslem_register(uint8_t trx_nr, RslChannelNr chan_nr, RSLEM_PROC_PT PT := RSL_PROC) runs on RSL_DchanHdlr { @@ -700,6 +756,24 @@ runs on RSL_DchanHdlr { } } +/* Enable queueing of RSL DChan messages from IPA until f_rslem_dchan_queue_disable() is called. */ +function f_rslem_dchan_queue_enable(RSLEM_PROC_PT PT := RSL_PROC) +runs on RSL_DchanHdlr { + PT.call(RSLEM_wait_queue:{true}) { + [] PT.getreply(RSLEM_wait_queue:{true}) {}; + } +} + +/* Disable queueing of RSL DChan messages after f_rslem_dchan_queue_enable() is called. + * Dispatch all stalled messages to the registered handlers. Make sure that no + * messages for which there is no handler are left in the queue (mtc.stop if so). */ +function f_rslem_dchan_queue_dispatch(RSLEM_PROC_PT PT := RSL_PROC) +runs on RSL_DchanHdlr { + PT.call(RSLEM_wait_queue:{false}) { + [] PT.getreply(RSLEM_wait_queue:{false}) {}; + } +} + /* obtain the last RSL_CHAN_ACT message for the given chan_nr */ function f_rslem_get_last_act(RSLEM_PROC_PT PT, uint8_t trx_nr, RslChannelNr chan_nr) runs on RSL_DchanHdlr return RSL_Message { -- cgit v1.2.3