Project

General

Profile

Actions

Bug #4003

closed

msc crashes with sigsegv on "sh subscriber msisdn xxxxx" via vty

Added by roh almost 5 years ago. Updated almost 5 years ago.

Status:
Resolved
Priority:
High
Assignee:
Category:
-
Target version:
-
Start date:
05/15/2019
Due date:
% Done:

100%

Resolution:
Spec Reference:

Description

version 1.3.1.108.d24c from -nightlsy on debian

steps to reproduce: run a network with sysmobts and one c118 subscriber attached and do "sh subscriber extension 23841" on msc repeatedly

ussd *#100# fails after restarting msc. retry multiple times (usually ~2 fail, third goes through.)
while doing ussd, connect to msc:
telnet localhost 4254
en
sh subscriber extension 23841
% No subscriber found for extension 23841
OsmoMSC# sh subscriber extension 23841
% No subscriber found for extension 23841
OsmoMSC# sh subscriber extension 23841
<segfault>

first sh sub. on msc fails with "% No subscriber found for msisdn 23841"
*#100# fails with 'operation fail' on mobile and gives this output on msc console:

<0010> ran_peer.c:243 ran_peer(GERAN-A:RI-SSN_PC:PC-0-23-3:SSN-BSSAP)[0x55555595ab60]{WAIT_RX_RESET}: Receiving CO message on RAN peer that has not done a proper RESET yet. Disconnecting on incoming message, sending RESET to RAN peer.
<0020> sccp_scoc.c:1677 SCCP-SCOC(0)[0x5555559593c0]{DISCONN_PEND}: Event RCOC-DT1.ind not permitted

second *#100# on mobile - same error on mobile
<000e> fsm.c:423 Process_Access_Request_VLR(TMSI-0x5247688F:GERAN-A-1:CM_SERVICE_REQ)[0x55555595c4b0]{PR_ARQ_S_INIT}: Allocated
<000e> fsm.c:453 Process_Access_Request_VLR(TMSI-0x5247688F:GERAN-A-1:CM_SERVICE_REQ)[0x55555595c4b0]{PR_ARQ_S_INIT}: is child of msc_a(TMSI-0x5247688F:GERAN-A-1:CM_SERVICE_REQ)[0x555555958f00]
<000e> vlr_access_req_fsm.c:675 Process_Access_Request_VLR(TMSI-0x5247688F:GERAN-A-1:CM_SERVICE_REQ)[0x55555595c4b0]{PR_ARQ_S_INIT}: rev=GSM net=GERAN Auth (no Ciph)
<000e> vlr_access_req_fsm.c:699 Process_Access_Request_VLR(TMSI-0x5247688F:GERAN-A-1:CM_SERVICE_REQ)[0x55555595c4b0]{PR_ARQ_S_INIT}: Received Event PR_ARQ_E_START
<000e> vlr_access_req_fsm.c:402 Process_Access_Request_VLR(TMSI-0x5247688F:GERAN-A-1:CM_SERVICE_REQ)[0x55555595c4b0]{PR_ARQ_S_INIT}: proc_arq_fsm_done(IMSI_UNKNOWN_IN_VLR)
<000e> vlr_access_req_fsm.c:103 Process_Access_Request_VLR(TMSI-0x5247688F:GERAN-A-1:CM_SERVICE_REQ)[0x55555595c4b0]{PR_ARQ_S_INIT}: State change to PR_ARQ_S_DONE (no timeout)
<000e> vlr_access_req_fsm.c:112 Process_Access_Request_VLR(TMSI-0x5247688F:GERAN-A-1:CM_SERVICE_REQ)[0x55555595c4b0]{PR_ARQ_S_DONE}: Process Access Request result: IMSI_UNKNOWN_IN_VLR
<0010> gsm_04_08.c:805 msc_a(TMSI-0x5247688F:GERAN-A-1:CM_SERVICE_REQ)[0x555555958f00]{MSC_A_ST_RELEASING}: subscriber not allowed to do a CM Service Request
<0010> msc_a.c:1525 msc_a(TMSI-0x5247688F:GERAN-A-1:CM_SERVICE_REQ)[0x555555958f00]{MSC_A_ST_RELEASING}: RAN decode error (rc=-5) for COMPL_L3 from MSC-I
<000e> msc_a.c:806 Process_Access_Request_VLR(TMSI-0x5247688F:GERAN-A-1:CM_SERVICE_REQ)[0x55555595c4b0]{PR_ARQ_S_DONE}: Terminating in cascade, depth 2 (cause = OSMO_FSM_TERM_PARENT, caused by: msc_a(TMSI-0x5247688F:GERAN-A-1:CM_SERVICE_REQ)[0x555555958f00])
<000e> msc_a.c:806 Process_Access_Request_VLR(TMSI-0x5247688F:GERAN-A-1:CM_SERVICE_REQ)[0x55555595c4b0]{PR_ARQ_S_DONE}: Removing from parent msc_a(TMSI-0x5247688F:GERAN-A-1:CM_SERVICE_REQ)[0x555555958f00]
<000e> fsm.c:514 Process_Access_Request_VLR(TMSI-0x5247688F:GERAN-A-1:CM_SERVICE_REQ)[0x55555595c4b0]{PR_ARQ_S_DONE}: Deferring: will deallocate with msc_a(TMSI-0x5247688F:GERAN-A-1:CM_SERVICE_REQ)[0x555555958f00]

