Yate Community Forum

Yate server => SIP to H.323 proxy => Topic started by: xevyk on March 31, 2016, 05:31:54 AM

Title: No RBT during calls
Post by: xevyk on March 31, 2016, 05:31:54 AM
Hello everyone!

I've stuck with another problem. I trying to make outbounding calls from FS to CUCM through Yate (FS & Yate on one box) without RTP Forwarding because CUCM confs doesn't support faststart. Calls are successfull and media goes fine but there is no RBT.

My regexroute.conf:

${formats}^\([^,]*\)=;formats=\1
${module}^sip$=h323/${called}@10.74.100.5
${module}^h323$=sip/sip:${called}@10.74.33.70;line=freeswitch
.*=-;error=forbidden;reason=Protocol not allowed

With RTP Forwarding enabled RBT works fine, but calls dropped with error due to disabled support of faststart on CUCM.

Here is call log with RTP Forwarding disabled and no RBT:

 0160331182652.770165 <sip:INFO> 'udp:0.0.0.0:5068' received 1133 bytes SIP message from 10.74.33.70:5080 [0x279c500]
 -----
 NVITE sip:5142@10.74.33.70:5068 SIP/2.0
 ia: SIP/2.0/UDP 10.74.33.70:5080;rport;branch=z9hG4bK3aBcyHeD2y8vH
 ax-Forwards: 69
 rom: "TEST 1" <sip:5000@10.74.33.70:5068>;tag=32S3FBggXSNQa
 o: <sip:5142@10.74.33.70:5068>
 all-ID: 4f07ed6c-71d6-1234-7faf-aad026afe127
 Seq: 89375742 INVITE
 ontact: <sip:gw+yate@10.74.33.70:5080;transport=udp;gw=yate>
 ser-Agent: FreeSWITCH-mod_sofia/1.6.6+git~20160111T201612Z~d2d0b3283a~64bit
 llow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
 upported: timer, path, replaces
 llow-Events: talk, hold, conference, refer
 ontent-Type: application/sdp
 ontent-Disposition: session
 ontent-Length: 313
 -FS-Support: update_display,send_info
 emote-Party-ID: "TEST 1" <sip:5200@10.74.33.70:5068>;party=calling;screen=yes;privacy=off
 
 =0
 =FreeSWITCH 1459399404 1459399405 IN IP4 10.74.33.70
 =FreeSWITCH
 =IN IP4 10.74.33.70
 =0 0
 =audio 24208 RTP/AVP 0 8 18 9 101
 =rtpmap:0 PCMU/8000
 =rtpmap:8 PCMA/8000
 =rtpmap:18 G729/8000
 =fmtp:18 annexb=no
 =rtpmap:9 G722/8000
 =rtpmap:101 telephone-event/8000
 =fmtp:101 0-16
 =ptime:20
------
 0160331182652.775440 <sip:INFO> 'udp:0.0.0.0:5068' sending code 100 0x7f559800ce40 to 10.74.33.70:5080 [0x279c500]
 -----
 IP/2.0 100 Trying
 ia: SIP/2.0/UDP 10.74.33.70:5080;rport=5080;branch=z9hG4bK3aBcyHeD2y8vH;received=10.74.33.70
 rom: "TEST 1" <sip:5000@10.74.33.70:5068>;tag=32S3FBggXSNQa
 o: <sip:5142@10.74.33.70:5068>
 all-ID: 4f07ed6c-71d6-1234-7faf-aad026afe127
 Seq: 89375742 INVITE
 erver: YATE/5.5.1
 ontent-Length: 0
 
