Cellular Network Infrastructure » Core Network (CN) » OsmoSGSN

Tests actually pass fine (setverdict(pass) is called at the end of the test), but during test shutdown something goes wrong inside TTCN3:

10:58:20.370911 11 - Function f_M3UA_Emulation was stopped. PTC terminates.
10:58:20.370918 4 - Removing unterminated connection between port BSCP and SGSN_Test-Gb0-NS0(3):NS_SP.
10:58:20.370951 4 - Port BSCP was stopped.
10:58:20.370969 4 - Port BSSGP_SP was stopped.
10:58:20.370976 4 - Port BSSGP_SP_SIG was stopped.
10:58:20.370977 5 - Terminating component type NS_Emulation.NS_CT.
10:58:20.370977 7 - Terminating component type NS_Emulation.NS_CT.
10:58:20.370981 4 - Port BSSGP_PROC was stopped.
10:58:20.370987 11 - Terminating component type M3UA_Emulation.M3UA_CT.
10:58:20.370987 4 - Component type BSSGP_Emulation.BSSGP_CT was shut down inside testcase TC_attach.
10:58:20.371003 11 - Stop timer T_Timer: 2 s
10:58:20.371005 4 - Final verdict of PTC: none
10:58:20.371016 11 - Removing unterminated connection between port MTP3_SP_PORT and SGSN_Test_0-SCCP(9):MTP3_SCCP_PORT.
10:58:20.371018 5 - Default with id 1 (altstep as_allstate) was deactivated.
10:58:20.371018 7 - Default with id 1 (altstep as_allstate) was deactivated.
10:58:20.371037 5 - Stop timer Tns_test: 10 s
10:58:20.371040 7 - Stop timer Tns_test: 10 s
10:58:20.371051 5 - Removing unterminated mapping between port NSCP and system:NS_CODEC_PORT.
10:58:20.371051 7 - Removing unterminated mapping between port NSCP and system:NS_CODEC_PORT.
10:58:20.371062 4 - Disconnected from MC.
10:58:20.371079 4 - TTCN-3 Parallel Test Component finished.
10:58:20.371087 11 - Message with id 1 was extracted from the queue of MTP3_SP_PORT.
10:58:20.371110 11 - Port MTP3_SP_PORT was stopped.
10:58:20.371126 11 - Removing unterminated mapping between port SCTP_PORT and system:sctp.
10:58:20.371155 11 - Dynamic test case error: Fd_And_Timeout_User::remove_all_fds Internal error 4: fdCount: 1
10:58:20.371175 3 - Function NSStart was stopped. PTC terminates.
10:58:20.371182 11 - setverdict(error): none -> error
10:58:20.371199 11 - Performing error recovery.

Commit introducing the error: osmo-ttcn3-hacks 26fbb6e0171f3dfe8019ff0e31129b8ee592daf7 ("sgsn: Integrate RANAP")

Related TTCN3 code seems to be here: https://github.com/eclipse/titan.core/blob/master/core/Snapshot.cc#L797

Not sure how to fix it. Looks like an internal TTCN3 error with some fd (from an SCTP socket in this case) being faulty?

Similar issue seems to have happened here: http://osmocom.org/issues/3816

It seems TTCN3 is actually crashing. It cannot be seen on the log file, but it shows up in stdout (docker):