some delay
<000e> fsm.c:423 vlr_lu_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595c4b0]{VLR_ULA_S_IDLE}: Allocated
<000e> fsm.c:453 vlr_lu_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595c4b0]{VLR_ULA_S_IDLE}: is child of msc_a(IMSI-901700000023841:GERAN-A-2:LU)[0x555555958f00]
<000e> vlr_lu_fsm.c:1476 vlr_lu_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595c4b0]{VLR_ULA_S_IDLE}: rev=GSM net=GERAN Auth (no Ciph)
<000e> vlr_lu_fsm.c:1482 vlr_lu_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595c4b0]{VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA
<000e> vlr.c:435 set IMSI on subscriber; IMSI=901700000023841 id=901700000023841
<000e> vlr.c:386 New subscr, IMSI: 901700000023841
<000e> vlr_lu_fsm.c:909 vlr_lu_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595c4b0]{VLR_ULA_S_IDLE}: vlr_loc_upd_node1()
<000e> vlr_lu_fsm.c:916 vlr_lu_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595c4b0]{VLR_ULA_S_IDLE}: State change to VLR_ULA_S_WAIT_AUTH (T0, 30s)
<000e> fsm.c:423 VLR_Authenticate(IMSI-901700000023841:GERAN-A-2:LU)[0x555555959940]{VLR_SUB_AS_NEEDS_AUTH}: Allocated
<000e> fsm.c:453 VLR_Authenticate(IMSI-901700000023841:GERAN-A-2:LU)[0x555555959940]{VLR_SUB_AS_NEEDS_AUTH}: is child of vlr_lu_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595c4b0]
<000e> vlr_auth_fsm.c:628 VLR_Authenticate(IMSI-901700000023841:GERAN-A-2:LU)[0x555555959940]{VLR_SUB_AS_NEEDS_AUTH}: Received Event VLR_AUTH_E_START
<000e> vlr_auth_fsm.c:318 VLR_Authenticate(IMSI-901700000023841:GERAN-A-2:LU)[0x555555959940]{VLR_SUB_AS_NEEDS_AUTH}: State change to VLR_SUB_AS_NEEDS_AUTH_WAIT_AI (T0, 30s)
<0005> ran_peer.c:105 ran_peer(GERAN-A:RI-SSN_PC:PC-0-23-3:SSN-BSSAP)[0x55555595ab60]{READY}: Added seen cell to this RAN peer: CGI:901-70-1-0
<000e> vlr.c:752 VLR_Authenticate(IMSI-901700000023841:GERAN-A-2:LU)[0x555555959940]{VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: Received Event VLR_AUTH_E_HLR_SAI_ACK
<000e> vlr.c:732 SUBSCR(IMSI-901700000023841) Received 5 auth tuples
<000e> vlr_auth_fsm.c:374 VLR_Authenticate(IMSI-901700000023841:GERAN-A-2:LU)[0x555555959940]{VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: State change to VLR_SUB_AS_WAIT_RESP (no timeout)
<000e> vlr_auth_fsm.c:286 VLR_Authenticate(IMSI-901700000023841:GERAN-A-2:LU)[0x555555959940]{VLR_SUB_AS_WAIT_RESP}: got auth tuple: use_count=1 key_seq=0 -- will use GSM AKA (is_r99=no, at->vec.auth_types=0x3)
<000e> vlr.c:1323 VLR_Authenticate(IMSI-901700000023841:GERAN-A-2:LU)[0x555555959940]{VLR_SUB_AS_WAIT_RESP}: Received Event VLR_AUTH_E_MS_AUTH_RESP
<000e> vlr_auth_fsm.c:136 SUBSCR(IMSI-901700000023841) AUTH on GERAN received SRES/RES: 09aaf6d3 (4 bytes)
<000e> vlr_auth_fsm.c:208 SUBSCR(IMSI-901700000023841) AUTH established GSM security context
<000e> vlr_auth_fsm.c:244 VLR_Authenticate(IMSI-901700000023841:GERAN-A-2:LU)[0x555555959940]{VLR_SUB_AS_WAIT_RESP}: Authentication terminating with result PASSED
<000e> vlr_auth_fsm.c:248 VLR_Authenticate(IMSI-901700000023841:GERAN-A-2:LU)[0x555555959940]{VLR_SUB_AS_WAIT_RESP}: State change to VLR_SUB_AS_AUTHENTICATED (no timeout)
<000e> vlr_auth_fsm.c:253 VLR_Authenticate(IMSI-901700000023841:GERAN-A-2:LU)[0x555555959940]{VLR_SUB_AS_AUTHENTICATED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
<000e> vlr_auth_fsm.c:253 VLR_Authenticate(IMSI-901700000023841:GERAN-A-2:LU)[0x555555959940]{VLR_SUB_AS_AUTHENTICATED}: Removing from parent vlr_lu_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595c4b0]
<000e> vlr_auth_fsm.c:253 vlr_lu_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595c4b0]{VLR_ULA_S_WAIT_AUTH}: Received Event VLR_ULA_E_AUTH_RES
<000e> vlr_lu_fsm.c:863 vlr_lu_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595c4b0]{VLR_ULA_S_WAIT_AUTH}: vlr_loc_upd_post_auth()
<000e> vlr_lu_fsm.c:830 vlr_lu_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595c4b0]{VLR_ULA_S_WAIT_AUTH}: vlr_loc_upd_post_ciph()
<000e> vlr_lu_fsm.c:791 vlr_lu_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595c4b0]{VLR_ULA_S_WAIT_AUTH}: vlr_loc_upd_node_4()
<000e> vlr_lu_fsm.c:800 vlr_lu_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595c4b0]{VLR_ULA_S_WAIT_AUTH}: State change to VLR_ULA_S_WAIT_HLR_UPD (T0, 30s)
<000e> fsm.c:423 upd_hlr_vlr_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595a7e0]{UPD_HLR_VLR_S_INIT}: Allocated
<000e> fsm.c:453 upd_hlr_vlr_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595a7e0]{UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595c4b0]
<000e> vlr_lu_fsm.c:176 upd_hlr_vlr_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595a7e0]{UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START
<000e> vlr_lu_fsm.c:87 upd_hlr_vlr_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595a7e0]{UPD_HLR_VLR_S_INIT}: State change to UPD_HLR_VLR_S_WAIT_FOR_DATA (T0, 30s)
<000e> fsm.c:535 VLR_Authenticate(IMSI-901700000023841:GERAN-A-2:LU)[0x555555959940]{VLR_SUB_AS_AUTHENTICATED}: Deallocated
<000e> vlr.c:775 IMSI:901700000023841 has MSISDN:23841
<000e> gsm_04_08.c:1364 SUBSCR(IMSI-901700000023841:MSISDN-23841) VLR: update for IMSI=901700000023841 (MSISDN=23841)
<000e> vlr.c:876 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-2:LU)[0x55555595c4b0]{VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES
<000e> vlr_lu_fsm.c:1186 upd_hlr_vlr_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595a7e0]{UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK
<000e> vlr_lu_fsm.c:109 upd_hlr_vlr_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595a7e0]{UPD_HLR_VLR_S_WAIT_FOR_DATA}: State change to UPD_HLR_VLR_S_DONE (no timeout)
<000e> vlr_lu_fsm.c:110 upd_hlr_vlr_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595a7e0]{UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
<000e> vlr_lu_fsm.c:110 upd_hlr_vlr_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595a7e0]{UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-2:LU)[0x55555595c4b0]
<000e> vlr_lu_fsm.c:110 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-2:LU)[0x55555595c4b0]{VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL
<000e> vlr_lu_fsm.c:1194 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-2:LU)[0x55555595c4b0]{VLR_ULA_S_WAIT_HLR_UPD}: State change to VLR_ULA_S_WAIT_LU_COMPL (T0, 30s)
<000e> fsm.c:423 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-2:LU)[0x555555959940]{LU_COMPL_VLR_S_INIT}: Allocated
<000e> fsm.c:453 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-2:LU)[0x555555959940]{LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-2:LU)[0x55555595c4b0]
<000e> vlr_lu_fsm.c:773 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-2:LU)[0x555555959940]{LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START
<000e> vlr_lu_fsm.c:418 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-2:LU)[0x555555959940]{LU_COMPL_VLR_S_INIT}: State change to LU_COMPL_VLR_S_WAIT_SUB_PRES (T0, 30s)
<000e> vlr_lu_fsm.c:425 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-2:LU)[0x555555959940]{LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL
<000e> vlr_lu_fsm.c:434 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-2:LU)[0x555555959940]{LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi()
<000e> gsm_04_08.c:1364 SUBSCR(IMSI-901700000023841:MSISDN-23841:TMSInew-0x54096394) VLR: update for IMSI=901700000023841 (MSISDN=23841)
<000e> vlr_lu_fsm.c:443 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-2:LU)[0x555555959940]{LU_COMPL_VLR_S_WAIT_SUB_PRES}: State change to LU_COMPL_VLR_S_WAIT_TMSI_CNF (no timeout)
<000e> fsm.c:535 upd_hlr_vlr_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595a7e0]{UPD_HLR_VLR_S_DONE}: Deallocated
<000e> vlr.c:1185 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSInew-0x54096394:GERAN-A-2:LU)[0x55555595c4b0]{VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK
<000e> vlr_lu_fsm.c:1228 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-2:LU)[0x555555959940]{LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK
<000e> gsm_04_08.c:1364 SUBSCR(IMSI-901700000023841:MSISDN-23841:TMSI-0x54096394) VLR: update for IMSI=901700000023841 (MSISDN=23841)
<000e> vlr_lu_fsm.c:353 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-2:LU)[0x555555959940]{LU_COMPL_VLR_S_WAIT_TMSI_CNF}: State change to LU_COMPL_VLR_S_DONE (no timeout)
<000e> vlr_lu_fsm.c:388 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x54096394:GERAN-A-2:LU)[0x55555595c4b0]{VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS
<000e> vlr_lu_fsm.c:781 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-2:LU)[0x555555959940]{LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
<000e> vlr_lu_fsm.c:781 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-2:LU)[0x555555959940]{LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x54096394:GERAN-A-2:LU)[0x55555595c4b0]
<000e> fsm.c:535 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-2:LU)[0x555555959940]{LU_COMPL_VLR_S_DONE}: Deallocated
<000e> vlr_lu_fsm.c:749 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x54096394:GERAN-A-2:LU)[0x55555595c4b0]{VLR_ULA_S_WAIT_LU_COMPL}: State change to VLR_ULA_S_DONE (no timeout)
<000e> msc_a.c:806 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x54096394:GERAN-A-2:LU)[0x55555595c4b0]{VLR_ULA_S_DONE}: Terminating in cascade, depth 2 (cause = OSMO_FSM_TERM_PARENT, caused by: msc_a(IMSI-901700000023841:MSISDN-23841:TMSI-0x54096394:GERAN-A-2:LU)[0x555555958f00])
<000e> msc_a.c:806 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x54096394:GERAN-A-2:LU)[0x55555595c4b0]{VLR_ULA_S_DONE}: Removing from parent msc_a(IMSI-901700000023841:MSISDN-23841:TMSI-0x54096394:GERAN-A-2:LU)[0x555555958f00]
<000e> vlr_lu_fsm.c:1401 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x54096394:GERAN-A-2:LU)[0x55555595c4b0]{VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
<000e> fsm.c:514 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x54096394:GERAN-A-2:LU)[0x55555595c4b0]{VLR_ULA_S_DONE}: Deferring: will deallocate with msc_a(IMSI-901700000023841:MSISDN-23841:TMSI-0x54096394:GERAN-A-2:LU)[0x555555958f00]