------
20160331182652.775516 <sip/3:ALL> YateSIPConnection::YateSIPConnection(0x7f559800bdb0,0x7f55ac02d830) [0x7f5598002fe0]
20160331182652.775591 <sip/3:ALL> NAT address is '(null)' [0x7f5598002fe0]
20160331182652.775746 <sip/3:ALL> Set media: audio=g729 [0x7f5598002fe0]
20160331182652.778955 <INFO> Could not classify call from '5000', wasted 4 usec
20160331182652.779095 <INFO> Routing call to '5142' in context 'default' via 'h323/5142@10.74.100.5' in 78 usec
20160331182652.779106 <sip/3:ALL> NAT address is '(null)' [0x7f5598002fe0]
20160331182652.779155 <h323:INFO> Found call to H.323 target='5142@10.74.100.5'
20160331182652.783909 <h323:ALL> YateH323Connection::YateH323Connection(0x26d56f0,5784,0x7f5598001d20) [0x7f55b4000c10]
20160331182652.783922 <h323/3:ALL> YateH323Chan::YateH323Chan(0x7f55b4000c10,(null)) outgoing [0x7f55b4004b50]
20160331182652.783945 <h323/3:INFO> Setting H.323 caller: number='5000' name='TEST 1'
20160331182652.783952 <h323/3:ALL> YateH323Connection::rtpForward(0x7f5598001d20,0) [0x7f55b4000c10]
20160331182652.783956 <h323/3:NOTE> Formats changed to 'g729'
20160331182652.783980 <h323/3:ALL> Removing capability 'G.729B' (g729b) not in remote 'g729'
20160331182652.790985 <h323/3:ALL> YateH323Connection::OnSetLocalCapabilities() external [0x7f55b4000c10]
20160331182652.791025 <h323/3:ALL> H323Connection::CreateRealTimeLogicalChannel external [0x7f55b4000c10]
20160331182652.791041 <h323/3:ALL> Capability 'G.729A/B{sw}' format 'g729' session 1 receive
20160331182652.791069 <h323/3:ALL> Logical control channel address '10.74.33.70'
20160331182652.791082 <yrtp:ALL> No-transport message received
20160331182652.791097 <yrtp:ALL> YRTPWrapper::YRTPWrapper('10.74.33.70',0x7f55b4004b50,'audio',receive,0x7f55bb7d6dd0,false) [0x7f55b4009b60]
20160331182652.791108 <yrtp:ALL> YRTPWrapper::setupRTP("10.74.33.70",true,true) [0x7f55b4009b60]
20160331182652.791130 <yrtp:INFO> Session 'yrtp/1910091913' 0x7f55b4009ee0 bound to 10.74.33.70:22190 +RTCP [0x7f55b4009b60]
20160331182652.791137 <yrtp:ALL> YRTPSource::YRTPSource(0x7f55b4009b60) [0x7f55b400a320]
20160331182652.791143 <yrtp:ALL> YRTPWrapper::setupSRTP(false) [0x7f55b4009b60]
20160331182652.791168 <h323/3:ALL> H323Connection::CreateRealTimeLogicalChannel external [0x7f55b4000c10]
20160331182652.791178 <h323/3:ALL> Capability 'G.729A/B{sw}' format 'g729' session 1 send
20160331182652.791189 <h323/3:ALL> Logical control channel address '10.74.33.70'
20160331182652.791198 <yrtp:ALL> No-transport message received
20160331182652.791202 <yrtp:ALL> Wrapper 0x7f55b4009b60 found by CallEndpoint 0x7f55b4004b50
20160331182652.791206 <yrtp:ALL> YRTPConsumer::YRTPConsumer(0x7f55b4009b60) [0x7f55b400a880]
20160331182652.791210 <yrtp:ALL> YRTPWrapper::setupSRTP(false) [0x7f55b4009b60]
20160331182652.791232 <h323/3:ALL> H323Connection::CreateRealTimeLogicalChannel external [0x7f55b4000c10]
20160331182652.791240 <h323/3:ALL> Capability 'G.729A{sw}' format 'g729' session 1 receive
20160331182652.791250 <h323/3:ALL> Logical control channel address '10.74.33.70'
20160331182652.791258 <yrtp:ALL> No-transport message received
20160331182652.791262 <yrtp:ALL> Wrapper 0x7f55b4009b60 found by CallEndpoint 0x7f55b4004b50
20160331182652.791265 <yrtp:ALL> YRTPWrapper::setupSRTP(false) [0x7f55b4009b60]
20160331182652.791281 <h323/3:ALL> H323Connection::CreateRealTimeLogicalChannel external [0x7f55b4000c10]
20160331182652.791288 <h323/3:ALL> Capability 'G.729A{sw}' format 'g729' session 1 send
20160331182652.791297 <h323/3:ALL> Logical control channel address '10.74.33.70'
20160331182652.791305 <yrtp:ALL> No-transport message received
20160331182652.791308 <yrtp:ALL> Wrapper 0x7f55b4009b60 found by CallEndpoint 0x7f55b4004b50
20160331182652.791312 <yrtp:ALL> YRTPWrapper::setupSRTP(false) [0x7f55b4009b60]
20160331182652.791328 <h323/3:ALL> H323Connection::CreateRealTimeLogicalChannel external [0x7f55b4000c10]
20160331182652.791335 <h323/3:ALL> Capability 'G.729{sw}' format 'g729' session 1 receive
20160331182652.791344 <h323/3:ALL> Logical control channel address '10.74.33.70'
20160331182652.791352 <yrtp:ALL> No-transport message received
20160331182652.791355 <yrtp:ALL> Wrapper 0x7f55b4009b60 found by CallEndpoint 0x7f55b4004b50
20160331182652.791358 <yrtp:ALL> YRTPWrapper::setupSRTP(false) [0x7f55b4009b60]
20160331182652.791377 <h323/3:ALL> H323Connection::CreateRealTimeLogicalChannel external [0x7f55b4000c10]
20160331182652.791385 <h323/3:ALL> Capability 'G.729{sw}' format 'g729' session 1 send
20160331182652.791394 <h323/3:ALL> Logical control channel address '10.74.33.70'
20160331182652.791401 <yrtp:ALL> No-transport message received
20160331182652.791405 <yrtp:ALL> Wrapper 0x7f55b4009b60 found by CallEndpoint 0x7f55b4004b50
20160331182652.791409 <yrtp:ALL> YRTPWrapper::setupSRTP(false) [0x7f55b4009b60]
20160331182653.263866 <h323/3:INFO> YateH323Connection::OnAlerting '5142' [0x7f55b4000c10]
20160331182653.265510 <yrtp:ALL> RTP/AVP message received
20160331182653.265547 <yrtp:INFO> Guessed local IP '10.74.33.70' for remote '10.74.33.70'
20160331182653.265553 <yrtp:ALL> YRTPWrapper::YRTPWrapper('10.74.33.70',0x7f5598002fe0,'audio',bidir,0x27ab130,false) [0x27b1a20]
20160331182653.265560 <yrtp:ALL> YRTPWrapper::setupRTP("10.74.33.70",true,true) [0x27b1a20]
20160331182653.265578 <yrtp:INFO> Session 'yrtp/1139616103' 0x27b2930 bound to 10.74.33.70:27396 +RTCP [0x27b1a20]
20160331182653.265584 <yrtp:ALL> YRTPSource::YRTPSource(0x27b1a20) [0x27b6ab0]
20160331182653.265590 <INFO> DataTranslator::attachChain [0x27b6ab0] '(null)' -> [0x7f55b400a880] '(null)' not possible
20160331182653.265594 <yrtp:ALL> YRTPConsumer::YRTPConsumer(0x27b1a20) [0x27b6c40]
20160331182653.265598 <INFO> DataTranslator::attachChain [0x7f55b400a320] '(null)' -> [0x27b6c40] '(null)' not possible
20160331182653.265602 <yrtp:ALL> YRTPWrapper::startRTP("10.74.33.70",24208) [0x27b1a20]
20160331182653.265607 <yrtp:INFO> RTP starting format 'g729' payload 18 [0x27b1a20]
20160331182653.265613 >>> DataTranslator::detachChain(0x27b6ab0,0x7f55b400a880)
20160331182653.265616 <<< DataTranslator::detachChain
20160331182653.265621 <INFO> DataTranslator::attachChain [0x27b6ab0] 'g729' -> [0x7f55b400a880] '(null)' not possible
20160331182653.265624 >>> DataTranslator::detachChain(0x7f55b400a320,0x27b6c40)
20160331182653.265627 <<< DataTranslator::detachChain
20160331182653.265630 <INFO> DataTranslator::attachChain [0x7f55b400a320] '(null)' -> [0x27b6c40] 'g729' not possible
 0160331182653.268333 <sip:INFO> 'udp:0.0.0.0:5068' sending code 180 0x27af4f0 to 10.74.33.70:5080 [0x279c500]
 -----
 IP/2.0 180 Ringing
 ia: SIP/2.0/UDP 10.74.33.70:5080;rport=5080;branch=z9hG4bK3aBcyHeD2y8vH;received=10.74.33.70
 rom: "TEST 1" <sip:5000@10.74.33.70:5068>;tag=32S3FBggXSNQa
 o: <sip:5142@10.74.33.70:5068>;tag=1646484832
 all-ID: 4f07ed6c-71d6-1234-7faf-aad026afe127
 Seq: 89375742 INVITE
 erver: YATE/5.5.1
 ontact: <sip:5142@10.74.33.70:5068>
 llow: ACK, INVITE, BYE, CANCEL, REGISTER, REFER, OPTIONS, INFO
 ontent-Type: application/sdp
 ontent-Length: 204
 
 =0
 =yate 1459423613 1459423613 IN IP4 10.74.33.70
 =SIP Call
 =IN IP4 10.74.33.70
 =0 0
 =audio 27396 RTP/AVP 18 101
 =rtpmap:18 G729/8000
 =fmtp:18 annexb=no
 =rtpmap:101 telephone-event/8000
