<p>laforge <strong>submitted</strong> this change.</p><p><a href="https://gerrit.osmocom.org/c/osmo-ttcn3-hacks/+/18923">View Change</a></p><div style="white-space:pre-wrap">Approvals:
  laforge: Looks good to me, approved
  Jenkins Builder: Verified

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

<div style="display:none"> Gerrit-Project: osmo-ttcn3-hacks </div>
<div style="display:none"> Gerrit-Branch: master </div>
<div style="display:none"> Gerrit-Change-Id: I25e10e28de174337233e6a3bb32cc16f2d7d614e </div>
<div style="display:none"> Gerrit-Change-Number: 18923 </div>
<div style="display:none"> Gerrit-PatchSet: 3 </div>
<div style="display:none"> Gerrit-Owner: fixeria <vyanitskiy@sysmocom.de> </div>
<div style="display:none"> Gerrit-Reviewer: Jenkins Builder </div>
<div style="display:none"> Gerrit-Reviewer: fixeria <vyanitskiy@sysmocom.de> </div>
<div style="display:none"> Gerrit-Reviewer: laforge <laforge@osmocom.org> </div>
<div style="display:none"> Gerrit-Reviewer: neels <nhofmeyr@sysmocom.de> </div>
<div style="display:none"> Gerrit-Reviewer: pespin <pespin@sysmocom.de> </div>
<div style="display:none"> Gerrit-MessageType: merged </div>