sh subscriber msisdn 23841
<segfault>
Program received signal SIGSEGV, Segmentation fault.
0x00007ffff7536ee5 in osmo_use_count_total (uc=uc@entry=0x670) at use_count.c:76
76    use_count.c: No such file or directory.
(gdb) 
(gdb) 
(gdb) 
(gdb) 
(gdb) bt
#0  0x00007ffff7536ee5 in osmo_use_count_total (uc=uc@entry=0x670) at use_count.c:76
#1  0x00007ffff7536f94 in osmo_use_count_name_buf (buf=buf@entry=0x7fffffffdc00 "\020\334\377\377\377\177", buf_len=buf_len@entry=128, uc=uc@entry=0x670) at use_count.c:110
#2  0x0000555555567ae2 in vty_dump_one_conn (vty=vty@entry=0x5555559513b0, msub=0x55555595bbc0, idx=idx@entry=0x7fffffffdcdc) at msc_vty.c:648
#3  0x00005555555682df in subscr_dump_full_vty (vty=vty@entry=0x5555559513b0, vsub=vsub@entry=0x555555959030) at msc_vty.c:813
#4  0x000055555556a362 in show_subscr (self=<optimized out>, vty=0x5555559513b0, argc=<optimized out>, argv=<optimized out>) at msc_vty.c:971
#5  0x00007ffff7bbf7c1 in cmd_execute_command_real (vline=vline@entry=0x555555951940, vty=vty@entry=0x5555559513b0, cmd=0x0) at command.c:2320
#6  0x00007ffff7bc2231 in cmd_execute_command (vline=vline@entry=0x555555951940, vty=vty@entry=0x5555559513b0, cmd=cmd@entry=0x0, vtysh=vtysh@entry=0) at command.c:2353
#7  0x00007ffff7bc4740 in vty_command (buf=<optimized out>, vty=0x5555559513b0) at vty.c:431
#8  vty_execute (vty=0x5555559513b0) at vty.c:695
#9  vty_read (vty=<optimized out>) at vty.c:1419
#10 0x00007ffff7bc6831 in client_data (fd=0x5555559522c8, what=1) at telnet_interface.c:147
#11 0x00007ffff7525667 in osmo_fd_disp_fds (_eset=0x7fffffffea40, _wset=0x7fffffffe9c0, _rset=0x7fffffffe940) at select.c:223
#12 osmo_select_main (polling=0) at select.c:263
#13 0x0000555555564c7b in main (argc=3, argv=<optimized out>) at msc_main.c:747
(gdb) 

full trace:

root@test123:~# gdb --args /usr/bin/osmo-msc -c /etc/osmocom/osmo-msc.cfg
GNU gdb (Debian 7.12-6) 7.12.0.20161007-git
Copyright (C) 2016 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying" 
and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /usr/bin/osmo-msc...Reading symbols from /usr/lib/debug/.build-id/3e/d2e8d03b9e2e3e1b51b41c6de46b194bdd70f0.debug...done.
done.
(gdb) r
Starting program: /usr/bin/osmo-msc -c /etc/osmocom/osmo-msc.cfg
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
<001f> osmo_ss7.c:1326 0: ASP Restart for server not implemented yet!
<0013> telnet_interface.c:104 Available via telnet 127.0.0.1 4254
<000c> smpp_smsc.c:1017 SMPP at 0.0.0.0 2775
<001a> control_if.c:911 CTRL at 127.0.0.1 4255
<0009> db.c:619 Init database connection to 'sms.db' using libdbi v0.9.0
<001d> gsup_client.c:73 GSUP connecting to 127.0.0.1:4222
<0023> mgcp_client.c:716 MGCP client: using endpoint domain '@mgw'
<0013> socket.c:228 unable to bind socket: 0.0.0.0:2727: Address already in use
<0013> socket.c:237 no suitable local addr found for: 0.0.0.0:2727
<0023> mgcp_client.c:749 MGCPGW failed to bind to 0.0.0.0:2727, retrying with port 2728
<0020> sccp_user.c:515 OsmoMSC-A-Iu: Using SS7 instance 0, pc:0.23.1
<0020> sccp_user.c:533 OsmoMSC-A-Iu: Using AS instance as-clnt-OsmoMSC-A-Iu
<0020> sccp_user.c:538 OsmoMSC-A-Iu: Creating default route
<0020> sccp_user.c:594 OsmoMSC-A-Iu: Using ASP instance asp-clnt-OsmoMSC-A-Iu
<001f> osmo_ss7.c:471 0: Creating SCCP instance
<0011> sgs_server.c:186 SGs socket bound to r=NULL<->l=0.0.0.0:29118
<0006> msc_main.c:712 A-interface: SCCP user OsmoMSC-A:RI=SSN_PC,PC=(no PC),SSN=BSSAP, cs7-instance 0 ((null))
<0006> msc_main.c:731 Iu-interface: SCCP user OsmoMSC-IuCS:RI=SSN_PC,PC=(no PC),SSN=RANAP, cs7-instance 0 ((null))
<0015> input/ipa.c:128 127.0.0.1:4222 connection done
<0015> input/ipaccess.c:705 received ID get from 0/0/0
<0022> m3ua.c:634 asp-asp-clnt-OsmoMSC-A-Iu: Received NOTIFY Type State Change:AS Inactive ()
<001f> xua_default_lm_fsm.c:353 xua_default_lm(asp-clnt-OsmoMSC-A-Iu)[0x555555953850]{ACTIVE}: Ignoring primitive M-ASP_ACTIVE.confirm
<0022> m3ua.c:634 asp-asp-clnt-OsmoMSC-A-Iu: Received NOTIFY Type State Change:AS Active ()
<0010> ran_peer.c:243 ran_peer(GERAN-A:RI-SSN_PC:PC-0-23-3:SSN-BSSAP)[0x55555595ab80]{WAIT_RX_RESET}: Receiving CO message on RAN peer that has not done a proper RESET yet. Disconnecting on incoming message, sending RESET to RAN peer.
<0020> sccp_scoc.c:1677 SCCP-SCOC(0)[0x5555559593e0]{DISCONN_PEND}: Event RCOC-DT1.ind not permitted
<000e> fsm.c:423 Process_Access_Request_VLR(TMSI-0x2EE3A704:GERAN-A-1:CM_SERVICE_REQ)[0x55555595c4d0]{PR_ARQ_S_INIT}: Allocated
<000e> fsm.c:453 Process_Access_Request_VLR(TMSI-0x2EE3A704:GERAN-A-1:CM_SERVICE_REQ)[0x55555595c4d0]{PR_ARQ_S_INIT}: is child of msc_a(TMSI-0x2EE3A704:GERAN-A-1:CM_SERVICE_REQ)[0x555555958f20]
<000e> vlr_access_req_fsm.c:675 Process_Access_Request_VLR(TMSI-0x2EE3A704:GERAN-A-1:CM_SERVICE_REQ)[0x55555595c4d0]{PR_ARQ_S_INIT}: rev=GSM net=GERAN Auth (no Ciph)
<000e> vlr_access_req_fsm.c:699 Process_Access_Request_VLR(TMSI-0x2EE3A704:GERAN-A-1:CM_SERVICE_REQ)[0x55555595c4d0]{PR_ARQ_S_INIT}: Received Event PR_ARQ_E_START
<000e> vlr_access_req_fsm.c:402 Process_Access_Request_VLR(TMSI-0x2EE3A704:GERAN-A-1:CM_SERVICE_REQ)[0x55555595c4d0]{PR_ARQ_S_INIT}: proc_arq_fsm_done(IMSI_UNKNOWN_IN_VLR)
<000e> vlr_access_req_fsm.c:103 Process_Access_Request_VLR(TMSI-0x2EE3A704:GERAN-A-1:CM_SERVICE_REQ)[0x55555595c4d0]{PR_ARQ_S_INIT}: State change to PR_ARQ_S_DONE (no timeout)
<000e> vlr_access_req_fsm.c:112 Process_Access_Request_VLR(TMSI-0x2EE3A704:GERAN-A-1:CM_SERVICE_REQ)[0x55555595c4d0]{PR_ARQ_S_DONE}: Process Access Request result: IMSI_UNKNOWN_IN_VLR
<0010> gsm_04_08.c:805 msc_a(TMSI-0x2EE3A704:GERAN-A-1:CM_SERVICE_REQ)[0x555555958f20]{MSC_A_ST_RELEASING}: subscriber not allowed to do a CM Service Request
<0010> msc_a.c:1525 msc_a(TMSI-0x2EE3A704:GERAN-A-1:CM_SERVICE_REQ)[0x555555958f20]{MSC_A_ST_RELEASING}: RAN decode error (rc=-5) for COMPL_L3 from MSC-I
<000e> msc_a.c:806 Process_Access_Request_VLR(TMSI-0x2EE3A704:GERAN-A-1:CM_SERVICE_REQ)[0x55555595c4d0]{PR_ARQ_S_DONE}: Terminating in cascade, depth 2 (cause = OSMO_FSM_TERM_PARENT, caused by: msc_a(TMSI-0x2EE3A704:GERAN-A-1:CM_SERVICE_REQ)[0x555555958f20])
<000e> msc_a.c:806 Process_Access_Request_VLR(TMSI-0x2EE3A704:GERAN-A-1:CM_SERVICE_REQ)[0x55555595c4d0]{PR_ARQ_S_DONE}: Removing from parent msc_a(TMSI-0x2EE3A704:GERAN-A-1:CM_SERVICE_REQ)[0x555555958f20]
<000e> fsm.c:514 Process_Access_Request_VLR(TMSI-0x2EE3A704:GERAN-A-1:CM_SERVICE_REQ)[0x55555595c4d0]{PR_ARQ_S_DONE}: Deferring: will deallocate with msc_a(TMSI-0x2EE3A704:GERAN-A-1:CM_SERVICE_REQ)[0x555555958f20]
<000e> fsm.c:423 vlr_lu_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595c4d0]{VLR_ULA_S_IDLE}: Allocated
<000e> fsm.c:453 vlr_lu_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595c4d0]{VLR_ULA_S_IDLE}: is child of msc_a(IMSI-901700000023841:GERAN-A-2:LU)[0x555555958f20]
<000e> vlr_lu_fsm.c:1476 vlr_lu_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595c4d0]{VLR_ULA_S_IDLE}: rev=GSM net=GERAN Auth (no Ciph)
<000e> vlr_lu_fsm.c:1482 vlr_lu_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595c4d0]{VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA
<000e> vlr.c:435 set IMSI on subscriber; IMSI=901700000023841 id=901700000023841
<000e> vlr.c:386 New subscr, IMSI: 901700000023841
<000e> vlr_lu_fsm.c:909 vlr_lu_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595c4d0]{VLR_ULA_S_IDLE}: vlr_loc_upd_node1()
<000e> vlr_lu_fsm.c:916 vlr_lu_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595c4d0]{VLR_ULA_S_IDLE}: State change to VLR_ULA_S_WAIT_AUTH (T0, 30s)
<000e> fsm.c:423 VLR_Authenticate(IMSI-901700000023841:GERAN-A-2:LU)[0x555555959960]{VLR_SUB_AS_NEEDS_AUTH}: Allocated
<000e> fsm.c:453 VLR_Authenticate(IMSI-901700000023841:GERAN-A-2:LU)[0x555555959960]{VLR_SUB_AS_NEEDS_AUTH}: is child of vlr_lu_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595c4d0]
<000e> vlr_auth_fsm.c:628 VLR_Authenticate(IMSI-901700000023841:GERAN-A-2:LU)[0x555555959960]{VLR_SUB_AS_NEEDS_AUTH}: Received Event VLR_AUTH_E_START
<000e> vlr_auth_fsm.c:318 VLR_Authenticate(IMSI-901700000023841:GERAN-A-2:LU)[0x555555959960]{VLR_SUB_AS_NEEDS_AUTH}: State change to VLR_SUB_AS_NEEDS_AUTH_WAIT_AI (T0, 30s)
<0005> ran_peer.c:105 ran_peer(GERAN-A:RI-SSN_PC:PC-0-23-3:SSN-BSSAP)[0x55555595ab80]{READY}: Added seen cell to this RAN peer: CGI:901-70-1-0
<000e> vlr.c:752 VLR_Authenticate(IMSI-901700000023841:GERAN-A-2:LU)[0x555555959960]{VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: Received Event VLR_AUTH_E_HLR_SAI_ACK
<000e> vlr.c:732 SUBSCR(IMSI-901700000023841) Received 5 auth tuples
<000e> vlr_auth_fsm.c:374 VLR_Authenticate(IMSI-901700000023841:GERAN-A-2:LU)[0x555555959960]{VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: State change to VLR_SUB_AS_WAIT_RESP (no timeout)
<000e> vlr_auth_fsm.c:286 VLR_Authenticate(IMSI-901700000023841:GERAN-A-2:LU)[0x555555959960]{VLR_SUB_AS_WAIT_RESP}: got auth tuple: use_count=1 key_seq=0 -- will use GSM AKA (is_r99=no, at->vec.auth_types=0x3)
<000e> vlr.c:1323 VLR_Authenticate(IMSI-901700000023841:GERAN-A-2:LU)[0x555555959960]{VLR_SUB_AS_WAIT_RESP}: Received Event VLR_AUTH_E_MS_AUTH_RESP
<000e> vlr_auth_fsm.c:136 SUBSCR(IMSI-901700000023841) AUTH on GERAN received SRES/RES: 9a8c5d25 (4 bytes)
<000e> vlr_auth_fsm.c:208 SUBSCR(IMSI-901700000023841) AUTH established GSM security context
<000e> vlr_auth_fsm.c:244 VLR_Authenticate(IMSI-901700000023841:GERAN-A-2:LU)[0x555555959960]{VLR_SUB_AS_WAIT_RESP}: Authentication terminating with result PASSED
<000e> vlr_auth_fsm.c:248 VLR_Authenticate(IMSI-901700000023841:GERAN-A-2:LU)[0x555555959960]{VLR_SUB_AS_WAIT_RESP}: State change to VLR_SUB_AS_AUTHENTICATED (no timeout)
<000e> vlr_auth_fsm.c:253 VLR_Authenticate(IMSI-901700000023841:GERAN-A-2:LU)[0x555555959960]{VLR_SUB_AS_AUTHENTICATED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
<000e> vlr_auth_fsm.c:253 VLR_Authenticate(IMSI-901700000023841:GERAN-A-2:LU)[0x555555959960]{VLR_SUB_AS_AUTHENTICATED}: Removing from parent vlr_lu_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595c4d0]
<000e> vlr_auth_fsm.c:253 vlr_lu_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595c4d0]{VLR_ULA_S_WAIT_AUTH}: Received Event VLR_ULA_E_AUTH_RES
<000e> vlr_lu_fsm.c:863 vlr_lu_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595c4d0]{VLR_ULA_S_WAIT_AUTH}: vlr_loc_upd_post_auth()
<000e> vlr_lu_fsm.c:830 vlr_lu_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595c4d0]{VLR_ULA_S_WAIT_AUTH}: vlr_loc_upd_post_ciph()
<000e> vlr_lu_fsm.c:791 vlr_lu_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595c4d0]{VLR_ULA_S_WAIT_AUTH}: vlr_loc_upd_node_4()
<000e> vlr_lu_fsm.c:800 vlr_lu_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595c4d0]{VLR_ULA_S_WAIT_AUTH}: State change to VLR_ULA_S_WAIT_HLR_UPD (T0, 30s)
<000e> fsm.c:423 upd_hlr_vlr_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595a800]{UPD_HLR_VLR_S_INIT}: Allocated
<000e> fsm.c:453 upd_hlr_vlr_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595a800]{UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595c4d0]
<000e> vlr_lu_fsm.c:176 upd_hlr_vlr_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595a800]{UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START
<000e> vlr_lu_fsm.c:87 upd_hlr_vlr_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595a800]{UPD_HLR_VLR_S_INIT}: State change to UPD_HLR_VLR_S_WAIT_FOR_DATA (T0, 30s)
<000e> fsm.c:535 VLR_Authenticate(IMSI-901700000023841:GERAN-A-2:LU)[0x555555959960]{VLR_SUB_AS_AUTHENTICATED}: Deallocated
<000e> vlr.c:775 IMSI:901700000023841 has MSISDN:23841
<000e> gsm_04_08.c:1364 SUBSCR(IMSI-901700000023841:MSISDN-23841) VLR: update for IMSI=901700000023841 (MSISDN=23841)
<000e> vlr.c:876 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-2:LU)[0x55555595c4d0]{VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES
<000e> vlr_lu_fsm.c:1186 upd_hlr_vlr_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595a800]{UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK
<000e> vlr_lu_fsm.c:109 upd_hlr_vlr_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595a800]{UPD_HLR_VLR_S_WAIT_FOR_DATA}: State change to UPD_HLR_VLR_S_DONE (no timeout)
<000e> vlr_lu_fsm.c:110 upd_hlr_vlr_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595a800]{UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
<000e> vlr_lu_fsm.c:110 upd_hlr_vlr_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595a800]{UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-2:LU)[0x55555595c4d0]
<000e> vlr_lu_fsm.c:110 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-2:LU)[0x55555595c4d0]{VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL
<000e> vlr_lu_fsm.c:1194 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-2:LU)[0x55555595c4d0]{VLR_ULA_S_WAIT_HLR_UPD}: State change to VLR_ULA_S_WAIT_LU_COMPL (T0, 30s)
<000e> fsm.c:423 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-2:LU)[0x555555959960]{LU_COMPL_VLR_S_INIT}: Allocated
<000e> fsm.c:453 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-2:LU)[0x555555959960]{LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-2:LU)[0x55555595c4d0]
<000e> vlr_lu_fsm.c:773 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-2:LU)[0x555555959960]{LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START
<000e> vlr_lu_fsm.c:418 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-2:LU)[0x555555959960]{LU_COMPL_VLR_S_INIT}: State change to LU_COMPL_VLR_S_WAIT_SUB_PRES (T0, 30s)
<000e> vlr_lu_fsm.c:425 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-2:LU)[0x555555959960]{LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL
<000e> vlr_lu_fsm.c:434 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-2:LU)[0x555555959960]{LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi()
<000e> gsm_04_08.c:1364 SUBSCR(IMSI-901700000023841:MSISDN-23841:TMSInew-0x31E5A925) VLR: update for IMSI=901700000023841 (MSISDN=23841)
<000e> vlr_lu_fsm.c:443 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-2:LU)[0x555555959960]{LU_COMPL_VLR_S_WAIT_SUB_PRES}: State change to LU_COMPL_VLR_S_WAIT_TMSI_CNF (no timeout)
<000e> fsm.c:535 upd_hlr_vlr_fsm(IMSI-901700000023841:GERAN-A-2:LU)[0x55555595a800]{UPD_HLR_VLR_S_DONE}: Deallocated
<000e> vlr.c:1185 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSInew-0x31E5A925:GERAN-A-2:LU)[0x55555595c4d0]{VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK
<000e> vlr_lu_fsm.c:1228 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-2:LU)[0x555555959960]{LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK
<000e> gsm_04_08.c:1364 SUBSCR(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925) VLR: update for IMSI=901700000023841 (MSISDN=23841)
<000e> vlr_lu_fsm.c:353 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-2:LU)[0x555555959960]{LU_COMPL_VLR_S_WAIT_TMSI_CNF}: State change to LU_COMPL_VLR_S_DONE (no timeout)
<000e> vlr_lu_fsm.c:388 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-2:LU)[0x55555595c4d0]{VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS
<000e> vlr_lu_fsm.c:781 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-2:LU)[0x555555959960]{LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
<000e> vlr_lu_fsm.c:781 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-2:LU)[0x555555959960]{LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-2:LU)[0x55555595c4d0]
<000e> fsm.c:535 lu_compl_vlr_fsm(IMSI-901700000023841:MSISDN-23841:GERAN-A-2:LU)[0x555555959960]{LU_COMPL_VLR_S_DONE}: Deallocated
<000e> vlr_lu_fsm.c:749 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-2:LU)[0x55555595c4d0]{VLR_ULA_S_WAIT_LU_COMPL}: State change to VLR_ULA_S_DONE (no timeout)
<000e> msc_a.c:806 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-2:LU)[0x55555595c4d0]{VLR_ULA_S_DONE}: Terminating in cascade, depth 2 (cause = OSMO_FSM_TERM_PARENT, caused by: msc_a(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-2:LU)[0x555555958f20])
<000e> msc_a.c:806 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-2:LU)[0x55555595c4d0]{VLR_ULA_S_DONE}: Removing from parent msc_a(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-2:LU)[0x555555958f20]
<000e> vlr_lu_fsm.c:1401 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-2:LU)[0x55555595c4d0]{VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
<000e> fsm.c:514 vlr_lu_fsm(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-2:LU)[0x55555595c4d0]{VLR_ULA_S_DONE}: Deferring: will deallocate with msc_a(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-2:LU)[0x555555958f20]
<000e> fsm.c:423 Process_Access_Request_VLR(TMSI-0x31E5A925:GERAN-A-3:CM_SERVICE_REQ)[0x55555595d220]{PR_ARQ_S_INIT}: Allocated
<000e> fsm.c:453 Process_Access_Request_VLR(TMSI-0x31E5A925:GERAN-A-3:CM_SERVICE_REQ)[0x55555595d220]{PR_ARQ_S_INIT}: is child of msc_a(TMSI-0x31E5A925:GERAN-A-3:CM_SERVICE_REQ)[0x55555595e0e0]
<000e> vlr_access_req_fsm.c:675 Process_Access_Request_VLR(TMSI-0x31E5A925:GERAN-A-3:CM_SERVICE_REQ)[0x55555595d220]{PR_ARQ_S_INIT}: rev=GSM net=GERAN Auth (no Ciph)
<000e> vlr_access_req_fsm.c:699 Process_Access_Request_VLR(TMSI-0x31E5A925:GERAN-A-3:CM_SERVICE_REQ)[0x55555595d220]{PR_ARQ_S_INIT}: Received Event PR_ARQ_E_START
<000e> vlr_access_req_fsm.c:333 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-3:CM_SERVICE_REQ)[0x55555595d220]{PR_ARQ_S_INIT}: proc_arq_vlr_fn_post_imsi()
<000e> vlr_access_req_fsm.c:340 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-3:CM_SERVICE_REQ)[0x55555595d220]{PR_ARQ_S_INIT}: State change to PR_ARQ_S_WAIT_AUTH (no timeout)
<000e> fsm.c:423 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-3:CM_SERVICE_REQ)[0x555555958ca0]{VLR_SUB_AS_NEEDS_AUTH}: Allocated
<000e> fsm.c:453 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-3:CM_SERVICE_REQ)[0x555555958ca0]{VLR_SUB_AS_NEEDS_AUTH}: is child of Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-3:CM_SERVICE_REQ)[0x55555595d220]
<000e> vlr_auth_fsm.c:628 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-3:CM_SERVICE_REQ)[0x555555958ca0]{VLR_SUB_AS_NEEDS_AUTH}: Received Event VLR_AUTH_E_START
<000e> vlr_auth_fsm.c:322 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-3:CM_SERVICE_REQ)[0x555555958ca0]{VLR_SUB_AS_NEEDS_AUTH}: State change to VLR_SUB_AS_WAIT_RESP (no timeout)
<000e> vlr_auth_fsm.c:286 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-3:CM_SERVICE_REQ)[0x555555958ca0]{VLR_SUB_AS_WAIT_RESP}: got auth tuple: use_count=1 key_seq=1 -- will use GSM AKA (is_r99=no, at->vec.auth_types=0x3)
<000e> vlr.c:1323 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-3:CM_SERVICE_REQ)[0x555555958ca0]{VLR_SUB_AS_WAIT_RESP}: Received Event VLR_AUTH_E_MS_AUTH_RESP
<000e> vlr_auth_fsm.c:136 SUBSCR(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925) AUTH on GERAN received SRES/RES: b3c7269f (4 bytes)
<000e> vlr_auth_fsm.c:208 SUBSCR(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925) AUTH established GSM security context
<000e> vlr_auth_fsm.c:244 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-3:CM_SERVICE_REQ)[0x555555958ca0]{VLR_SUB_AS_WAIT_RESP}: Authentication terminating with result PASSED
<000e> vlr_auth_fsm.c:248 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-3:CM_SERVICE_REQ)[0x555555958ca0]{VLR_SUB_AS_WAIT_RESP}: State change to VLR_SUB_AS_AUTHENTICATED (no timeout)
<000e> vlr_auth_fsm.c:253 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-3:CM_SERVICE_REQ)[0x555555958ca0]{VLR_SUB_AS_AUTHENTICATED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
<000e> vlr_auth_fsm.c:253 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-3:CM_SERVICE_REQ)[0x555555958ca0]{VLR_SUB_AS_AUTHENTICATED}: Removing from parent Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-3:CM_SERVICE_REQ)[0x55555595d220]
<000e> vlr_auth_fsm.c:253 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-3:CM_SERVICE_REQ)[0x55555595d220]{PR_ARQ_S_WAIT_AUTH}: Received Event PR_ARQ_E_AUTH_RES
<000e> vlr_access_req_fsm.c:284 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-3:CM_SERVICE_REQ)[0x55555595d220]{PR_ARQ_S_WAIT_AUTH}: _proc_arq_vlr_node2()
<000e> vlr_access_req_fsm.c:250 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-3:CM_SERVICE_REQ)[0x55555595d220]{PR_ARQ_S_WAIT_AUTH}: _proc_arq_vlr_node2_post_ciph()
<000e> vlr_access_req_fsm.c:222 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-3:CM_SERVICE_REQ)[0x55555595d220]{PR_ARQ_S_WAIT_AUTH}: _proc_arq_vlr_node2_post_vlr()
<000e> vlr_access_req_fsm.c:207 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-3:CM_SERVICE_REQ)[0x55555595d220]{PR_ARQ_S_WAIT_AUTH}: _proc_arq_vlr_post_pres()
<000e> vlr_access_req_fsm.c:191 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-3:CM_SERVICE_REQ)[0x55555595d220]{PR_ARQ_S_WAIT_AUTH}: _proc_arq_vlr_post_trace()
<000e> vlr_access_req_fsm.c:169 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-3:CM_SERVICE_REQ)[0x55555595d220]{PR_ARQ_S_WAIT_AUTH}: _proc_arq_vlr_post_imei()
<000e> vlr_access_req_fsm.c:182 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-3:CM_SERVICE_REQ)[0x55555595d220]{PR_ARQ_S_WAIT_AUTH}: proc_arq_fsm_done(PASSED)
<000e> vlr_access_req_fsm.c:103 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-3:CM_SERVICE_REQ)[0x55555595d220]{PR_ARQ_S_WAIT_AUTH}: State change to PR_ARQ_S_DONE (no timeout)
<000e> vlr_access_req_fsm.c:112 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-3:CM_SERVICE_REQ)[0x55555595d220]{PR_ARQ_S_DONE}: Process Access Request result: PASSED
<000e> fsm.c:535 VLR_Authenticate(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-3:CM_SERVICE_REQ)[0x555555958ca0]{VLR_SUB_AS_AUTHENTICATED}: Deallocated
<000e> msc_a.c:806 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-3:CM_SERVICE_REQ)[0x55555595d220]{PR_ARQ_S_DONE}: Terminating in cascade, depth 2 (cause = OSMO_FSM_TERM_PARENT, caused by: msc_a(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-3:CM_SERVICE_REQ)[0x55555595e0e0])
<000e> msc_a.c:806 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-3:CM_SERVICE_REQ)[0x55555595d220]{PR_ARQ_S_DONE}: Removing from parent msc_a(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-3:CM_SERVICE_REQ)[0x55555595e0e0]
<000e> fsm.c:514 Process_Access_Request_VLR(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-3:CM_SERVICE_REQ)[0x55555595d220]{PR_ARQ_S_DONE}: Deferring: will deallocate with msc_a(IMSI-901700000023841:MSISDN-23841:TMSI-0x31E5A925:GERAN-A-3:CM_SERVICE_REQ)[0x55555595e0e0]