------

Help me please.
Title: Re: No RBT during calls
Post by: marian on March 31, 2016, 08:44:19 AM
Can you post a log with all call signalling from start to end?
Yate messages (sniffer) included.
Title: Re: No RBT during calls
Post by: xevyk on March 31, 2016, 09:59:54 PM
Can you post a log with all call signalling from start to end?
Yate messages (sniffer) included.

Thank you for reply again!

Here is log http://pastebin.com/CuzTLYQ7 (http://pastebin.com/CuzTLYQ7)
Title: Re: No RBT during calls
Post by: marian on April 01, 2016, 01:02:29 AM
Yate is receiving remote party RTP addr/port after answer.
No ringback or any other early media is possible before it.

See log:
20160401104223.017318 <h323/4:INFO> YateH323Connection::OnEstablished() [0x7f55a0009ca0]
...
20160401104223.027413 <h323/4:INFO> Got remote RTP address 10.74.100.5:4000 [0x7f55a0009ca0]
Title: Re: No RBT during calls
Post by: xevyk on April 01, 2016, 01:59:24 AM
Yate is receiving remote party RTP addr/port after answer.
No ringback or any other early media is possible before it.

See log:
20160401104223.017318 <h323/4:INFO> YateH323Connection::OnEstablished() [0x7f55a0009ca0]
...
20160401104223.027413 <h323/4:INFO> Got remote RTP address 10.74.100.5:4000 [0x7f55a0009ca0]

It looks like I have to change order of receiveng remote party RTP addr/port before answer but how can I do it?
Title: Re: No RBT during calls
Post by: marian on April 01, 2016, 02:11:08 AM
I don't know it: I don't know much about H323.
Maybe remote party don't send early media?
This might be the reason why remote RTP ip/port is received on answer.
Title: Re: No RBT during calls
Post by: xevyk on April 01, 2016, 02:23:34 AM
I don't know it: I don't know much about H323.
Maybe remote party don't send early media?
This might be the reason why remote RTP ip/port is received on answer.

Thank you for help!

I'll try to solve this puzzle and write back to this topic.