<div>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. </div><div><br></div><div>
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!"</div>
<div><br></div><div>sip proxy: 10.14.84.203</div><div>MG: 10.14.84.183</div><div>External system: 10.10.24.36</div><div><br></div><div>I'm wondering:</div><div>* Can/should I prevent osips from sending the 500 on my behalf?</div>
<div>* Why are the ACKs ignored by osips?</div><div><br></div><div>failure_route[11] {</div><div><br></div><div> if (t_was_cancelled()) {</div><div> exit;</div><div> }</div><div><br></div><div> if ( ($T_reply_code=="604") || ($T_reply_code=="404") || ($T_reply_code=="486") ) {</div>
<div> xlog("L_WARN", "Received $T_reply_code from NVP:$avp(i:271) for callid [$ci] - DID is most likely not configured");</div><div> route(5);</div><div> }</div><div>
<br></div><div> xlog("L_WARN","Route failed - $avp(i:271) $avp(i:272) $avp(i:273)");</div><div> xlog("Details - (mf [$mF] ruri [$ru] callid [$ci])");</div><div><br></div><div> # ds_next_dst - will do the routing.</div>
<div> if (ds_next_dst()){</div><div> xlog("L_INFO","First Route Failed : Routing to $avp(i:271) $avp(i:272) $avp(i:273)");</div><div> xlog("Details - (mf [$mF] ruri [$ru] callid [$ci])");</div>
<div> xlog("L_INFO"," ");</div><div><br></div><div> # relay the call to the new destination</div><div> t_on_failure("11");</div><div> t_relay();</div>
<div> }</div><div> else {</div><div> xlog("L_CRIT","ds_dispatcher Sorry none of our gateways are available to take your call.");</div><div><span class="Apple-tab-span" style="white-space:pre"> </span>exit;</div>
<div> }</div><div> </div><div>}</div><div><br></div><div><br></div><div>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</div>
<div>Jul 17 10:38:35 siphost /usr/sbin/opensips[27595]: DBG:tm:set_timer: relative timeout is 2000000</div><div>Jul 17 10:38:35 siphost /usr/sbin/opensips[27595]: DBG:tm:insert_timer_unsafe: [6]: 0x2af44b39a2f8 (14600000)</div>
<div>Jul 17 10:38:35 siphost /usr/sbin/opensips[27595]: DBG:tm:retransmission_handler: retransmission_handler : done</div><div>Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]: DBG:core:parse_msg: SIP Request:</div><div>
Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]: DBG:core:parse_msg: method: <ACK></div><div>Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]: DBG:core:parse_msg: uri: <<a href="http://sip:2025551212@10.14.84.203:5060">sip:2025551212@10.14.84.203:5060</a>></div>
<div>Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]: DBG:core:parse_msg: version: <SIP/2.0></div><div>Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]: DBG:core:parse_headers: flags=2</div><div>Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK02B027d670e963c415e>; state=16</div>
<div>Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]: DBG:core:parse_via: end of header reached, state=5</div><div>Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]: DBG:core:parse_headers: via found, flags=2</div><div>
Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]: DBG:core:parse_headers: this is the first via</div><div>Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]: DBG:core:receive_msg: After parse_msg...</div><div>Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]: DBG:core:receive_msg: preparing to run routing scripts...</div>
<div>Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]: DBG:sl:sl_filter_ACK: to late to be a local ACK!</div><div>Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]: DBG:core:comp_scriptvar: str 20 : true</div><div>Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]: DBG:core:parse_headers: flags=100</div>
<div>Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]: DBG:core:parse_to_param: tag=aeac620b</div><div>Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]: DBG:core:parse_to: end of header reached, state=29</div><div>Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]: DBG:core:parse_to: display={}, ruri={<a href="http://sip:2025551212@10.14.84.203:5060">sip:2025551212@10.14.84.203:5060</a>}</div>
<div>Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]: DBG:core:get_hdr_field: <To> [49]; uri=[<a href="http://sip:2025551212@10.14.84.203:5060">sip:2025551212@10.14.84.203:5060</a>]</div><div>Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]: DBG:core:get_hdr_field: to body [<<a href="http://sip:2025551212@10.14.84.203:5060">sip:2025551212@10.14.84.203:5060</a>>]</div>
<div>Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]: DBG:core:get_hdr_field: cseq <CSeq>: <25848> <ACK></div><div>Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]: DBG:maxfwd:is_maxfwd_present: value = 70</div>
<div>Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]: DBG:core:destroy_avp_list: destroying list 0x2af44b39a010</div><div>Jul 17 10:38:35 siphost /usr/sbin/opensips[27582]: DBG:core:receive_msg: cleaning up</div><div>Jul 17 10:38:36 siphost /usr/sbin/opensips[27595]: DBG:tm:timer_routine: timer routine:0,tl=0x2af44b39a5d8 next=0x2af44b39a7b0, timeout=13</div>
<div>Jul 17 10:38:36 siphost /usr/sbin/opensips[27595]: DBG:tm:timer_routine: timer routine:0,tl=0x2af44b39a7b0 next=0x2af44b39a988, timeout=13</div><div>Jul 17 10:38:36 siphost /usr/sbin/opensips[27595]: DBG:tm:timer_routine: timer routine:0,tl=0x2af44b39a988 next=0x2af44b39a328, timeout=13</div>
<div>Jul 17 10:38:36 siphost /usr/sbin/opensips[27595]: DBG:tm:timer_routine: timer routine:0,tl=0x2af44b39a328 next=(nil), timeout=13</div><div>Jul 17 10:38:36 siphost /usr/sbin/opensips[27595]: DBG:tm:insert_timer_unsafe: [2]: 0x2af44b39a230 (18)</div>
<div><br></div><div><br></div><div>U <a href="http://10.14.84.203:5060">10.14.84.203:5060</a> -> <a href="http://10.14.84.183:5060">10.14.84.183:5060</a></div><div>INVITE <a href="http://sip:2025551212@10.14.84.203:5060">sip:2025551212@10.14.84.203:5060</a> SIP/2.0.</div>
<div>Via: SIP/2.0/UDP 10.14.84.203;branch=z9hG4bK050f.4234dfd2.3.</div><div>Via: SIP/2.0/UDP 10.10.24.36:5060;branch=z9hG4bK02B027d670e963c415e.</div><div>From: <sip:9995551212@10.10.24.36:5060;pstn-params=9084818088>;tag=gK0201303f.</div>
<div>To: <<a href="http://sip:2025551212@10.14.84.203:5060">sip:2025551212@10.14.84.203:5060</a>>.</div><div>Call-ID: <a href="mailto:335708310_82542752@10.10.24.36">335708310_82542752@10.10.24.36</a>.</div><div>CSeq: 25848 INVITE.</div>
<div>Max-Forwards: 13.</div><div>Allow: INVITE, ACK, CANCEL, BYE, REGISTER, REFER, INFO, SUBSCRIBE, NOTIFY, PRACK, UPDATE, OPTIONS, MESSAGE, PUBLISH.</div><div>Accept: application/sdp, application/isup, application/dtmf, application/dtmf-relay, multipart/mixed.</div>
<div>Contact: <<a href="http://sip:9995551212@10.10.24.36:5060">sip:9995551212@10.10.24.36:5060</a>>.</div><div>P-Asserted-Identity: "9995551212" <<a href="http://sip:9995551212@10.10.24.36:5060">sip:9995551212@10.10.24.36:5060</a>>, "9995551212" <tel:9995551212>.</div>
<div>Supported: timer, 100rel.</div><div>Session-Expires: 1800.</div><div>Min-SE: 90.</div><div>Content-Disposition: session; handling=required.</div><div>Content-Type: application/sdp.</div><div>Content-Length: 314.</div>
<div>.</div><div>v=0.</div><div>o=Sonus_UAC 11709 17649 IN IP4 10.10.24.36.</div><div>s=SIP Media Capabilities.</div><div>c=IN IP4 216.115.26.209.</div><div>t=0 0.</div><div>m=audio 11676 RTP/AVP 0 18 2 100.</div><div>a=rtpmap:0 PCMU/8000.</div>
<div>a=rtpmap:18 G729/8000.</div><div>a=fmtp:18 annexb=no.</div><div>a=rtpmap:2 G726-32/8000.</div><div>a=rtpmap:100 telephone-event/8000.</div><div>a=fmtp:100 0-15.</div><div>a=sendrecv.</div><div>a=maxptime:20.</div><div>
<br></div><div><br></div><div>U <a href="http://10.14.84.183:5060">10.14.84.183:5060</a> -> <a href="http://10.14.84.203:5060">10.14.84.203:5060</a></div><div>SIP/2.0 503 Service Unavailable.</div><div>Via: SIP/2.0/UDP 10.14.84.203;branch=z9hG4bK050f.4234dfd2.3.</div>
<div>Via: SIP/2.0/UDP 10.10.24.36:5060;branch=z9hG4bK02B027d670e963c415e.</div><div>To: <<a href="http://sip:2025551212@10.14.84.203:5060">sip:2025551212@10.14.84.203:5060</a>>;tag=aeac620b.</div><div>From: <sip:9995551212@10.10.24.36:5060;pstn-params=9084818088>;tag=gK0201303f.</div>
<div>Call-ID: <a href="mailto:335708310_82542752@10.10.24.36">335708310_82542752@10.10.24.36</a>.</div><div>CSeq: 25848 INVITE.</div><div>User-Agent: NVP/4.0.1-CT79038 .</div><div>Content-Length: 0.</div><div>.</div><div>
<br></div><div>U <a href="http://10.14.84.203:5060">10.14.84.203:5060</a> -> <a href="http://10.14.84.183:5060">10.14.84.183:5060</a></div><div>ACK <a href="http://sip:2025551212@10.14.84.203:5060">sip:2025551212@10.14.84.203:5060</a> SIP/2.0.</div>
<div>Via: SIP/2.0/UDP 10.14.84.203;branch=z9hG4bK050f.4234dfd2.3.</div><div>From: <sip:9995551212@10.10.24.36:5060;pstn-params=9084818088>;tag=gK0201303f.</div><div>Call-ID: <a href="mailto:335708310_82542752@10.10.24.36">335708310_82542752@10.10.24.36</a>.</div>
<div>To: <<a href="http://sip:2025551212@10.14.84.203:5060">sip:2025551212@10.14.84.203:5060</a>>;tag=aeac620b.</div><div>CSeq: 25848 ACK.</div><div>Max-Forwards: 70.</div><div>User-Agent: OpenSIPS (1.6.2-notls (x86_64/linux)).</div>
<div>Content-Length: 0.</div><div>.</div><div><br></div><div>U <a href="http://10.14.84.203:5060">10.14.84.203:5060</a> -> external:5060</div><div>SIP/2.0 500 Service Unavailable.</div><div>Via: SIP/2.0/UDP 10.10.24.36:5060;branch=z9hG4bK02B027d670e963c415e.</div>
<div>To: <<a href="http://sip:2025551212@10.14.84.203:5060">sip:2025551212@10.14.84.203:5060</a>>;tag=aeac620b.</div><div>From: <sip:9995551212@10.10.24.36:5060;pstn-params=9084818088>;tag=gK0201303f.</div><div>
Call-ID: <a href="mailto:335708310_82542752@10.10.24.36">335708310_82542752@10.10.24.36</a>.</div><div>CSeq: 25848 INVITE.</div><div>User-Agent: NVP/4.0.1-CT79038 .</div><div>Content-Length: 0.</div><div>.</div><div><br>
</div>
<div>U <a href="http://10.10.24.36:5060">10.10.24.36:5060</a> -> <a href="http://10.14.84.203:5060">10.14.84.203:5060</a></div><div>ACK <a href="http://sip:2025551212@10.14.84.203:5060">sip:2025551212@10.14.84.203:5060</a> SIP/2.0.</div>
<div>Via: SIP/2.0/UDP 10.10.24.36:5060;branch=z9hG4bK02B027d670e963c415e.</div><div>From: <sip:9995551212@10.10.24.36:5060;pstn-params=9084818088>;tag=gK0201303f.</div><div>To: <<a href="http://sip:2025551212@10.14.84.203:5060">sip:2025551212@10.14.84.203:5060</a>>;tag=aeac620b.</div>
<div>Call-ID: <a href="mailto:335708310_82542752@10.10.24.36">335708310_82542752@10.10.24.36</a>.</div><div>CSeq: 25848 ACK.</div><div>Max-Forwards: 70.</div><div>Content-Length: 0.</div><div>.</div><div><br></div><div>U <a href="http://10.14.84.203:5060">10.14.84.203:5060</a> -> <a href="http://10.10.24.36:5060">10.10.24.36:5060</a></div>
<div>SIP/2.0 500 Service Unavailable.</div><div>Via: SIP/2.0/UDP 10.10.24.36:5060;branch=z9hG4bK02B027d670e963c415e.</div><div>To: <<a href="http://sip:2025551212@10.14.84.203:5060">sip:2025551212@10.14.84.203:5060</a>>;tag=aeac620b.</div>
<div>From: <sip:9995551212@10.10.24.36:5060;pstn-params=9084818088>;tag=gK0201303f.</div><div>Call-ID: <a href="mailto:335708310_82542752@10.10.24.36">335708310_82542752@10.10.24.36</a>.</div><div>CSeq: 25848 INVITE.</div>
<div>User-Agent: NVP/4.0.1-CT79038 .</div><div>Content-Length: 0.</div><div>.</div><div><br></div><div>U <a href="http://10.10.24.36:5060">10.10.24.36:5060</a> -> <a href="http://10.14.84.203:5060">10.14.84.203:5060</a></div>
<div>ACK <a href="http://sip:2025551212@10.14.84.203:5060">sip:2025551212@10.14.84.203:5060</a> SIP/2.0.</div><div>Via: SIP/2.0/UDP 10.10.24.36:5060;branch=z9hG4bK02B027d670e963c415e.</div><div>From: <sip:9995551212@10.10.24.36:5060;pstn-params=9084818088>;tag=gK0201303f.</div>
<div>To: <<a href="http://sip:2025551212@10.14.84.203:5060">sip:2025551212@10.14.84.203:5060</a>>;tag=aeac620b.</div><div>Call-ID: <a href="mailto:335708310_82542752@10.10.24.36">335708310_82542752@10.10.24.36</a>.</div>
<div>CSeq: 25848 ACK.</div><div>Max-Forwards: 70.</div><div>Content-Length: 0.</div><div>.</div><div><br></div><div>U <a href="http://10.14.84.203:5060">10.14.84.203:5060</a> -> <a href="http://10.10.24.36:5060">10.10.24.36:5060</a></div>
<div>SIP/2.0 500 Service Unavailable.</div><div>Via: SIP/2.0/UDP 10.10.24.36:5060;branch=z9hG4bK02B027d670e963c415e.</div><div>To: <<a href="http://sip:2025551212@10.14.84.203:5060">sip:2025551212@10.14.84.203:5060</a>>;tag=aeac620b.</div>
<div>From: <sip:9995551212@10.10.24.36:5060;pstn-params=9084818088>;tag=gK0201303f.</div><div>Call-ID: <a href="mailto:335708310_82542752@10.10.24.36">335708310_82542752@10.10.24.36</a>.</div><div>CSeq: 25848 INVITE.</div>
<div>User-Agent: NVP/4.0.1-CT79038 .</div><div>Content-Length: 0.</div><div>.</div><div><br></div><div>U <a href="http://10.10.24.36:5060">10.10.24.36:5060</a> -> <a href="http://10.14.84.203:5060">10.14.84.203:5060</a></div>
<div>ACK <a href="http://sip:2025551212@10.14.84.203:5060">sip:2025551212@10.14.84.203:5060</a> SIP/2.0.</div><div>Via: SIP/2.0/UDP 10.10.24.36:5060;branch=z9hG4bK02B027d670e963c415e.</div><div>From: <sip:9995551212@10.10.24.36:5060;pstn-params=9084818088>;tag=gK0201303f.</div>
<div>To: <<a href="http://sip:2025551212@10.14.84.203:5060">sip:2025551212@10.14.84.203:5060</a>>;tag=aeac620b.</div><div>Call-ID: <a href="mailto:335708310_82542752@10.10.24.36">335708310_82542752@10.10.24.36</a>.</div>
<div>CSeq: 25848 ACK.</div><div>Max-Forwards: 70.</div><div>Content-Length: 0.</div><div>.</div><div><br></div><div>-- </div><div>Thanks,</div><div>Tim</div><div><br></div><div><div><div><div><div>.</div><div><br></div>-- <br>
Thanks,<br>Tim<br><br><br>
</div></div></div></div>