Program received signal SIGSEGV, Segmentation fault.
0x00007ffff7536ee5 in osmo_use_count_total (uc=uc@entry=0x670) at use_count.c:76
76    use_count.c: No such file or directory.
(gdb) bt
#0  0x00007ffff7536ee5 in osmo_use_count_total (uc=uc@entry=0x670) at use_count.c:76
#1  0x00007ffff7536f94 in osmo_use_count_name_buf (buf=buf@entry=0x7fffffffdc00 "\020\334\377\377\377\177", buf_len=buf_len@entry=128, uc=uc@entry=0x670) at use_count.c:110
#2  0x0000555555567ae2 in vty_dump_one_conn (vty=vty@entry=0x5555559513b0, msub=0x55555595c9e0, idx=idx@entry=0x7fffffffdcdc) at msc_vty.c:648
#3  0x00005555555682df in subscr_dump_full_vty (vty=vty@entry=0x5555559513b0, vsub=vsub@entry=0x555555959050) at msc_vty.c:813
#4  0x000055555556a362 in show_subscr (self=<optimized out>, vty=0x5555559513b0, argc=<optimized out>, argv=<optimized out>) at msc_vty.c:971
#5  0x00007ffff7bbf7c1 in cmd_execute_command_real (vline=vline@entry=0x555555955a00, vty=vty@entry=0x5555559513b0, cmd=0x0) at command.c:2320
#6  0x00007ffff7bc2231 in cmd_execute_command (vline=vline@entry=0x555555955a00, vty=vty@entry=0x5555559513b0, cmd=cmd@entry=0x0, vtysh=vtysh@entry=0) at command.c:2353
#7  0x00007ffff7bc4740 in vty_command (buf=<optimized out>, vty=0x5555559513b0) at vty.c:431
#8  vty_execute (vty=0x5555559513b0) at vty.c:695
#9  vty_read (vty=<optimized out>) at vty.c:1419
#10 0x00007ffff7bc6831 in client_data (fd=0x5555559522c8, what=1) at telnet_interface.c:147
#11 0x00007ffff7525667 in osmo_fd_disp_fds (_eset=0x7fffffffea40, _wset=0x7fffffffe9c0, _rset=0x7fffffffe940) at select.c:223
#12 osmo_select_main (polling=0) at select.c:263
#13 0x0000555555564c7b in main (argc=3, argv=<optimized out>) at msc_main.c:747
(gdb) 

