3.20: Kamailio Issue with 302 Redirects?

680 views
Skip to first unread message

Dayton Turner

unread,
May 28, 2015, 9:08:54 PM5/28/15
to 2600h...@googlegroups.com
Hi guys,

More 3.20 kamailio config testing going on.  Noticing that whenever kazoo generates a 302 redirect to move a phone to another media server, the call is failing.  Digging through logs, I see this in the kamailio logs:

May 29 00:55:29 sbc02 kamailio[13194]: INFO: <script>: 01oMPXADT6X2CJ28iP.TAnMPI4OwGSCN|start|recieved internal reply 100 Trying
May 29 00:55:29 sbc02 kamailio[13194]: INFO: <script>: 01oMPXADT6X2CJ28iP.TAnMPI4OwGSCN|log|source 74.114.21.2:11000
May 29 00:55:29 sbc02 kamailio[13194]: INFO: <script>: 01oMPXADT6X2CJ28iP.TAnMPI4OwGSCN|pass|70.11.28.22:64385
May 29 00:55:29 sbc02 kamailio[13135]: INFO: <script>: 01oMPXADT6X2CJ28iP.TAnMPI4OwGSCN|start|recieved internal reply 302 Moved Temporarily
May 29 00:55:29 sbc02 kamailio[13135]: INFO: <script>: 01oMPXADT6X2CJ28iP.TAnMPI4OwGSCN|log|source 74.114.21.2:11000
May 29 00:55:29 sbc02 kamailio[13135]: INFO: <script>: 01oMPXADT6X2CJ28iP.TAnMPI4OwGSCN|log|stored redirect mapping daytons...@realm.com->*11...@realm.com to sip:74.114.21.3:11000
May 29 00:55:29 sbc02 kamailio[13135]: INFO: <script>: 01oMPXADT6X2CJ28iP.TAnMPI4OwGSCN|log|failure route ignoring reply 302 <null>
May 29 00:55:29 sbc02 kamailio[13135]: INFO: <script>: 01oMPXADT6X2CJ28iP.TAnMPI4OwGSCN|pass|70.11.28.22:64385

The 302 does make its way back to the phone on my desk, but it has the X-Redirect-Server header still set, and thats the only place that the 'next hop server' is listed - the phone ACK's the 302, but then never issues another INVITE or anything at all to connect to the new server.

The log line above stating failure route, ignoring reply 302 <null> stands out of course.

Any thoughts on what could be happening?

Dayton

Dayton Turner

