[SR-Users] Rtpproxy re-INVITE handling

Thu Sep 6 08:44:09 CEST 2012

Hi Daniel,

I collected logs and a trace exhibiting this behavior.

The logs are here:
http://pastebin.com/1rQwLmx9

The trace is here:
http://pastebin.com/sXVL69tD

Thanks,
Spencer

On Aug 31, 2012, at 1:33 PM, Daniel-Constantin Mierla wrote:

> Hello,
> 
> the command to rtpproxy for the reply seem to miss the to-tag, can you grab the ngrep trace for such call and the logs for processing it? Having the logs from a different call than the ngrep trace you posted on pastebin is not helping much.
> 
> Cheers,
> Daniel
> 
> 
> On 8/31/12 6:49 PM, Spencer Thomason wrote:
>> Yes,
>> 
>> The request (re-INVITE):
>> 
>> Aug 30 22:38:59 sip /usr/sbin/kamailio[25778]: ERROR: *** cfgtrace: c=[/etc/kamailio/kamailio.cfg] l=471 a=25 n=rtpproxy_manage
>> Aug 30 22:38:59 sip rtpproxy[25671]: DBUG:handle_command: received command "25778_11 U 1952045641-6076-15 at BA.FJ.B.CFC 184.170.249.3 32122 3ae1Dvgr5vmeg;1 199857477;1"
>> Aug 30 22:38:59 sip rtpproxy[25671]: INFO:handle_command: adding strong flag to existing session, new=1/0/0
>> Aug 30 22:38:59 sip rtpproxy[25671]: INFO:handle_command: lookup on ports 55324/46010, session timer restarted
>> Aug 30 22:38:59 sip rtpproxy[25671]: DBUG:doreply: sending reply "25778_11 46010 184.170.249.8#012"
>> 
>>  
>> The reply:
>> 
>> Aug 30 22:38:59 sip /usr/sbin/kamailio[25778]: ERROR: *** cfgtrace: c=[/etc/kamailio/kamailio.cfg] l=471 a=25 n=rtpproxy_manage
>> Aug 30 22:38:59 sip rtpproxy[25671]: DBUG:handle_command: received command "25778_12 L 1952045641-6076-15 at BA.FJ.B.CFC 71.104.248.48 6016 3ae1Dvgr5vmeg;1"
>> Aug 30 22:38:59 sip rtpproxy[25671]: INFO:handle_command: lookup request failed: session 1952045641-6076-15 at BA.FJ.B.CFC, tags 3ae1Dvgr5vmeg;1/NONE not found
>> Aug 30 22:38:59 sip rtpproxy[25671]: DBUG:doreply: sending reply "25778_12 0 184.170.249.8#012"
>> Aug 30 22:38:59 sip /usr/sbin/kamailio[25778]: ERROR: rtpproxy [rtpproxy.c:2260]: incorrect port 0 in reply from rtp proxy
>> 
>>  
>> I was able to get it working correctly by reworking the config like the 3.1 branch by using rtpproxy_offer instead of force_rtp_proxy.  When I attempted to use rtpproxy_answer in the reply route, I was getting the same lookup request failed error from rtpproxy.  In the request and reply, the tags change.  Could this be the reason that the session lookup is failing?  If I use rtpproxy_offer in both the request and reply, everything works correctly.  Is there any consequence to doing this?
>> 
>> Thanks,
>> 
>> Spencer
>> 
>>  
>>  
>> On 31.08.2012 01:53, Daniel-Constantin Mierla wrote:
>> 
>>> Hello,
>>> 
>>> On 8/31/12 3:41 AM, Spencer Thomason wrote:
>>>> Hi Daniel, I can confirm that rtpproxy_manage is called. See: http://pastebin.com/ZVXjK9ry I'm seeing ERROR: rtpproxy [rtpproxy.c:2260]: incorrect port 0 in reply from rtp proxy in the logs when processing the 200OK in the re-INVITE. I've included a debug level log from rtpproxy in the log as well.
>>> this can happen because the rtpproxy was not engaged for the request, 
>>> but only for the reply.
>>> 
>>> As you say, the logs are for the 200OK, what about the ones for request, 
>>> is rtpproxy called there?
>>> 
>>> Cheers,
>>> Daniel
>>>> When handling the re-INVITE there is: • Aug 30 22:38:59 sip /usr/sbin/kamailio[25778]: ERROR: *** cfgtrace: c=[/etc/kamailio/kamailio.cfg] l=471 a=25 n=rtpproxy_manage • Aug 30 22:38:59 sip rtpproxy[25671]: DBUG:handle_command: received command "25778_11 U 1952045641-6076-15 at BA.FJ.B.CFC 184.170.249.3 32122 3ae1Dvgr5vmeg;1 199857477;1" • Aug 30 22:38:59 sip rtpproxy[25671]: INFO:handle_command: adding strong flag to existing session, new=1/0/0 • Aug 30 22:38:59 sip rtpproxy[25671]: INFO:handle_command: lookup on ports 55324/46010, session timer restarted • Aug 30 22:38:59 sip rtpproxy[25671]: DBUG:doreply: sending reply "25778_11 46010 184.170.249.8#012" but the 200OK: • Aug 30 22:38:59 sip /usr/sbin/kamailio[25778]: ERROR: *** cfgtrace: c=[/etc/kamailio/kamailio.cfg] l=471 a=25 n=rtpproxy_manage • Aug 30 22:38:59 sip rtpproxy[25671]: DBUG:handle_command: received command "25778_12 L 1952045641-6076-15 at BA.FJ.B.CFC 71.104.248.48 6016 3ae1Dvgr5vmeg;1" • Aug 30 22:38:59 sip rtpproxy[25671]: INFO:handle_command: lookup request failed: session 1952045641-6076-15 at BA.FJ.B.CFC, tags 3ae1Dvgr5vmeg;1/NONE not found • Aug 30 22:38:59 sip rtpproxy[25671]: DBUG:doreply: sending reply "25778_12 0 184.170.249.8#012" • Aug 30 22:38:59 sip /usr/sbin/kamailio[25778]: ERROR: rtpproxy [rtpproxy.c:2260]: incorrect port 0 in reply from rtp proxy I'm not familiar with the rtpproxy commands to know why it cannot locate the session. Thanks for your assistance, Spencer On Aug 30, 2012, at 11:59 AM, Daniel-Constantin Mierla wrote:
>>>>> 
>>>>> Hello, I could not spot by quick eye checking what could happen there, the best is to use the debugger module with cfg_trace parameter set and check the execution trace to see what actions of the configuration file are executed and be sure the rtpproxy is called or not. You can post the execution trace here if you need further help with it. Cheers, Daniel On 8/30/12 7:40 PM, Spencer Thomason wrote:
>>>>>> 
>>>>>> Hi Daniel, Thanks for your help with this. Here is a trace: http://pastebin.com/pXeFbwBz I see the nat=yes parameter added to the Route header. I've posted the script here: http://pastebin.com/2qwHYHvjForgive my ignorance, I can't tell what I'm doing wrong. Thanks! Spencer On Aug 30, 2012, at 12:51 AM, Daniel-Constantin Mierla wrote:
>>>>>>> 
>>>>>>> Hello, if your config it is based on the default one, the Route header for within dialog requests is marked by a parameter, nat=yes, that is used to decide whether to do rtpproxy or not. So, if you have a custom config, check the default one for the nat traversal handling part. Cheers, Daniel On 8/30/12 12:39 AM, Spencer Thomason wrote:
>>>>>>>> 
>>>>>>>> Hello, I'm using Kamailio 3.2.4 for NAT traversal using rtpproxy_manage() in a largely stock script. Everything works great until the far end (on a public ip) sends a t.38 re-INVITE. The 200OK from the NATed UAC then doesn't trigger rtpproxy and the private IP in the sdp causes the fax to fail. Any help handling these re-INVITEs would be greatly appreciated. I'm happy to post traces if that helps describe the situation. The network topology looks like this: NATed UAC -> Kamailio on a public IP -> UAS on a public IP Thanks in advance, Spencer Connected by DROID on Verizon Wireless _______________________________________________ SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users at lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
>>>>>>> -- Daniel-Constantin Mierla - http://www.asipto.com http://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda Kamailio Advanced Training, Berlin, Nov 5-8, 2012 - http://asipto.com/u/kat
>>>>> -- Daniel-Constantin Mierla - http://www.asipto.com http://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda Kamailio Advanced Training, Berlin, Nov 5-8, 2012 - http://asipto.com/u/kat
>>>> _______________________________________________ SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users at lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
> 
> -- 
> Daniel-Constantin Mierla - http://www.asipto.com
> http://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
> Kamailio Advanced Training, Berlin, Nov 5-8, 2012 - http://asipto.com/u/kat

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.sip-router.org/pipermail/sr-users/attachments/20120906/44abbde2/attachment-0001.htm>