Actions #1

Updated by laforge almost 5 years ago

  • Assignee set to pespin
  • Priority changed from Normal to High
Actions #2

Updated by fixeria almost 5 years ago

I have managed to reproduce this segfault, but in a simper way:

1) compile OsmoMSC with ASAN (--enable-sanitize);
2) register a subscriber with known MSISDN;
3) in the VTY, do 'show subscriber extension MSISDN'.

Result:

=================================================================
==2581==ERROR: AddressSanitizer: heap-use-after-free on address 0x61d000017d00 at pc 0x000000562c9e bp 0x7ffd48b0ec60 sp 0x7ffd48b0ec58
READ of size 8 at 0x61d000017d00 thread T0
    #0 0x562c9d in msub_msc_a /home/wmn/osmocom/osmo-msc/src/libmsc/msub.c:273:7
    #1 0x512599 in vty_dump_one_conn /home/wmn/osmocom/osmo-msc/src/libmsc/msc_vty.c:651:24
    #2 0x510f01 in subscr_dump_full_vty /home/wmn/osmocom/osmo-msc/src/libmsc/msc_vty.c:827:4
    #3 0x50f66b in show_subscr /home/wmn/osmocom/osmo-msc/src/libmsc/msc_vty.c:985:2
    #4 0x7fb273582d36 in cmd_execute_command_real /opt/osmocom/libosmocore/src/vty/command.c:2320
    #5 0x7fb273587940 in vty_command /opt/osmocom/libosmocore/src/vty/vty.c:431
    #6 0x7fb273587940 in vty_execute /opt/osmocom/libosmocore/src/vty/vty.c:695
    #7 0x7fb273587940 in vty_read /opt/osmocom/libosmocore/src/vty/vty.c:1419
    #8 0x7fb273589b08 in client_data /opt/osmocom/libosmocore/src/vty/telnet_interface.c:147
    #9 0x7fb272cd8cb3 in osmo_fd_disp_fds /opt/osmocom/libosmocore/src/select.c:223
    #10 0x7fb272cd8cb3 in osmo_select_main /opt/osmocom/libosmocore/src/select.c:263
    #11 0x4fe771 in main /home/wmn/osmocom/osmo-msc/src/osmo-msc/msc_main.c:747:3
    #12 0x7fb270d03f44 in __libc_start_main /build/eglibc-xkFqqE/eglibc-2.19/csu/libc-start.c:287
    #13 0x4225db in _start (/home/wmn/osmocom/osmo-msc/src/osmo-msc/osmo-msc+0x4225db)

