Actions
Bug #3518
closedRapid SETUP followed DISC results in lingering B-leg
Start date:
09/04/2018
Due date:
% Done:
60%
Resolution:
Spec Reference:
Description
This is 100% reproducible at the moment.
First log output is from correct behaviour, (slighty longer before pressing END on UE)
Second log output shows some clue of what's happening..
A race condition?
Tue Sep 4 17:30:22 2018 DMNCC <0001> mncc.c:845 MNCC rcvd message type: MNCC_SETUP_IND Tue Sep 4 17:30:22 2018 DMNCC <0001> mncc.c:466 Created call(5018) with MNCC leg(2147483734) IMSI(262423203000396) Tue Sep 4 17:30:22 2018 DMNCC <0001> mncc.c:845 MNCC rcvd message type: MNCC_RTP_CREATE Tue Sep 4 17:30:22 2018 DMNCC <0001> mncc.c:391 RTP cnt leg(2147483734) ip(172.16.0.15), port(16536) pt(98) ptm(771) Tue Sep 4 17:30:22 2018 DMNCC <0001> mncc.c:81 Got response(0x204), stopping timer on leg(2147483734) Tue Sep 4 17:30:22 2018 DSIP <0000> sip.c:223 SIP event(7) status(0) phrase(INVITE sent) 0x1476e50 Tue Sep 4 17:30:22 2018 DSIP <0000> sip.c:290 nua_callback() did nothing with event(7), status(0) Tue Sep 4 17:30:22 2018 DSIP <0000> sip.c:223 SIP event(1) status(100) phrase(Trying) (nil) Tue Sep 4 17:30:22 2018 DSIP <0000> sip.c:89 Incoming call handle(0x147fb10) Tue Sep 4 17:30:22 2018 DSIP <0000> sip.c:223 SIP event(7) status(100) phrase(Trying) 0x1487b30 Tue Sep 4 17:30:22 2018 DSIP <0000> sip.c:290 nua_callback() did nothing with event(7), status(100) Tue Sep 4 17:30:23 2018 DMNCC <0001> mncc.c:845 MNCC rcvd message type: MNCC_DISC_IND Tue Sep 4 17:30:23 2018 DMNCC <0001> mncc.c:511 Rcvd MNCC_DISC_IND, Cause: NORM_CALL_CLEAR Tue Sep 4 17:30:23 2018 DMNCC <0001> mncc.c:513 leg(2147483734) was disconnected. Releasing Tue Sep 4 17:30:23 2018 DSIP <0000> sip.c:332 sip_release_call(): Release with MNCC cause(NORM_CALL_CLEAR) Tue Sep 4 17:30:23 2018 DSIP <0000> sip.c:304 cause2status(): Mapping cause(NORM_CALL_CLEAR) to status(200) Tue Sep 4 17:30:23 2018 DSIP <0000> sip.c:338 Canceling leg(0x1476e50) in int state Tue Sep 4 17:30:23 2018 DSIP <0000> :0 nta_outgoing_tcancel: trying to cancel cancelled request Tue Sep 4 17:30:23 2018 DSIP <0000> sip.c:223 SIP event(2) status(200) phrase(OK) 0x1487b30 Tue Sep 4 17:30:23 2018 DSIP <0000> sip.c:280 Canceled on leg(0x1487b30) Tue Sep 4 17:30:23 2018 DMNCC <0001> mncc.c:253 Releasing call in initial-state leg(5019) Tue Sep 4 17:30:23 2018 DMNCC <0001> mncc.c:845 MNCC rcvd message type: MNCC_REL_CNF Tue Sep 4 17:30:23 2018 DMNCC <0001> mncc.c:81 Got response(0x112), stopping timer on leg(5019) Tue Sep 4 17:30:23 2018 DMNCC <0001> mncc.c:560 leg(5019) was cnf released. Tue Sep 4 17:30:23 2018 DAPP <0002> call.c:88 call(5019) released. Tue Sep 4 17:30:23 2018 DMNCC <0001> mncc.c:845 MNCC rcvd message type: MNCC_REL_CNF Tue Sep 4 17:30:23 2018 DMNCC <0001> mncc.c:81 Got response(0x112), stopping timer on leg(2147483734) Tue Sep 4 17:30:23 2018 DMNCC <0001> mncc.c:560 leg(2147483734) was cnf released. Tue Sep 4 17:30:23 2018 DAPP <0002> call.c:88 call(5018) released. Tue Sep 4 17:30:27 2018 DMNCC <0001> mncc.c:845 MNCC rcvd message type: MNCC_SETUP_IND Tue Sep 4 17:30:27 2018 DMNCC <0001> mncc.c:466 Created call(5020) with MNCC leg(2147483735) IMSI(262423203000396) Tue Sep 4 17:30:27 2018 DMNCC <0001> mncc.c:845 MNCC rcvd message type: MNCC_DISC_IND Tue Sep 4 17:30:27 2018 DMNCC <0001> mncc.c:511 Rcvd MNCC_DISC_IND, Cause: NORM_CALL_CLEAR Tue Sep 4 17:30:27 2018 DMNCC <0001> mncc.c:513 leg(2147483735) was disconnected. Releasing Tue Sep 4 17:30:27 2018 DMNCC <0001> mncc.c:845 MNCC rcvd message type: MNCC_RTP_CREATE Tue Sep 4 17:30:27 2018 DMNCC <0001> mncc.c:391 RTP cnt leg(2147483735) ip(172.16.0.15), port(16538) pt(98) ptm(771) Tue Sep 4 17:30:27 2018 DMNCC <0001> mncc.c:75 Wanted rsp(274) but got(516) for leg(2147483735) Tue Sep 4 17:30:27 2018 DSIP <0000> sip.c:223 SIP event(7) status(0) phrase(INVITE sent) 0x148b950 Tue Sep 4 17:30:27 2018 DSIP <0000> sip.c:290 nua_callback() did nothing with event(7), status(0) Tue Sep 4 17:30:27 2018 DSIP <0000> sip.c:223 SIP event(1) status(100) phrase(Trying) (nil) Tue Sep 4 17:30:27 2018 DSIP <0000> sip.c:89 Incoming call handle(0x1489690) Tue Sep 4 17:30:27 2018 DSIP <0000> sip.c:223 SIP event(7) status(100) phrase(Trying) 0x148e950 Tue Sep 4 17:30:27 2018 DSIP <0000> sip.c:290 nua_callback() did nothing with event(7), status(100) Tue Sep 4 17:30:27 2018 DMNCC <0001> mncc.c:845 MNCC rcvd message type: MNCC_REL_CNF Tue Sep 4 17:30:27 2018 DMNCC <0001> mncc.c:81 Got response(0x112), stopping timer on leg(2147483735) Tue Sep 4 17:30:27 2018 DMNCC <0001> mncc.c:560 leg(2147483735) was cnf released. Tue Sep 4 17:30:27 2018 DMNCC <0001> mncc.c:845 MNCC rcvd message type: MNCC_CALL_CONF_IND Tue Sep 4 17:30:27 2018 DMNCC <0001> mncc.c:609 leg(5021) confirmend. creating RTP socket. Tue Sep 4 17:30:28 2018 DMNCC <0001> mncc.c:845 MNCC rcvd message type: MNCC_RTP_CREATE Tue Sep 4 17:30:28 2018 DMNCC <0001> mncc.c:391 RTP cnt leg(5021) ip(172.16.0.15), port(16540) pt(3) ptm(768) Tue Sep 4 17:30:28 2018 DMNCC <0001> mncc.c:81 Got response(0x204), stopping timer on leg(5021) Tue Sep 4 17:30:28 2018 DMNCC <0001> mncc.c:845 MNCC rcvd message type: MNCC_ALERT_IND Tue Sep 4 17:30:28 2018 DMNCC <0001> mncc.c:626 leg(5021) is alerting. Tue Sep 4 17:30:28 2018 DSIP <0000> sip.c:223 SIP event(7) status(180) phrase(Ringing) 0x148e950 Tue Sep 4 17:30:28 2018 DSIP <0000> sip.c:290 nua_callback() did nothing with event(7), status(180) Tue Sep 4 17:30:28 2018 DSIP <0000> sip.c:223 SIP event(31) status(183) phrase(Session Progress) 0x148b950 Tue Sep 4 17:30:28 2018 DSIP <0000> sip.c:223 SIP event(7) status(183) phrase(Session Progress) 0x148b950 Tue Sep 4 17:30:28 2018 DSIP <0000> sip.c:290 nua_callback() did nothing with event(7), status(183) Tue Sep 4 17:30:30 2018 DMNCC <0001> mncc.c:845 MNCC rcvd message type: MNCC_DISC_IND Tue Sep 4 17:30:30 2018 DMNCC <0001> mncc.c:511 Rcvd MNCC_DISC_IND, Cause: USER_BUSY Tue Sep 4 17:30:30 2018 DMNCC <0001> mncc.c:513 leg(5021) was disconnected. Releasing Tue Sep 4 17:30:30 2018 DSIP <0000> sip.c:332 sip_release_call(): Release with MNCC cause(USER_BUSY) Tue Sep 4 17:30:30 2018 DSIP <0000> sip.c:304 cause2status(): Mapping cause(USER_BUSY) to status(486) Tue Sep 4 17:30:30 2018 DSIP <0000> sip.c:343 Canceling leg(0x148e950) in cnfd state Tue Sep 4 17:30:30 2018 DMNCC <0001> mncc.c:845 MNCC rcvd message type: MNCC_REL_CNF Tue Sep 4 17:30:30 2018 DMNCC <0001> mncc.c:81 Got response(0x112), stopping timer on leg(5021) Tue Sep 4 17:30:30 2018 DMNCC <0001> mncc.c:560 leg(5021) was cnf released. Tue Sep 4 17:30:30 2018 DAPP <0002> call.c:88 call(5021) released. Tue Sep 4 17:30:37 2018 DSIP <0000> sip.c:223 SIP event(31) status(486) phrase(Busy Here) 0x148b950 Tue Sep 4 17:30:37 2018 DSIP <0000> sip.c:242 leg(0x148b950) unknown SIP status(486), releasing. Tue Sep 4 17:30:37 2018 DAPP <0002> call.c:88 call(5020) released.
Actions