MTC@fc78fc7bc964: Connecting RANAP RAN_Emulation to SCCP_SP_PORT
MTC@fc78fc7bc964: Starting RAN_Emulation
SGSN_Test_0-M3UA(11)@fc78fc7bc964: *************************************************
SGSN_Test_0-M3UA(11)@fc78fc7bc964: M3UA emulation initiated, the test can be started
SGSN_Test_0-M3UA(11)@fc78fc7bc964: *************************************************
SGSN_Test-Gb2-BSSGP2(8)@fc78fc7bc964: BSSGP State Transition: BVC_S_BLOCKED (0) -> BVC_S_UNBLOCKED (1)
SGSN_Test_0-SCCP(9)@fc78fc7bc964: v_sccp_pdu_maxlen:268
SGSN_Test_0-M3UA(11)@fc78fc7bc964: Warning: The maximum number of open file descriptors (1048576) is greater than FD_SETSIZE (1024). Ensure that Test Ports using Install_Handler do not try to wait for events of file descriptors with values greater than FD_SETSIZE (1024). (Current caller of Install_Handler is "SCTP_PORT")
SGSN_Test-GSUP-IPA(12)@fc78fc7bc964: IPA: Connected
SGSN_Test-GSUP-IPA(12)@fc78fc7bc964: CCM Tx:{ msg_type := IPAC_MSGT_ID_GET (4), u := { get := { { len := 1, tag := IPAC_IDTAG_UNITNAME (1) } } } }
SGSN_Test-GSUP-IPA(12)@fc78fc7bc964: CCM Rx:{ msg_type := IPAC_MSGT_PING (0), u := omit }
SGSN_Test-GSUP-IPA(12)@fc78fc7bc964: CCM Tx:{ msg_type := IPAC_MSGT_PONG (1), u := omit }
SGSN_Test-GSUP-IPA(12)@fc78fc7bc964: CCM Rx:{ msg_type := IPAC_MSGT_ID_RESP (5), u := { resp := { { len := 24, tag := IPAC_IDTAG_UNITNAME (1), data := '5347534E2D30302D30302D30302D30302D30302D303000'O } } } }
SGSN_Test-GSUP-IPA(12)@fc78fc7bc964: IPA ID RESP: { { len := 24, tag := IPAC_IDTAG_UNITNAME (1), data := '5347534E2D30302D30302D30302D30302D30302D303000'O } }
SGSN_Test-GSUP-IPA(12)@fc78fc7bc964: CCM Tx:{ msg_type := IPAC_MSGT_ID_ACK (6), u := omit }
SGSN_Test-GSUP-IPA(12)@fc78fc7bc964: CCM Rx:{ msg_type := IPAC_MSGT_ID_ACK (6), u := omit }
SGSN_Test-Gb0-BSSGP0(4)@fc78fc7bc964: Adding Client=TC_attach(15), IMSI='262420000000001'H, TLLI='E1AD38CD'O, index=0
SGSN_Test-GSUP(13)@fc78fc7bc964: Created GsupExpect[0] for "262420000000001" to be handled at TC_attach(15)
TC_attach(15)@fc78fc7bc964: GSUP sends only 2G auth tuple{ tag := OSMO_GSUP_AUTH_TUPLE_IE (3), len := 0, val := { auth_tuple := { { tag := OSMO_GSUP_RAND_IE (32), len := 0, val := { rand := 'AB07A397CEB61A78A7EB262C3DC8C535'O } }, { tag := OSMO_GSUP_SRES_IE (33), len := 0, val := { sres := '31DC2171'O } }, { tag := OSMO_GSUP_KC_IE (34), len := 0, val := { kc := 'FC3E29FEC5706869'O } } } } }
SGSN_Test-GSUP(13)@fc78fc7bc964: Found GsupExpect[0] for "262420000000001" handled at TC_attach(15)
SGSN_Test-GSUP(13)@fc78fc7bc964: Added IMSI table entry 0TC_attach(15)"262420000000001" 
SGSN_Test-Gb0-BSSGP0(4)@fc78fc7bc964: Removing Client IMSI='262420000000001'H, index=0
SGSN_Test_0-M3UA(11)@fc78fc7bc964: Dynamic test case error: Fd_And_Timeout_User::remove_all_fds Internal error 4: fdCount: 1
SGSN_Test_0-M3UA(11)@fc78fc7bc964: Dynamic test case error: Fd_And_Timeout_User::remove_all_fds Internal error 4: fdCount: 1
SGSN_Test_0-M3UA(11)@fc78fc7bc964: Dynamic test case error: Fd_And_Timeout_User::remove_all_fds Internal error 4: fdCount: 1
MC@fc78fc7bc964: Unexpected message KILLED was received from PTC 11.
MC@fc78fc7bc964: Unexpected end of PTC connection (11) from fc78fc7bc964 [172.18.8.103].
terminate called after throwing an instance of 'TC_Error'
 /osmo-ttcn3-hacks/sgsn/SGSN_Tests: Abort was called