0x61d000017d00 is located 128 bytes inside of 2104-byte region [0x61d000017c80,0x61d0000184b8)
freed by thread T0 here:
    #0 0x4cdc12 in __interceptor_free (/home/wmn/osmocom/osmo-msc/src/osmo-msc/osmo-msc+0x4cdc12)
    #1 0x7fb273372c23  (/usr/lib/x86_64-linux-gnu/libtalloc.so.2+0x9c23)

previously allocated by thread T0 here:
    #0 0x4cdf93 in malloc (/home/wmn/osmocom/osmo-msc/src/osmo-msc/osmo-msc+0x4cdf93)
    #1 0x7fb27336e2a8 in talloc_named_const (/usr/lib/x86_64-linux-gnu/libtalloc.so.2+0x52a8)

SUMMARY: AddressSanitizer: heap-use-after-free /home/wmn/osmocom/osmo-msc/src/libmsc/msub.c:273:7 in msub_msc_a
Shadow bytes around the buggy address:
  0x0c3a7fffaf50: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c3a7fffaf60: fd fd fd fd fd fd fd fd fd fd fd fd fd fa fa fa
  0x0c3a7fffaf70: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c3a7fffaf80: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c3a7fffaf90: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
=>0x0c3a7fffafa0:[fd]fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c3a7fffafb0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c3a7fffafc0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c3a7fffafd0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c3a7fffafe0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c3a7fffaff0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
Shadow byte legend (one shadow byte represents 8 application bytes):
  Addressable:           00
  Partially addressable: 01 02 03 04 05 06 07 
  Heap left redzone:       fa
  Freed heap region:       fd
  Stack left redzone:      f1
  Stack mid redzone:       f2
  Stack right redzone:     f3
  Stack after return:      f5
  Stack use after scope:   f8
  Global redzone:          f9
  Global init order:       f6
  Poisoned by user:        f7
  Container overflow:      fc
  Array cookie:            ac
  Intra object redzone:    bb
  ASan internal:           fe
  Left alloca redzone:     ca
  Right alloca redzone:    cb
  Shadow gap:              cc
