Actions
Bug #4017
openMSC fails to handle calls
Status:
New
Priority:
Normal
Assignee:
-
Category:
-
Target version:
-
Start date:
05/22/2019
Due date:
% Done:
0%
Resolution:
Spec Reference:
Description
Osmo-MSC fails to handle calls sometimes after the phone has been registered to the network.
The following is the log from osmo-msc
Wed May 22 12:17:58 2019 DVLR <000e> vlr_access_req_fsm.c:374 Process_Access_Request_VLR(TMSI-0x35814F56:UTRAN-Iu-158:CM_SERVICE_REQ)[0x1377b80]{PR_ARQ_S_INIT}: Another proc_arq_fsm is already associated with subscr IMSI-450091000000001:MSISDN-01000000001:TMSI-0x35814F56, terminating the other FSM.
Wed May 22 12:17:58 2019 DVLR <000e> vlr_access_req_fsm.c:103 Process_Access_Request_VLR(IMSI-450091000000001:MSISDN-01000000001:TMSI-0x35814F56:UTRAN-Iu-157:CM_SERVICE_REQ)[0x136efe0]{PR_ARQ_S_DONE}: transition to state PR_ARQ_S_DONE not permitted!
Wed May 22 12:17:58 2019 DIUCS <000f> msub.c:360 msc_a(TMSI-0x35814F56:UTRAN-Iu-158:CM_SERVICE_REQ)[0x13793b0]{MSC_A_ST_VALIDATE_L3}: Cannot associate with VLR subscr, another connection is already active at IMSI-450091000000001:MSISDN-01000000001:TMSI-0x35814F56:UTRAN-Iu-157:CM_SERVICE_REQ
Wed May 22 12:17:58 2019 DIUCS <000f> msub.c:362 msc_a(IMSI-450091000000001:MSISDN-01000000001:TMSI-0x35814F56:UTRAN-Iu-157:CM_SERVICE_REQ)[0x136ed80]{MSC_A_ST_COMMUNICATING}: Attempt to associate a second subscriber connection at TMSI-0x35814F56:UTRAN-Iu-158:CM_SERVICE_REQ
Wed May 22 12:17:58 2019 DIUCS <000f> gsm_04_08.c:805 msc_a(TMSI-0x35814F56:UTRAN-Iu-158:CM_SERVICE_REQ)[0x13793b0]{MSC_A_ST_RELEASING}: subscriber not allowed to do a CM Service Request
Wed May 22 12:17:58 2019 DIUCS <000f> msc_a.c:1525 msc_a(TMSI-0x35814F56:UTRAN-Iu-158:CM_SERVICE_REQ)[0x13793b0]{MSC_A_ST_RELEASING}: RAN decode error (rc=-5) for COMPL_L3 from MSC-I
Wed May 22 12:17:58 2019 DIUCS <000f> msc_a.c:1377 msc_a(IMSI-450091000000001:MSISDN-01000000001:TMSI-0x35814F56:UTRAN-Iu-157:CM_SERVICE_REQ)[0x136ed80]{MSC_A_ST_COMMUNICATING}: Received Clear Complete event, but did not send Clear Command
Wed May 22 12:18:01 2019 DVLR <000e> vlr_access_req_fsm.c:374 Process_Access_Request_VLR(TMSI-0x35814F56:UTRAN-Iu-159:CM_SERVICE_REQ)[0x1377d70]{PR_ARQ_S_INIT}: Another proc_arq_fsm is already associated with subscr IMSI-450091000000001:MSISDN-01000000001:TMSI-0x35814F56, terminating the other FSM.
Wed May 22 12:18:01 2019 DVLR <000e> vlr_access_req_fsm.c:103 Process_Access_Request_VLR(TMSI-0x35814F56:UTRAN-Iu-158:CM_SERVICE_REQ)[0x1377b80]{PR_ARQ_S_DONE}: transition to state PR_ARQ_S_DONE not permitted!
Wed May 22 12:18:02 2019 DIUCS <000f> ran_msg_iu.c:179 msc_i(IMSI-450091000000001:MSISDN-01000000001:TMSI-0x35814F56:UTRAN-Iu-159:CM_SERVICE_REQ)[0x136bce0]{READY}: RAN decode: RANAP: RAB Assignment Response does not contain RAB information
Wed May 22 12:18:02 2019 DIUCS <000f> ran_msg_iu.c:179 msc_a(IMSI-450091000000001:MSISDN-01000000001:TMSI-0x35814F56:UTRAN-Iu-159:CM_SERVICE_REQ)[0x136af60]{MSC_A_ST_COMMUNICATING}: RAN decode: RANAP: RAB Assignment Response does not contain RAB information
Wed May 22 12:18:02 2019 DIUCS <000f> msc_a.c:1285 msc_a(IMSI-450091000000001:MSISDN-01000000001:TMSI-0x35814F56:UTRAN-Iu-159:CM_SERVICE_REQ)[0x136af60]{MSC_A_ST_COMMUNICATING}: Assignment Failure, releasing call
Wed May 22 12:18:02 2019 DIUCS <000f> msc_a.c:1193 msc_a(IMSI-450091000000001:MSISDN-01000000001:TMSI-0x35814F56:UTRAN-Iu-159:CM_SERVICE_REQ)[0x136af60]{MSC_A_ST_RELEASING}: Message not permitted for initial conn: GSM48_MT_CC_RELEASE_COMPL
Wed May 22 12:18:02 2019 DIUCS <000f> msc_a.c:1525 msc_a(IMSI-450091000000001:MSISDN-01000000001:TMSI-0x35814F56:UTRAN-Iu-159:CM_SERVICE_REQ)[0x136af60]{MSC_A_ST_RELEASING}: RAN decode error (rc=-13) for DTAP from MSC-I
Wed May 22 12:18:06 2019 DIUCS <000f> ran_msg_iu.c:179 msc_i(IMSI-450091000000001:MSISDN-01000000001:TMSI-0x35814F56:UTRAN-Iu-160:CM_SERVICE_REQ)[0x1378ec0]{READY}: RAN decode: RANAP: RAB Assignment Response does not contain RAB information
Wed May 22 12:18:06 2019 DIUCS <000f> ran_msg_iu.c:179 msc_a(IMSI-450091000000001:MSISDN-01000000001:TMSI-0x35814F56:UTRAN-Iu-160:CM_SERVICE_REQ)[0x136af60]{MSC_A_ST_COMMUNICATING}: RAN decode: RANAP: RAB Assignment Response does not contain RAB information
Wed May 22 12:18:06 2019 DIUCS <000f> msc_a.c:1285 msc_a(IMSI-450091000000001:MSISDN-01000000001:TMSI-0x35814F56:UTRAN-Iu-160:CM_SERVICE_REQ)[0x136af60]{MSC_A_ST_COMMUNICATING}: Assignment Failure, releasing call
Wed May 22 12:18:28 2019 DIUCS <000f> msc_a.c:688 msc_a(TMSI-0x35814F56:UTRAN-Iu-158:CM_SERVICE_REQ)[0x13793b0]{MSC_A_ST_RELEASING}: Timeout while releasing, discarding right now
Wed May 22 12:18:28 2019 DLSCCP <0020> sccp_scoc.c:1677 SCCP-SCOC(158)[0x1370e70]{DISCONN_PEND}: Event RCOC-ERROR.ind not permitted
osmo-sip-connector
Wed May 22 12:18:02 2019 DMNCC <0001> mncc.c:76 Wanted rsp(MNCC_RTP_CREATE) but got(MNCC_REL_CNF) for leg(2147483705) Wed May 22 12:18:06 2019 DMNCC <0001> mncc.c:76 Wanted rsp(MNCC_RTP_CREATE) but got(MNCC_REL_CNF) for leg(2147483706)
Files
Updated by manatails over 4 years ago
log and pcap file at the time of call failure. Please ignore the first pcap file as it is cut short.
Updated by laforge over 4 years ago
I could imagine that it's related to some of the other problems about not closing
SCCP connections in the first place. I honstly think we need to analyze those step by
step in a logical manner. As long as we don't even do the basics like SCCP connection handling
right, all kinds of strange higher-layer behavior may be a result.
Updated by manatails over 4 years ago
I thought this could be related to bug #3995 but it persists even when the SGSN is not present.
Actions