/usr/lib/titan/libttcn3-parallel-dynamic.so(_Z14signal_handleri+0xa3)[0x7fb857a4d2d3]
/lib/x86_64-linux-gnu/libc.so.6(+0x33060)[0x7fb855e14060]
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0xcf)[0x7fb855e13fff]
/lib/x86_64-linux-gnu/libc.so.6(abort+0x16a)[0x7fb855e1542a]
/usr/lib/x86_64-linux-gnu/libstdc++.so.6(_ZN9__gnu_cxx27__verbose_terminate_handlerEv+0x15d)[0x7fb85672c0ad]
/usr/lib/x86_64-linux-gnu/libstdc++.so.6(+0x8f066)[0x7fb85672a066]
/usr/lib/x86_64-linux-gnu/libstdc++.so.6(+0x8e089)[0x7fb856729089]
/usr/lib/x86_64-linux-gnu/libstdc++.so.6(__gxx_personality_v0+0x2cd)[0x7fb8567299dd]
/lib/x86_64-linux-gnu/libgcc_s.so.1(+0xff33)[0x7fb85618ff33]
/lib/x86_64-linux-gnu/libgcc_s.so.1(_Unwind_RaiseException+0xfb)[0x7fb85619029b]
/usr/lib/x86_64-linux-gnu/libstdc++.so.6(__cxa_throw+0x5c)[0x7fb85672a2bc]
/usr/lib/titan/libttcn3-parallel-dynamic.so(_Z10TTCN_errorPKcz+0x1af)[0x7fb8579d606f]
/usr/lib/titan/libttcn3-parallel-dynamic.so(_ZN19Fd_And_Timeout_User14remove_all_fdsEP28Fd_And_Timeout_Event_Handler+0x3af)[0x7fb857a100bf]
/usr/lib/titan/libttcn3-parallel-dynamic.so(_ZN4PORT15deactivate_portEb+0x144)[0x7fb857a07524]
/usr/lib/titan/libttcn3-parallel-dynamic.so(_ZN4PORTD1Ev+0x1f)[0x7fb857a075ff]
/osmo-ttcn3-hacks/sgsn/SCTPasp_PT.so(_ZN17SCTPasp__PortType20SCTPasp__PT_PROVIDERD1Ev+0xbc)[0x7fb8580c1d3c]
/osmo-ttcn3-hacks/sgsn/SCTPasp_PortType.so(_ZN17SCTPasp__PortType11SCTPasp__PTD1Ev+0x36)[0x7fb869b3be3e]
/lib/x86_64-linux-gnu/libc.so.6(__cxa_finalize+0x8f)[0x7fb855e16caf]
/osmo-ttcn3-hacks/sgsn/M3UA_Emulation.so(+0x25483)[0x7fb8817f7483]
MTC@fc78fc7bc964: Test case TC_attach finished. Verdict: error
MTC@fc78fc7bc964: Starting external command `../ttcn3-tcpdump-stop.sh SGSN_Tests.TC_attach error'.
Mon Aug 19 13:59:27 UTC 2019
------ SGSN_Tests.TC_attach error ------

cherry-picking https://gerrit.osmocom.org/c/docker-playground/+/15155 (starting stp in ttcn3-sgsn tests) seems to fix the issue. Still it looks like a bug in TTCN3 M3UA module (opening tons of fds when SCTP INIT is aborted on the other side?).

I'll merge the docker-playground patch above.

Lowering the priority of the ticket and re-assigning to laforge , he may have a better clue on where the issue in TTCN3 may be located.

I attach a pcap file of a faulty test to show what happens on the SCTP side.

After merging the docker-playground patch above (starting stp in ttcn3-sgsn-tests), some tests still fail due to stp/sgsn not answering the RESET sent by TTCN3 code.

It seems changing osmo-sgsn.cfg just merged to "cs7 instance 1" instead of "cs7 instance 0" helps there. lynxis seems to want to change it in libosmo-sccp:
https://gerrit.osmocom.org/c/libosmo-sccp/+/15062

So far I'm switching only osmo-sgsn to use 0:
https://gerrit.osmocom.org/c/osmo-sgsn/+/15236 sgsn: use sccp_simple_client API to setup ss7 id 0 instead of 1

Feel free to revert or change if you don't like the solution.

I'm also removing the SGSN_Tests_IU.control line introduced by merging the docker-playground test withut related osmo-ttcn3-hacks tests being merged:
https://gerrit.osmocom.org/c/docker-playground/+/15237 ttcn3-sgsn: Disable not-yet available SGSN_Tests_Iu tests

Fixed ttcn3-sgsn-latest too:
https://gerrit.osmocom.org/c/docker-playground/+/15240 Fix ttcn3-sgsn-latest (cs7 instance override)

Fixed, closing ticket.