Hi Tim,
Could you send my (off list) the logs (in debug 4) covering the entire
call (invite to last 500 retransmission) ?
Regarding the 500 - by default, in failure route, the received reply is
forwarded to caller - in your case, the received 503 is fwded as 500
back (there is a translation from 503 to 500, according to RFC)
Regards,
Bogdan-Andrei Iancu
OpenSIPS Founder and Developer
http://www.opensips-solutions.com
On 07/17/2012 09:10 PM, Tim Burke wrote:
Sorry about the large posting but I wanted to included as many details
a possible. I'm trying to figure out why opensips seems to be
ignoring ACK received from far end when a 500 is sent.
This code in play is in my failure_route where I'm reacting to 503
received from my internal media gateway. It seems like osips is
sending a 500 on my behalf even if I just exit the failure_route. The
far end relies to the 500 with an ACK but osips seems to now like it
and repeats the process for a total of 3 500 messages sent out. I'm
on osips 1.6.2 and have the following in the log. I'm not sure of the
significance of: "Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]:
DBG:sl:sl_filter_ACK: to late to be a local ACK!"
sip proxy: 10.14.84.203
MG: 10.14.84.183
External system: 10.10.24.36
I'm wondering:
* Can/should I prevent osips from sending the 500 on my behalf?
* Why are the ACKs ignored by osips?
failure_route[11] {
if (t_was_cancelled()) {
exit;
}
if ( ($T_reply_code=="604") || ($T_reply_code=="404") ||
($T_reply_code=="486") ) {
xlog("L_WARN", "Received $T_reply_code from
NVP:$avp(i:271) for callid [$ci] - DID is most likely not configured");
route(5);
}
xlog("L_WARN","Route failed - $avp(i:271) $avp(i:272)
$avp(i:273)");
xlog("Details - (mf [$mF] ruri [$ru] callid [$ci])");
# ds_next_dst - will do the routing.
if (ds_next_dst()){
xlog("L_INFO","First Route Failed : Routing to
$avp(i:271) $avp(i:272) $avp(i:273)");
xlog("Details - (mf [$mF] ruri [$ru] callid [$ci])");
xlog("L_INFO"," ");
# relay the call to the new destination
t_on_failure("11");
t_relay();
}
else {
xlog("L_CRIT","ds_dispatcher Sorry none of our
gateways are available to take your call.");
exit;
}
}
Jul 17 10:38:35 siphost /usr/sbin/opensips[27595]:
DBG:tm:t_retransmit_reply: buf=0x2af449a51620: SIP/2.0 5...,
shmem=0x2af44b3a0fa8: SIP/2.0 5
Jul 17 10:38:35 siphost /usr/sbin/opensips[27595]: DBG:tm:set_timer:
relative timeout is 2000000
Jul 17 10:38:35 siphost /usr/sbin/opensips[27595]:
DBG:tm:insert_timer_unsafe: [6]: 0x2af44b39a2f8 (14600000)
Jul 17 10:38:35 siphost /usr/sbin/opensips[27595]:
DBG:tm:retransmission_handler: retransmission_handler : done
Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]: DBG:core:parse_msg:
SIP Request:
Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]: DBG:core:parse_msg:
method: <ACK>
Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]: DBG:core:parse_msg:
uri: <sip:[email protected]:5060
<http://sip:[email protected]:5060>>
Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]: DBG:core:parse_msg:
version: <SIP/2.0>
Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]:
DBG:core:parse_headers: flags=2
Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]:
DBG:core:parse_via_param: found param type 232, <branch> =
<z9hG4bK02B027d670e963c415e>; state=16
Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]: DBG:core:parse_via:
end of header reached, state=5
Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]:
DBG:core:parse_headers: via found, flags=2
Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]:
DBG:core:parse_headers: this is the first via
Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]:
DBG:core:receive_msg: After parse_msg...
Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]:
DBG:core:receive_msg: preparing to run routing scripts...
Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]:
DBG:sl:sl_filter_ACK: to late to be a local ACK!
Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]:
DBG:core:comp_scriptvar: str 20 : true
Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]:
DBG:core:parse_headers: flags=100
Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]:
DBG:core:parse_to_param: tag=aeac620b
Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]: DBG:core:parse_to:
end of header reached, state=29
Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]: DBG:core:parse_to:
display={}, ruri={sip:[email protected]:5060
<http://sip:[email protected]:5060>}
Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]:
DBG:core:get_hdr_field: <To> [49];
uri=[sip:[email protected]:5060
<http://sip:[email protected]:5060>]
Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]:
DBG:core:get_hdr_field: to body [<sip:[email protected]:5060
<http://sip:[email protected]:5060>>]
Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]:
DBG:core:get_hdr_field: cseq <CSeq>: <25848> <ACK>
Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]:
DBG:maxfwd:is_maxfwd_present: value = 70
Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]:
DBG:core:destroy_avp_list: destroying list 0x2af44b39a010
Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]:
DBG:core:receive_msg: cleaning up
Jul 17 10:38:36 siphost /usr/sbin/opensips[27595]:
DBG:tm:timer_routine: timer routine:0,tl=0x2af44b39a5d8
next=0x2af44b39a7b0, timeout=13
Jul 17 10:38:36 siphost /usr/sbin/opensips[27595]:
DBG:tm:timer_routine: timer routine:0,tl=0x2af44b39a7b0
next=0x2af44b39a988, timeout=13
Jul 17 10:38:36 siphost /usr/sbin/opensips[27595]:
DBG:tm:timer_routine: timer routine:0,tl=0x2af44b39a988
next=0x2af44b39a328, timeout=13
Jul 17 10:38:36 siphost /usr/sbin/opensips[27595]:
DBG:tm:timer_routine: timer routine:0,tl=0x2af44b39a328 next=(nil),
timeout=13
Jul 17 10:38:36 siphost /usr/sbin/opensips[27595]:
DBG:tm:insert_timer_unsafe: [2]: 0x2af44b39a230 (18)
U 10.14.84.203:5060 <http://10.14.84.203:5060> -> 10.14.84.183:5060
<http://10.14.84.183:5060>
INVITE sip:[email protected]:5060
<http://sip:[email protected]:5060> SIP/2.0.
Via: SIP/2.0/UDP 10.14.84.203;branch=z9hG4bK050f.4234dfd2.3.
Via: SIP/2.0/UDP 10.10.24.36:5060;branch=z9hG4bK02B027d670e963c415e.
From:
<sip:[email protected]:5060;pstn-params=9084818088>;tag=gK0201303f.
To: <sip:[email protected]:5060
<http://sip:[email protected]:5060>>.
Call-ID: [email protected]
<mailto:[email protected]>.
CSeq: 25848 INVITE.
Max-Forwards: 13.
Allow: INVITE, ACK, CANCEL, BYE, REGISTER, REFER, INFO, SUBSCRIBE,
NOTIFY, PRACK, UPDATE, OPTIONS, MESSAGE, PUBLISH.
Accept: application/sdp, application/isup, application/dtmf,
application/dtmf-relay, multipart/mixed.
Contact: <sip:[email protected]:5060
<http://sip:[email protected]:5060>>.
P-Asserted-Identity: "9995551212" <sip:[email protected]:5060
<http://sip:[email protected]:5060>>, "9995551212" <tel:9995551212>.
Supported: timer, 100rel.
Session-Expires: 1800.
Min-SE: 90.
Content-Disposition: session; handling=required.
Content-Type: application/sdp.
Content-Length: 314.
.
v=0.
o=Sonus_UAC 11709 17649 IN IP4 10.10.24.36.
s=SIP Media Capabilities.
c=IN IP4 216.115.26.209.
t=0 0.
m=audio 11676 RTP/AVP 0 18 2 100.
a=rtpmap:0 PCMU/8000.
a=rtpmap:18 G729/8000.
a=fmtp:18 annexb=no.
a=rtpmap:2 G726-32/8000.
a=rtpmap:100 telephone-event/8000.
a=fmtp:100 0-15.
a=sendrecv.
a=maxptime:20.
U 10.14.84.183:5060 <http://10.14.84.183:5060> -> 10.14.84.203:5060
<http://10.14.84.203:5060>
SIP/2.0 503 Service Unavailable.
Via: SIP/2.0/UDP 10.14.84.203;branch=z9hG4bK050f.4234dfd2.3.
Via: SIP/2.0/UDP 10.10.24.36:5060;branch=z9hG4bK02B027d670e963c415e.
To: <sip:[email protected]:5060
<http://sip:[email protected]:5060>>;tag=aeac620b.
From:
<sip:[email protected]:5060;pstn-params=9084818088>;tag=gK0201303f.
Call-ID: [email protected]
<mailto:[email protected]>.
CSeq: 25848 INVITE.
User-Agent: NVP/4.0.1-CT79038 .
Content-Length: 0.
.
U 10.14.84.203:5060 <http://10.14.84.203:5060> -> 10.14.84.183:5060
<http://10.14.84.183:5060>
ACK sip:[email protected]:5060
<http://sip:[email protected]:5060> SIP/2.0.
Via: SIP/2.0/UDP 10.14.84.203;branch=z9hG4bK050f.4234dfd2.3.
From:
<sip:[email protected]:5060;pstn-params=9084818088>;tag=gK0201303f.
Call-ID: [email protected]
<mailto:[email protected]>.
To: <sip:[email protected]:5060
<http://sip:[email protected]:5060>>;tag=aeac620b.
CSeq: 25848 ACK.
Max-Forwards: 70.
User-Agent: OpenSIPS (1.6.2-notls (x86_64/linux)).
Content-Length: 0.
.
U 10.14.84.203:5060 <http://10.14.84.203:5060> -> external:5060
SIP/2.0 500 Service Unavailable.
Via: SIP/2.0/UDP 10.10.24.36:5060;branch=z9hG4bK02B027d670e963c415e.
To: <sip:[email protected]:5060
<http://sip:[email protected]:5060>>;tag=aeac620b.
From:
<sip:[email protected]:5060;pstn-params=9084818088>;tag=gK0201303f.
Call-ID: [email protected]
<mailto:[email protected]>.
CSeq: 25848 INVITE.
User-Agent: NVP/4.0.1-CT79038 .
Content-Length: 0.
.
U 10.10.24.36:5060 <http://10.10.24.36:5060> -> 10.14.84.203:5060
<http://10.14.84.203:5060>
ACK sip:[email protected]:5060
<http://sip:[email protected]:5060> SIP/2.0.
Via: SIP/2.0/UDP 10.10.24.36:5060;branch=z9hG4bK02B027d670e963c415e.
From:
<sip:[email protected]:5060;pstn-params=9084818088>;tag=gK0201303f.
To: <sip:[email protected]:5060
<http://sip:[email protected]:5060>>;tag=aeac620b.
Call-ID: [email protected]
<mailto:[email protected]>.
CSeq: 25848 ACK.
Max-Forwards: 70.
Content-Length: 0.
.
U 10.14.84.203:5060 <http://10.14.84.203:5060> -> 10.10.24.36:5060
<http://10.10.24.36:5060>
SIP/2.0 500 Service Unavailable.
Via: SIP/2.0/UDP 10.10.24.36:5060;branch=z9hG4bK02B027d670e963c415e.
To: <sip:[email protected]:5060
<http://sip:[email protected]:5060>>;tag=aeac620b.
From:
<sip:[email protected]:5060;pstn-params=9084818088>;tag=gK0201303f.
Call-ID: [email protected]
<mailto:[email protected]>.
CSeq: 25848 INVITE.
User-Agent: NVP/4.0.1-CT79038 .
Content-Length: 0.
.
U 10.10.24.36:5060 <http://10.10.24.36:5060> -> 10.14.84.203:5060
<http://10.14.84.203:5060>
ACK sip:[email protected]:5060
<http://sip:[email protected]:5060> SIP/2.0.
Via: SIP/2.0/UDP 10.10.24.36:5060;branch=z9hG4bK02B027d670e963c415e.
From:
<sip:[email protected]:5060;pstn-params=9084818088>;tag=gK0201303f.
To: <sip:[email protected]:5060
<http://sip:[email protected]:5060>>;tag=aeac620b.
Call-ID: [email protected]
<mailto:[email protected]>.
CSeq: 25848 ACK.
Max-Forwards: 70.
Content-Length: 0.
.
U 10.14.84.203:5060 <http://10.14.84.203:5060> -> 10.10.24.36:5060
<http://10.10.24.36:5060>
SIP/2.0 500 Service Unavailable.
Via: SIP/2.0/UDP 10.10.24.36:5060;branch=z9hG4bK02B027d670e963c415e.
To: <sip:[email protected]:5060
<http://sip:[email protected]:5060>>;tag=aeac620b.
From:
<sip:[email protected]:5060;pstn-params=9084818088>;tag=gK0201303f.
Call-ID: [email protected]
<mailto:[email protected]>.
CSeq: 25848 INVITE.
User-Agent: NVP/4.0.1-CT79038 .
Content-Length: 0.
.
U 10.10.24.36:5060 <http://10.10.24.36:5060> -> 10.14.84.203:5060
<http://10.14.84.203:5060>
ACK sip:[email protected]:5060
<http://sip:[email protected]:5060> SIP/2.0.
Via: SIP/2.0/UDP 10.10.24.36:5060;branch=z9hG4bK02B027d670e963c415e.
From:
<sip:[email protected]:5060;pstn-params=9084818088>;tag=gK0201303f.
To: <sip:[email protected]:5060
<http://sip:[email protected]:5060>>;tag=aeac620b.
Call-ID: [email protected]
<mailto:[email protected]>.
CSeq: 25848 ACK.
Max-Forwards: 70.
Content-Length: 0.
.
--
Thanks,
Tim
.
--
Thanks,
Tim
_______________________________________________
Users mailing list
[email protected]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users
_______________________________________________
Users mailing list
[email protected]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users
