Juha Heinanen writes: > 1) sems sends the second INVITE request to wrong IP:port (= > 192.98.102.10:5060) whereas it should go to > > next_hop=192.98.102.10:5070 > next_hop_1st_req=yes
i think that there actually is only one problem: sems thinks that the "503 service unavailable" response to the first invite: U 2013/09/04 10:25:18.643594 192.98.102.10:5070 -> 192.98.102.10:5090 SIP/2.0 503 Service Unavailable. Via: SIP/2.0/UDP 192.98.102.10:5090;branch=z9hG4bKhRQ9iaom;rport=5090. From: sip:[email protected];tag=65089D9C-5226E05A000C1108-68FE7700. To: sip:[email protected];tag=c02670ad1171fe45d9ff9a27d6c2cb82-b41f. CSeq: 10 INVITE. Call-ID: 739FB162-5226E05A000C111A-68FE7700. Content-Length: 0. established a dialog and sems then sends the second invite as an in-dialog request with to ;tag. since i have defined next_hop_1st_req=yes, next_hop=192.98.102.10:5070 is not used and the second invite is send according like all in-dialog requests based on the route set learned from the response that established the dialog. when the ivr app received 503 response, i added call self.terminateOtherLeg() just to check if that would make sems forget about the false dialog, but it didn't help. below is what i got to debug log after sems received "503 service unavailable" to the first invite if that would give any clues. it claims that the 503 response did this: setting SIP dialog status: Proceeding->Disconnected but for some reason it didn't. -- juha Sep 4 10:28:06 siika sems[25583]: [#7f2a691e9700] [run, udp_trsp.cpp:343] DEBUG: vv M [|] u recvd msg via UDP from 192.98.102.10:5070 vv.--++--.SIP/2.0 503 Service Unavailable..Via: SIP/2.0/UDP 192.98.102.10:5090;branch=z9hG4bKM2lqEard;rport=5090..From: sip:[email protected];tag=6CC3C886-5226E100000C3A1C-68FE7700..To: sip:[email protected];tag=c02670ad1171fe45d9ff9a27d6c2cb82-d1db..CSeq: 10 INVITE..Call-ID: 6900B3D5-5226E100000C3A2F-68FE7700..Server: OpenXg SIP Proxy (4.1.0-dev7 (x86_64/linux))..Content-Length: 0....--++-- Sep 4 10:28:06 siika sems[25583]: [#7f2a691e9700] [parse_via_params, parse_via.cpp:525] DEBUG: parsed branch: z9hG4bKM2lqEard Sep 4 10:28:06 siika sems[25583]: [#7f2a691e9700] [parse_via_params, parse_via.cpp:548] DEBUG: has_rport: 1 Sep 4 10:28:06 siika sems[25583]: [#7f2a691e9700] [received_msg, trans_layer.cpp:1488] DEBUG: Reply matched an existing transaction Sep 4 10:28:06 siika sems[25583]: [#7f2a691e9700] [update_uac_reply, trans_layer.cpp:1547] DEBUG: update_uac_reply(reply code = 503, trans=0x1443a80) Sep 4 10:28:06 siika sems[25583]: [#7f2a691e9700] [reset_timer, sip_trans.cpp:161] DEBUG: Clearing old timer of type C (this=0x1443eb0) Sep 4 10:28:06 siika sems[25583]: [#7f2a691e9700] [send_non_200_ack, trans_layer.cpp:1941] DEBUG: About to send ACK Sep 4 10:28:06 siika sems[25583]: [#7f2a691e9700] [send, udp_trsp.cpp:254] DEBUG: send msg.--++--.ACK sip:[email protected] SIP/2.0..Via: SIP/2.0/UDP 192.98.102.10:5090;branch=z9hG4bKM2lqEard;rport..From: sip:[email protected];tag=6CC3C886-5226E100000C3A1C-68FE7700..To: sip:[email protected];tag=c02670ad1171fe45d9ff9a27d6c2cb82-d1db..Call-ID: 6900B3D5-5226E100000C3A2F-68FE7700..CSeq: 10 ACK....--++-- Sep 4 10:28:06 siika sems[25583]: [#7f2a691e9700] [reset_timer, sip_trans.cpp:219] DEBUG: New timer of type D at time=11078 (repeated=0) Sep 4 10:28:06 siika sems[25583]: [#7f2a691e9700] [handle_sip_reply, SipCtrlInterface.cpp:687] DEBUG: Received reply: 503 Service Unavailable Sep 4 10:28:06 siika sems[25583]: [#7f2a691e9700] [handle_sip_reply, SipCtrlInterface.cpp:688] DEBUG: reply.callid = <6900B3D5-5226E100000C3A2F-68FE7700> Sep 4 10:28:06 siika sems[25583]: [#7f2a691e9700] [handle_sip_reply, SipCtrlInterface.cpp:689] DEBUG: reply.from_tag = <6CC3C886-5226E100000C3A1C-68FE7700> Sep 4 10:28:06 siika sems[25583]: [#7f2a691e9700] [handle_sip_reply, SipCtrlInterface.cpp:690] DEBUG: reply.to_tag = <c02670ad1171fe45d9ff9a27d6c2cb82-d1db> Sep 4 10:28:06 siika sems[25583]: [#7f2a691e9700] [handle_sip_reply, SipCtrlInterface.cpp:691] DEBUG: reply.contact = <> Sep 4 10:28:06 siika sems[25583]: [#7f2a691e9700] [handle_sip_reply, SipCtrlInterface.cpp:692] DEBUG: reply.to_uri = <> Sep 4 10:28:06 siika sems[25583]: [#7f2a691e9700] [handle_sip_reply, SipCtrlInterface.cpp:693] DEBUG: cseq = <10> Sep 4 10:28:06 siika sems[25583]: [#7f2a691e9700] [handle_sip_reply, SipCtrlInterface.cpp:694] DEBUG: reply.route = <> Sep 4 10:28:06 siika sems[25583]: [#7f2a691e9700] [handle_sip_reply, SipCtrlInterface.cpp:695] DEBUG: hdrs = <Server: OpenXg SIP Proxy (4.1.0-dev7 (x86_64/linux))..> Sep 4 10:28:06 siika sems[25583]: [#7f2a691e9700] [handle_sip_reply, SipCtrlInterface.cpp:696] DEBUG: body-ct = <> Sep 4 10:28:06 siika sems[25583]: [#7f2a691e9700] [handle_sip_reply, SipCtrlInterface.cpp:702] DEBUG: ^^ M [6900B3D5-5226E100000C3A2F-68FE7700|6CC3C886-5226E100000C3A1C-68FE7700] ru SIP reply 503 Service Unavailable handled ^^ Sep 4 10:28:06 siika sems[25583]: [#7f2a689e8700] [processingCycle, AmSession.cpp:378] DEBUG: vv S [6900B3D5-5226E100000C3A2F-68FE7700|6CC3C886-5226E100000C3A1C-68FE7700] Proceeding, running, 1 UACTransPending, 0 usages vv Sep 4 10:28:06 siika sems[25583]: [#7f2a689e8700] [process, AmSession.cpp:729] DEBUG: AmSession processing event Sep 4 10:28:06 siika sems[25583]: [#7f2a689e8700] [onRxReply, AmBasicSipDialog.cpp:410] DEBUG: onRxReply(rep = 503 Service Unavailable): transaction found! Sep 4 10:28:06 siika sems[25583]: [#7f2a689e8700] [setStatus, AmBasicSipDialog.cpp:81] DEBUG: setting SIP dialog status: Proceeding->Disconnected Sep 4 10:28:06 siika sems[25583]: [#7f2a689e8700] [onReplyIn, AmOfferAnswer.cpp:194] DEBUG: after 503 reply to INVITE: resetting OA state Sep 4 10:28:06 siika sems[25583]: [#7f2a689e8700] [setState, AmOfferAnswer.cpp:69] DEBUG: setting SIP dialog O/A status: OfferSent->None Sep 4 10:28:06 siika sems[25583]: [#7f2a689e8700] [onSipReply, AmB2BSession.cpp:463] DEBUG: onSipReply: INVITE -> 503 Service Unavailable (fwd=false), c-t= Sep 4 10:28:06 siika sems[25583]: [#7f2a689e8700] [onSipReply, AmSession.cpp:848] DEBUG: Dialog status changed Proceeding -> Disconnected (stopped=false) Sep 4 10:28:06 siika sems[25583]: [#7f2a689e8700] [onSipReply, AmB2BSession.cpp:524] DEBUG: relaying B2B SIP reply 503 Service Unavailable Sep 4 10:28:06 siika sems[25583]: [#7f2a689e8700] [relayEvent, AmB2BSession.cpp:573] DEBUG: AmB2BSession::relayEvent: to other_id='5E9E7CF0-5226E0FC0007354A-693EB700' Sep 4 10:28:06 siika sems[25583]: [#7f2a689e8700] [processingCycle, AmSession.cpp:397] DEBUG: ^^ S [6900B3D5-5226E100000C3A2F-68FE7700|6CC3C886-5226E100000C3A1C-68FE7700] Disconnected, running, 0 UACTransPending, 0 usages ^^ Sep 4 10:28:06 siika sems[25583]: [#7f2a68fe7700] [processingCycle, AmSession.cpp:378] DEBUG: vv S [[email protected]|5E9E7CF0-5226E0FC0007354A-693EB700] Connected, running, 0 UACTransPending, 0 usages vv Sep 4 10:28:06 siika sems[25583]: [#7f2a68fe7700] [process, Ivr.cpp:760] DEBUG: IvrDialog::process Sep 4 10:28:06 siika sems[25583]: [#7f2a68fe7700] [onB2BEvent, AmB2BSession.cpp:995] DEBUG: 503 Service Unavailable reply received from other leg Sep 4 10:28:06 siika sems[25583]: [#7f2a68fe7700] [relayEvent, AmB2BSession.cpp:573] DEBUG: AmB2BSession::relayEvent: to other_id='6CC3C886-5226E100000C3A1C-68FE7700' Sep 4 10:28:06 siika sems[25583]: [#7f2a68fe7700] [relayEvent, AmB2BSession.cpp:573] DEBUG: AmB2BSession::relayEvent: to other_id='6CC3C886-5226E100000C3A1C-68FE7700' Sep 4 10:28:06 siika sems[25583]: [#7f2a68fe7700] [removeTimer, AmSession.cpp:1319] DEBUG: removing timer 1 Sep 4 10:28:06 siika sems[25583]: [#7f2a68fe7700] [removeTimer, AmSession.cpp:1319] DEBUG: removing timer 2 Sep 4 10:28:06 siika sems[25583]: [#7f2a68fe7700] [setTimer, AmSession.cpp:1311] DEBUG: setting timer 1 with timeout 6.000000 Sep 4 10:28:06 siika sems[25583]: [#7f2a68fe7700] [setTimer, AmSession.cpp:1311] DEBUG: setting timer 2 with timeout 20.000000 Sep 4 10:28:06 siika sems[25583]: [#7f2a68fe7700] [IvrDialogBase_b2b_connectCallee, IvrDialogBase.cpp:316] DEBUG: args != Py_None Sep 4 10:28:06 siika sems[25583]: [#7f2a68fe7700] [connectCallee, AmB2BSession.cpp:1140] DEBUG: relaying B2B connect event to sip:[email protected] Sep 4 10:28:06 siika sems[25583]: [#7f2a68fe7700] [relayEvent, AmB2BSession.cpp:573] DEBUG: AmB2BSession::relayEvent: to other_id='6CC3C886-5226E100000C3A1C-68FE7700' Sep 4 10:28:06 siika sems[25583]: [#7f2a68fe7700] [onB2BEvent, AmB2BSession.cpp:158] DEBUG: AmB2BSession::onB2BEvent Sep 4 10:28:06 siika sems[25583]: [#7f2a68fe7700] [onB2BEvent, AmB2BSession.cpp:204] DEBUG: B2BSipReply: 503 Service Unavailable (fwd=false) Sep 4 10:28:06 siika sems[25583]: [#7f2a68fe7700] [onB2BEvent, AmB2BSession.cpp:206] DEBUG: B2BSipReply: content-type = Sep 4 10:28:06 siika sems[25583]: [#7f2a68fe7700] [processingCycle, AmSession.cpp:397] DEBUG: ^^ S [[email protected]|5E9E7CF0-5226E0FC0007354A-693EB700] Connected, running, 0 UACTransPending, 0 usages ^^ Sep 4 10:28:06 siika sems[25583]: [#7f2a689e8700] [processingCycle, AmSession.cpp:378] DEBUG: vv S [6900B3D5-5226E100000C3A2F-68FE7700|6CC3C886-5226E100000C3A1C-68FE7700] Disconnected, running, 0 UACTransPending, 0 usages vv Sep 4 10:28:06 siika sems[25583]: [#7f2a689e8700] [onB2BEvent, AmB2BSession.cpp:158] DEBUG: AmB2BSession::onB2BEvent Sep 4 10:28:06 siika sems[25583]: [#7f2a689e8700] [onB2BEvent, AmB2BSession.cpp:265] DEBUG: terminateLeg() Sep 4 10:28:06 siika sems[25583]: [#7f2a689e8700] [bye, AmSipDialog.cpp:565] DEBUG: bye(): we are not connected (status=Disconnected). do nothing! Sep 4 10:28:06 siika sems[25583]: [#7f2a689e8700] [onB2BEvent, AmB2BSession.cpp:158] DEBUG: AmB2BSession::onB2BEvent Sep 4 10:28:06 siika sems[25583]: [#7f2a689e8700] [onB2BEvent, AmB2BSession.cpp:265] DEBUG: terminateLeg() Sep 4 10:28:06 siika sems[25583]: [#7f2a689e8700] [bye, AmSipDialog.cpp:565] DEBUG: bye(): we are not connected (status=Disconnected). do nothing! Sep 4 10:28:06 siika sems[25583]: [#7f2a689e8700] [setState, AmOfferAnswer.cpp:69] DEBUG: setting SIP dialog O/A status: None->OfferSent Sep 4 10:28:06 siika sems[25583]: [#7f2a689e8700] [setStatus, AmBasicSipDialog.cpp:81] DEBUG: setting SIP dialog status: Disconnected->Trying Sep 4 10:28:06 siika sems[25583]: [#7f2a689e8700] [parse_sip_uri, parse_uri.cpp:343] DEBUG: Converted URI port () to int (5060) Sep 4 10:28:06 siika sems[25583]: [#7f2a689e8700] [set_next_hop, trans_layer.cpp:750] DEBUG: setting next-hop based on request-URI Sep 4 10:28:06 siika sems[25583]: [#7f2a689e8700] [set_next_hop, trans_layer.cpp:764] DEBUG: next_hop:next_port is <test.tutpro.com:0/udp> Sep 4 10:28:06 siika sems[25583]: [#7f2a689e8700] [set_destination_ip, trans_layer.cpp:775] DEBUG: checking whether 'test.tutpro.com' is IP address... Sep 4 10:28:06 siika sems[25583]: [#7f2a689e8700] [set_destination_ip, trans_layer.cpp:788] DEBUG: no port specified, looking up SRV '_sip._udp.test.tutpro.com'... Sep 4 10:28:06 siika sems[25583]: [#7f2a689e8700] [next_ip, resolver.cpp:272] DEBUG: setting port to 5060 Sep 4 10:28:06 siika sems[25583]: [#7f2a689e8700] [next_ip, resolver.cpp:289] DEBUG: target must be resolved first !!! (5060) Sep 4 10:28:06 siika sems[25583]: [#7f2a689e8700] [to_sa, resolver.cpp:420] DEBUG: copying ip_entry... Sep 4 10:28:06 siika sems[25583]: [#7f2a689e8700] [send_request, trans_layer.cpp:1095] DEBUG: send_request to R-URI <sip:[email protected]> Sep 4 10:28:06 siika sems[25583]: [#7f2a689e8700] [parse_sip_uri, parse_uri.cpp:343] DEBUG: Converted URI port () to int (5060) Sep 4 10:28:06 siika sems[25583]: [#7f2a689e8700] [parse_via_params, parse_via.cpp:525] DEBUG: parsed branch: z9hG4bKSbAakagf Sep 4 10:28:06 siika sems[25583]: [#7f2a689e8700] [parse_via_params, parse_via.cpp:548] DEBUG: has_rport: 1 Sep 4 10:28:06 siika sems[25583]: [#7f2a689e8700] [send_request, trans_layer.cpp:1112] DEBUG: Sending to 192.98.102.20:5060 <INVITE sip:[email protected] SIP/2.0..Via: SIP/...> Sep 4 10:28:06 siika sems[25583]: [#7f2a689e8700] [send, udp_trsp.cpp:254] DEBUG: send msg.--++--.INVITE sip:[email protected] SIP/2.0..Via: SIP/2.0/UDP 192.98.102.10:5090;branch=z9hG4bKSbAakagf;rport..From: sip:[email protected];tag=6CC3C886-5226E100000C3A1C-68FE7700..To: sip:[email protected];tag=c02670ad1171fe45d9ff9a27d6c2cb82-d1db..CSeq: 11 INVITE..Call-ID: 6900B3D5-5226E100000C3A2F-68FE7700..Contact: <sip:192.98.102.10:5090>..Max-Forwards: 16..Allow: INVITE,ACK,BYE,CANCEL,OPTIONS,PRACK,REFER,NOTIFY,SUBSCRIBE,INFO,MESSAGE..Supported: replaces,norefersub,100rel..User-Agent: Twinkle/1.4.2..Supported: 100rel..Content-Type: application/sdp..Content-Length: 317....v=0..o=twinkle 1496944675 932308098 IN IP4 192.98.102.10..s=-..c=IN IP4 192.98.102.10..t=0 0..m=audio 8002 RTP/AVP 97 98 8 0 101..a=rtpmap:97 speex/8000..a=rtpmap:98 speex/16000..a=rtpmap:8 PCMA/8000..a=rtpmap:0 PCMU/8000..a=rtpmap:101 telephone-event/8000..a=fmtp:101 0-15..a=sendrecv..a=ptime:20..a=direc tion:both..--++-- _______________________________________________ Sems mailing list [email protected] http://lists.iptel.org/mailman/listinfo/sems