==2581==ABORTING
Actions #3

Updated by fixeria almost 5 years ago

  • Status changed from New to Feedback
  • % Done changed from 0 to 50

Please see: https://gerrit.osmocom.org/#/c/osmo-msc/+/14061

This change fixes the segfault for me. TBH, I still don't know how this fixes the problem.
From the API point of view, using msub_for_vsub() looks more logical.

roh could you please test again?

Actions #4

Updated by laforge almost 5 years ago

  • Assignee changed from pespin to fixeria
  • % Done changed from 50 to 80

fixeria wrote:

This change fixes the segfault for me. TBH, I still don't know how this fixes the problem.

msc_conn_ref points to 'msc_a', not to a msub! That's the danger with passing 'void *' around all the time :/ The initial idea was to separate the VLR data structures from the MSC data structures, and use 'void *' to indicate that the VLR doesn't care about what you pass it.

There are two ways to reduce this kind of problem:

a) don't use 'void *' in the VLR, but actually use a 'struct msc_a *' everywhere. One can still declare that as an opaquae type ("struct msc_a;") without any definition to prevent the VLR from looking inside.

b) In MSC code, don't directly dereference msc_conn_ref members, but always use some kind of accessor inline function or macro, which then returns the "correct" type.

Actions #5

Updated by laforge almost 5 years ago

patch has been merged, it's an obvious fix.

Actions #6

Updated by roh almost 5 years ago

  • Status changed from Feedback to Resolved
  • % Done changed from 80 to 100

tested with new nightly build

i am not able to get it to crash anymore.

Actions

Also available in: Atom PDF

Add picture from clipboard (Maximum size: 48.8 MB)