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...@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...@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...@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...@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...@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...@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@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@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
_______________________________________________ SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