unread,
May 30, 2015, 3:01:47 PM5/30/15
to 2600h...@googlegroups.com
OK More to report, but can confirm that 302 redirects are currently not functioning correctly :( Any kamailio experts want to weigh in?

Here's where Kamailio starts when observing that a 302 needs to be handled:

As you can see, it stores the redirect (as evidenced by the log output from my previous post, as well)

At the end of the block of code I've highlighted, Kamailio should be removing all X-Headers from the SIP message.

The "Failure route ignoring reply 302 <null>" happens because the if conditions end up here:


But that is "ok" because all of this happened in the first place because of this:


(We were in INTERNAL_FAULT)

After we exit INTERNAL_FAULT, we continue on eventually to t_relay() which passes the 302 back to the client (this does occur)

However, the 302 that ends up reaching the SIP UA looks like this:


Notice that it still contains the X-Redirect-Server header?  Ive tried injecting more instances of remove_hf_re("^X-.*"); even within the "stored redirect mapping..." codeblock, the X- headers are still present.

Aside from that being "odd", the SIP UA ACK's the 302, but then never sends another invite out after that.  I've tried with multiple phones, Polycom, Aastra, Soft clients, they all seem to just give up at this point.

I have to presume that the intention here, is to have the phone 302 back to Kamailio itself (rather than modifying the Contact or Diversion headers to instruct the endpoint to go talk to the FS server directly), and when the INVITE comes back to the SBC, it will do a lookup in the redirect htable that it just stored some data in to, and handle redirecting the client to the appropriate FS server from there.  That all makes sense, and from reading the dispatcher-role config, it appears it should work that way.

Just gotta figure out why the endpoint is receiving the 302 and giving up.  Anyone see anything in that packet that looks wrong?  Also kind of confusing that the X- headers are still there despite asking to remove them.

This is Kamailio 4.2.3, and the configs are from the master branch of kazoo-configs

The callflow im using to get this to happen in the first place is cf_eavesdrop_function, and it builds a 302 when the server the call i am trying to eavesdrop lives on a different FS server than the one my eavesdrop request call was received on.




On Thursday, 28 May 2015 18:08:54 UTC-7, Dayton Turner wrote:
Hi guys,

More 3.20 kamailio config testing going on.  Noticing that whenever kazoo generates a 302 redirect to move a phone to another media server, the call is failing.  Digging through logs, I see this in the kamailio logs:

May 29 00:55:29 sbc02 kamailio[13194]: INFO: <script>: 01oMPXADT6X2CJ28iP.TAnMPI4OwGSCN|start|recieved internal reply 100 Trying
May 29 00:55:29 sbc02 kamailio[13194]: INFO: <script>: 01oMPXADT6X2CJ28iP.TAnMPI4OwGSCN|log|source 74.114.21.2:11000
May 29 00:55:29 sbc02 kamailio[13194]: INFO: <script>: 01oMPXADT6X2CJ28iP.TAnMPI4OwGSCN|pass|70.11.28.22:64385
May 29 00:55:29 sbc02 kamailio[13135]: INFO: <script>: 01oMPXADT6X2CJ28iP.TAnMPI4OwGSCN|start|recieved internal reply 302 Moved Temporarily
May 29 00:55:29 sbc02 kamailio[13135]: INFO: <script>: 01oMPXADT6X2CJ28iP.TAnMPI4OwGSCN|log|source 74.114.21.2:11000
May 29 00:55:29 sbc02 kamailio[13135]: INFO: <script>: 01oMPXADT6X2CJ28iP.TAnMPI4OwGSCN|log|stored redirect mapping daytons...@realm.com->*110...@realm.com to sip:74.114.21.3:11000
May 29 00:55:29 sbc02 kamailio[13135]: INFO: <script>: 01oMPXADT6X2CJ28iP.TAnMPI4OwGSCN|log|failure route ignoring reply 302 <null>
May 29 00:55:29 sbc02 kamailio[13135]: INFO: <script>: 01oMPXADT6X2CJ28iP.TAnMPI4OwGSCN|pass|70.11.28.22:64385

Mark Diaz

unread,
May 30, 2015, 9:43:40 PM5/30/15
to 2600h...@googlegroups.com
I see the same in my Kam logs when my kazoo (3.19) attempts toy redirect. In the actual Kazoo logs, I am seeing an actual crash in ecallmgr call ctrl: (Snipped for securoty reasons - but easily reproducable)

May 31 01:30:30 apps1 2600hz[2806]: |SZ-p3mRI81OcyNh31N7iFo2.H1tqpibE|ecallmgr_call_control:990 (<0.10728.339>) inserting at the tail of the control queue call command redirect
May 31 01:30:30 apps1 2600hz[2806]: |SZ-p3mRI81OcyNh31N7iFo2.H1tqpibE|ecallmgr_call_control:1081 (<0.10728.339>) executing call command 'redirect' 8edeb86c4db841203ee18dd7eb99b1fd
May 31 01:30:30 apps1 2600hz[2806]: |SZ-p3mRI81OcyNh31N7iFo2.H1tqpibE|ecallmgr_call_control:1134 (<0.10728.339>) exception (exit) while executing redirect: {noproc,{gen_server,call,[undefined,which_children,infinity]}}
May 31 01:30:30 apps1 2600hz[2806]: |SZ-p3mRI81OcyNh31N7iFo2.H1tqpibE|wh_util:128 (<0.10728.339>) stacktrace:
May 31 01:30:30 apps1 2600hz[2806]: |SZ-p3mRI81OcyNh31N7iFo2.H1tqpibE|wh_util:135 (<0.10728.339>) st: gen_server:call/3 at (188)
May 31 01:30:30 apps1 2600hz[2806]: |SZ-p3mRI81OcyNh31N7iFo2.H1tqpibE|wh_util:135 (<0.10728.339>) st: ecallmgr_fs_node_sup:node_srv/1 at (59)
May 31 01:30:30 apps1 2600hz[2806]: |SZ-p3mRI81OcyNh31N7iFo2.H1tqpibE|wh_util:135 (<0.10728.339>) st: ecallmgr_fs_node:sip_url/1 at (223)
May 31 01:30:30 apps1 2600hz[2806]: |SZ-p3mRI81OcyNh31N7iFo2.H1tqpibE|wh_util:135 (<0.10728.339>) st: ecallmgr_call_command:fixup_redirect_node/1 at (580)
May 31 01:30:30 apps1 2600hz[2806]: |SZ-p3mRI81OcyNh31N7iFo2.H1tqpibE|wh_util:135 (<0.10728.339>) st: ecallmgr_call_command:get_fs_app/4 at (522)
May 31 01:30:30 apps1 2600hz[2806]: |SZ-p3mRI81OcyNh31N7iFo2.H1tqpibE|wh_util:135 (<0.10728.339>) st: ecallmgr_call_command:exec_cmd/5 at (26)
May 31 01:30:30 apps1 2600hz[2806]: |SZ-p3mRI81OcyNh31N7iFo2.H1tqpibE|wh_util:135 (<0.10728.339>) st: ecallmgr_call_control:execute_control_request/2 at (1092)
May 31 01:30:30 apps1 2600hz[2806]: |SZ-p3mRI81OcyNh31N7iFo2.H1tqpibE|wh_util:135 (<0.10728.339>) st: ecallmgr_call_control:handle_dialplan/2 at (878)
May 31 01:30:30 apps1 2600hz[2806]: |SZ-p3mRI81OcyNh31N7iFo2.H1tqpibE|ecallmgr_call_control:1167 (<0.10728.339>) sending execution error:

Dayton Turner

unread,
Jun 2, 2015, 4:22:22 PM6/2/15
to 2600h...@googlegroups.com
Any kamailio experts out there that might be able to weigh in on why the remove_hf_re() function isn't doing what it seemingly should, and/or what about the actual 302 packet itself might make an endpoint ACK it and then never send another INVITE?  I presume there's something formatted incorrectly within the 302, going to try and compare to a known-working 302 packet to see what might be different.

Certainly seems to be a misconfiguration within kamailio, though.

Luis Azedo

unread,
Jun 4, 2015, 10:58:37 AM6/4/15
to 2600h...@googlegroups.com
not seeing these errors with cisco / polycom / grandstream. maybe a specific UA not working ?

May 29 00:55:29 sbc02 kamailio[13135]: INFO: <script>: 01oMPXADT6X2CJ28iP.TAnMPI4OwGSCN|log|stored redirect mapping daytons...@realm.com->*11...@realm.com to sip:74.114.21.3:11000
May 29 00:55:29 sbc02 kamailio[13135]: INFO: <script>: 01oMPXADT6X2CJ28iP.TAnMPI4OwGSCN|log|failure route ignoring reply 302 <null>
May 29 00:55:29 sbc02 kamailio[13135]: INFO: <script>: 01oMPXADT6X2CJ28iP.TAnMPI4OwGSCN|pass|70.11.28.22:64385

The 302 does make its way back to the phone on my desk, but it has the X-Redirect-Server header still set, and thats the only place that the 'next hop server' is listed - the phone ACK's the 302, but then never issues another INVITE or anything at all to connect to the new server.

The log line above stating failure route, ignoring reply 302 <null> stands out of course.

Any thoughts on what could be happening?

Dayton

--
You received this message because you are subscribed to the Google Groups "2600hz-dev" group.
To unsubscribe from this group and stop receiving emails from it, send an email to 2600hz-dev+...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

Dayton Turner

unread,
Jun 5, 2015, 3:52:37 PM6/5/15
to 2600h...@googlegroups.com
I've just re-tested with polycom, and it seems to handle the redirect properly.

Testing with the following UA's results in the 302 being ACK'ed then not generating a new INVITE afterwards (resulting in the call failing):
- Aastra, "Telephone" Soft client for MacOSX

I'll try testing other UA's to see if I can add to the list, but looking at the 302 thats generated the only big thing that stands out, is one sends P-Asserted-Identity, and one uses Remote-Party-ID.

I've included the 302's that are generated for each manufacturer below:

Polycom (works): http://notepad.cc/cejaini33
Aastra (does not work): http://notepad.cc/sexune8
Telephone for OSX (does not work): http://notepad.cc/neokaizbe8

Honestly, nothing is jumping out at me, but something must be different...  Anyone have any ideas?
May 29 00:55:29 sbc02 kamailio[13135]: INFO: <script>: 01oMPXADT6X2CJ28iP.TAnMPI4OwGSCN|log|stored redirect mapping daytons...@realm.com->*110...@realm.com to sip:74.114.21.3:11000
May 29 00:55:29 sbc02 kamailio[13135]: INFO: <script>: 01oMPXADT6X2CJ28iP.TAnMPI4OwGSCN|log|failure route ignoring reply 302 <null>
May 29 00:55:29 sbc02 kamailio[13135]: INFO: <script>: 01oMPXADT6X2CJ28iP.TAnMPI4OwGSCN|pass|70.11.28.22:64385

The 302 does make its way back to the phone on my desk, but it has the X-Redirect-Server header still set, and thats the only place that the 'next hop server' is listed - the phone ACK's the 302, but then never issues another INVITE or anything at all to connect to the new server.

The log line above stating failure route, ignoring reply 302 <null> stands out of course.

Any thoughts on what could be happening?

Dayton

Dayton Turner

unread,
Jul 30, 2015, 4:42:48 PM7/30/15
to 2600hz-dev, day...@voxter.ca
Heya - so, Ive spoken to a couple of vendors who reject these 302's, and its clear now what's happening!

Many vendors (Mitel/Aastra, a number of soft phones that use the same SIP library) treat a 302 that redirects back to the exact same "To:" as a "potential loop" and prevent the new call from happening

I can understand why they'd do this, but despite this fact, we need to figure out what to do for these circumstances, where Kamailio wants to send a redirect back to the same To, in order for it to have the opportunity to honor the X-Redirect-Server header, and dispatch to a specific freeswitch node.

We could presumably slightly modify the "To" (maybe put a fwd+ in front of the destination, and then strip it back off?), or does anyone (Luis?) have any other ideas for how we might best handle this scenario?

Thx!
Dayton

On Thursday, 28 May 2015 18:08:54 UTC-7, Dayton Turner wrote:

Luis Azedo

unread,
Jul 30, 2015, 4:45:32 PM7/30/15
to 2600h...@googlegroups.com, day...@voxter.ca
Hi,

i don't want to anticipate much but this is being addressed, expect more news at KazooCon.

Best

--
You received this message because you are subscribed to the Google Groups "2600hz-dev" group.

Dayton Turner

unread,
Jul 30, 2015, 6:05:39 PM7/30/15
to Luis Azedo, 2600h...@googlegroups.com
Sounds good - chat with you then!!
--
Dayton Turner, CEO
Voxter Communications
(604) 638-3851
www.voxter.com
Reply all
Reply to author
Forward
0 new messages