Project

General

Profile

Bug #4039

library/TRXC_CodecPort.ttcn: f_TRXC_transceive() fails to match TRXC response from FakeTRX

Added by Hoernchen 22 days ago. Updated 21 days ago.

Status:
Resolved
Priority:
High
Assignee:
Target version:
-
Start date:
06/03/2019
Due date:
% Done:

100%


Description

Trying to send a FAKE_RSSI command after sending any other command (i.e. FAKE_TOA which is implicitly sent in many tests) results in a receive timeout waiting for the RSP FAKE_TRX. This doesn't happen all the time, more like 4 out of 5 attempts, it sometimes succeeds. According to Wireshark the response is sent.
In the failling case the last two lines in the TTCN3 logs are:

15:05:46.406396 mtc TRXC_CodecPort.ttcn:36 dec_TrxcMessage(): Decoded @TRXC_Types.TrxcMessage: {
15:05:46.406419 mtc BTS_Tests.ttcn:1975 Incoming message was mapped to @TRXC_CodecPort.TRXC_RecvFrom : {

History

#1 Updated by fixeria 21 days ago

  • Project changed from OsmocomBB SDR PHY to Core testing infrastructure
  • Subject changed from fake_trx only works once in ttcn3 tests to library/TRXC_CodecPort.ttcn: f_TRXC_transceive() fails to match TRXC response from FakeTRX
  • Assignee changed from fixeria to laforge

I doubt it's a bug of FakeTRX. You can use ctrl_cmd.py to send as many FAKE_* TRXC commands as you wish, and they all will be confirmed. Moreover, if that was a problem of FakeTRX, OsmoBTS wouldn't work reliable, but it does.

I guess the problem is somewhere in our TTCN-3 implementation of the TRXC interface. If you add some logging to IPL4_to_TRXC_RecvFrom() and f_TRXC_transceive(), and then call the last one several times, you will see that the first command is confirmed in the most cases, but then ~4/5 times the following ones fail due to timeout.

An example of three subsequent successful commands:

TC_ho_rach(7)@DELL: Tx TRXC: { cmd := { verb := "FAKE_RSSI", params := { "-54", "0" } } }
TC_ho_rach(7)@DELL: Rx TRXC message: "RSP FAKE_RSSI 0 -54 0" & char(0, 0, 0, 0)
TC_ho_rach(7)@DELL: Warning: dec_TrxcMessage(): Data remained at the end of the stream after successful decoding: '00'O

TC_ho_rach(7)@DELL: Tx TRXC: { cmd := { verb := "FAKE_RSSI", params := { "-55", "0" } } }
TC_ho_rach(7)@DELL: Rx TRXC message: "RSP FAKE_RSSI 0 -55 0" & char(0, 0, 0, 0)
TC_ho_rach(7)@DELL: Warning: dec_TrxcMessage(): Data remained at the end of the stream after successful decoding: '00'O

TC_ho_rach(7)@DELL: Tx TRXC: { cmd := { verb := "FAKE_RSSI", params := { "-56", "0" } } }
TC_ho_rach(7)@DELL: Rx TRXC message: "RSP FAKE_RSSI 0 -56 0" & char(0, 0, 0, 0)
TC_ho_rach(7)@DELL: Warning: dec_TrxcMessage(): Data remained at the end of the stream after successful decoding: '00'O

An example of failed command:

TC_ho_rach(7)@DELL: Tx TRXC: { cmd := { verb := "FAKE_RSSI", params := { "-57", "0" } } }
MTC@DELL: dec_TrxcMessage(): Stream before decoding: "RSP FAKE_RSSI 0 -57 0" & char(0, 0, 0, 0)

...

MTC@DELL: dec_TrxcMessage(): Decoded @TRXC_Types.TrxcMessage: { rsp := { verb := "FAKE_RSSI", status := 0, params := { "-57", "0" } } }
MTC@DELL: Warning: dec_TrxcMessage(): Data remained at the end of the stream after successful decoding: '00'O

#2 Updated by laforge 21 days ago

I would appreciate if somebody could push a test case to a branch which reliably
(as possible) reproduces the issue. It should "pass" if all responses are received,
and fail if not.

Ideally the test case uses as little dependencies as possible, i.e. just deriving from
the TRXC_CodecPort.

I will then take a look and try to further debug this. Thanks!

#3 Updated by laforge 21 days ago

Actually, I believe the problem is quite obvious:

Both the test_CT and the ConnHdlr have a TRXC port, as depending on the test
one would want to globally control it from test_CT or from within a ConnHdlr.

The respective calls to TRXC_CodecPort_CtrlFunct.f_IPL4_connect are in

private function f_trxc_connect() runs on ConnHdlr
which is called always (if we have a TRXC control port) from f_handler_init()
private function f_main_trxc_connect() runs on test_CT
which is called always (if we have a TRXC control port) from f_init()

However, only one of the two should be active (connected) at any given point in
time. Otherwise we'll have two UDP sockets on the same port, and it's more or less
random on which of them it ends up.

@Hoernchen, would you care to try changin the code to ensure only one of the two
is connected? For example, the 'pars' could be extended with a 'hdlr_uses_trxc'
boolean variable, whihc would control if f_trxc_connect() is called from f_handler_init()
or not. But for sure there are other options.

#4 Updated by fixeria 21 days ago

  • Status changed from New to In Progress
  • Assignee changed from laforge to fixeria
  • % Done changed from 0 to 90

Thanks to Harald for extremely useful notes. Please see:

https://gerrit.osmocom.org/c/osmo-ttcn3-hacks/+/14370

#5 Updated by fixeria 21 days ago

  • Status changed from In Progress to Resolved
  • % Done changed from 90 to 100

Merged.

Also available in: Atom PDF

Add picture from clipboard (Maximum size: 48.8 MB)