Re: How to configure an Asterisk UniMRCP client to talk to a UniMRCP server?

[ashik...@gmail.com]

Hi,

     
       Please don't choose the port  no. 5060 in mrcp.conf for the server and client port. COZ it has been already occupied by asterisk.
       Find out the exact port no using  netstat command as follows.

       For the windows use netstat -ab to display executables names and its port no. For  the linux netstat -ltupeeeee    
       
         
       
        
Thanks,
Ashik

On Thursday, January 17, 2013 11:50:07 PM UTC+3, Weiyun wrote:

Hi all,

I need your help to configure Asterisk UniMRCP client so that it talks to UniMRCP server.

My first step was to run the executable UniMRCP client and server on two different machines.
The result of "run synth" was successful, and the message exchange captured by Wireshark seemed fine.

Then I setup the Asterisk 11 with the UniMRCP plugin to talk to the UniMRCP server. They are on two different machines.
But it seemed that Asterisk didn't send requests to the UniMRCP server when I placed a call to Asterisk.

The topology is like this: (they're all in the same LAN with firewall disabled)

Phone--------------Asterisk 11 with UniMRCP bridge------------UniMRCP server executable
192.168.180.99 192.168.180.22 192.168.180.33

Inside of the dialplan in extensions.conf: (I'm trying to keep everything simple)
exten => 1008,1, NoOp()
same => n, MRCPSynth(Hello world!, p=default&i=any&f=/tmp/synth.raw)
same=> n, Hangup()

I modified mrcp.conf to match the network settings. Please have a look in case there is something incorrect.
Also, on UniMRCP server, there is no TTS engine but only using "demosynth".

As I noticed, Asterisk did call on app_unimrcp, and from
[Jan 17 13:29:03] DEBUG[3245]: app_unimrcp.c:4173 unimrcp_log: Send Offer 0xa303cd8 <new> [c:1 a:1 v:0] to 192.168.180.33:5060

It seemed like a packet was prepared to send to UniMRCP server (192.168.180.33:5060), but Wireshark on both machine didn't capture that packet.

What am I missing here?
How do I configure the Asterisk UniMRCP client to talk to the UniMRCP server?
What does res_speech_unimrcp do? Should I always load both app_unimrcp and res_speech_unimrcp to the Asterisk?

Thank you very much.

Weiyun




Asterisk debug info attached here:

[Jan 17 13:29:03] DEBUG[3215]: chan_sip.c:9090 find_call: = Looking for Call ID: 18422...@192.168.180.99 (Checking From) --From tag 119259022 --To-tag
[Jan 17 13:29:03] DEBUG[3215]: logger.c:1285 ast_create_callid: CALL_ID [C-00000000] created by thread.
[Jan 17 13:29:03] DEBUG[3215]: acl.c:979 ast_ouraddrfor: For destination '192.168.180.99', our source address is '192.168.180.22'.
[Jan 17 13:29:03] DEBUG[3215]: chan_sip.c:4021 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 192.168.180.22:5060
[Jan 17 13:29:03] DEBUG[3215]: chan_sip.c:8693 sip_alloc: Allocating new SIP dialog for 18422...@192.168.180.99 - INVITE (No RTP)
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: logger.c:1315 ast_callid_threadassoc_add: CALL_ID [C-00000000] bound to thread.
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: chan_sip.c:27811 handle_incoming: **** Received INVITE (5) - Command in SIP INVITE
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: sip/reqresp_parser.c:1550 parse_sip_options: Begin: parsing SIP "Supported: replaces"
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: sip/reqresp_parser.c:1566 parse_sip_options: Found SIP option: -replaces-
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: sip/reqresp_parser.c:1574 parse_sip_options: Matched SIP option: replaces
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '192.168.180.99:5062' into...
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '192.168.180.99' and port '5062'.
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '192.168.180.22' into...
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '192.168.180.22' and port ''.
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: chan_sip.c:3864 __sip_xmit: Trying to put 'SIP/2.0 401' onto UDP socket destined for 192.168.180.99:5062
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: logger.c:1337 ast_callid_threadassoc_remove: Call_ID [C-00000000] being removed from thread.
[Jan 17 13:29:03] DEBUG[3215]: chan_sip.c:9090 find_call: = Looking for Call ID: 18422...@192.168.180.99 (Checking From) --From tag 119259022 --To-tag as21126457
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: logger.c:1315 ast_callid_threadassoc_add: CALL_ID [C-00000000] bound to thread.
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: chan_sip.c:27811 handle_incoming: **** Received ACK (6) - Command in SIP ACK
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: chan_sip.c:4556 __sip_ack: Stopping retransmission on '18422...@192.168.180.99' of Response 1: Match Found
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: logger.c:1337 ast_callid_threadassoc_remove: Call_ID [C-00000000] being removed from thread.
[Jan 17 13:29:03] DEBUG[3215]: chan_sip.c:9090 find_call: = Looking for Call ID: 18422...@192.168.180.99 (Checking From) --From tag 119259022 --To-tag
[Jan 17 13:29:03] DEBUG[3215]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '192.168.180.22' into...
[Jan 17 13:29:03] DEBUG[3215]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '192.168.180.22' and port ''.
[Jan 17 13:29:03] DEBUG[3215]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '192.168.180.22' into...
[Jan 17 13:29:03] DEBUG[3215]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '192.168.180.22' and port ''.
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: logger.c:1315 ast_callid_threadassoc_add: CALL_ID [C-00000000] bound to thread.
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: chan_sip.c:27811 handle_incoming: **** Received INVITE (5) - Command in SIP INVITE
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '192.168.180.99:5062' into...
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '192.168.180.99' and port '5062'.
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '192.168.180.22' into...
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '192.168.180.22' and port ''.
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: rtp_engine.c:283 ast_rtp_instance_new: Using engine 'asterisk' for RTP instance '0xb760c674'
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: res_rtp_asterisk.c:1732 ast_rtp_new: Allocated port 12550 for RTP instance '0xb760c674'
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: rtp_engine.c:292 ast_rtp_instance_new: RTP instance '0xb760c674' is setup and ready to go
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: res_rtp_asterisk.c:3848 ast_rtp_prop_set: Setup RTCP on RTP instance '0xb760c674' == Using SIP RTP CoS mark 5
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: chan_sip.c:5697 do_setnat: Setting NAT on RTP to On
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: chan_sip.c:9972 process_sdp: Processing session-level SDP v=0... UNSUPPORTED OR FAILED.
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: chan_sip.c:9972 process_sdp: Processing session-level SDP o=- 20019 20019 IN IP4 192.168.180.99... OK.
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: chan_sip.c:9972 process_sdp: Processing session-level SDP s=SDP data... UNSUPPORTED OR FAILED.
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '192.168.180.99' into...
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '192.168.180.99' and port ''.
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: chan_sip.c:9972 process_sdp: Processing session-level SDP c=IN IP4 192.168.180.99... OK.
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: chan_sip.c:9972 process_sdp: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED.
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: rtp_engine.c:557 ast_rtp_codecs_payloads_set_m_type: Setting payload 0 based on m type on 0xb6353348
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: rtp_engine.c:557 ast_rtp_codecs_payloads_set_m_type: Setting payload 8 based on m type on 0xb6353348
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: rtp_engine.c:557 ast_rtp_codecs_payloads_set_m_type: Setting payload 18 based on m type on 0xb6353348
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: rtp_engine.c:557 ast_rtp_codecs_payloads_set_m_type: Setting payload 9 based on m type on 0xb6353348
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: rtp_engine.c:557 ast_rtp_codecs_payloads_set_m_type: Setting payload 101 based on m type on 0xb6353348
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: chan_sip.c:10378 process_sdp: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK.
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: chan_sip.c:10378 process_sdp: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK.
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: chan_sip.c:10378 process_sdp: Processing media-level (audio) SDP a=rtpmap:18 G729/8000... OK.
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: chan_sip.c:10378 process_sdp: Processing media-level (audio) SDP a=fmtp:18 annexb=no... OK.
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: chan_sip.c:10378 process_sdp: Processing media-level (audio) SDP a=rtpmap:9 G722/8000... OK.
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: chan_sip.c:10378 process_sdp: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED OR FAILED.
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: chan_sip.c:10378 process_sdp: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK.
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: chan_sip.c:10378 process_sdp: Processing media-level (audio) SDP a=ptime:20... OK.
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: chan_sip.c:10378 process_sdp: Processing media-level (audio) SDP a=sendrecv... OK.
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: res_rtp_asterisk.c:3893 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0xb760c674'
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: rtp_engine.c:515 ast_rtp_codecs_payloads_copy: Copying payload 0 from 0xb6353348 to 0xb760c820
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: rtp_engine.c:515 ast_rtp_codecs_payloads_copy: Copying payload 8 from 0xb6353348 to 0xb760c820
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: rtp_engine.c:515 ast_rtp_codecs_payloads_copy: Copying payload 9 from 0xb6353348 to 0xb760c820
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: rtp_engine.c:515 ast_rtp_codecs_payloads_copy: Copying payload 18 from 0xb6353348 to 0xb760c820
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: rtp_engine.c:515 ast_rtp_codecs_payloads_copy: Copying payload 101 from 0xb6353348 to 0xb760c820
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: res_rtp_asterisk.c:3814 ast_rtp_prop_set: Ignoring duplicate RTCP property on RTP instance '0xb760c674'
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: chan_sip.c:10640 process_sdp: We're settling with these formats: (ulaw)
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: chan_sip.c:25089 handle_request_invite: Checking SIP call limits for device 1001
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: chan_sip.c:6641 update_call_counter: Updating call counter for incoming call
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '192.168.180.22' into...
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '192.168.180.22' and port ''.
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '192.168.180.22' into...
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '192.168.180.22' and port ''.
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: chan_sip.c:7878 sip_new: *** Our native formats are (ulaw)
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: chan_sip.c:7879 sip_new: *** Joint capabilities are (ulaw)
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: chan_sip.c:7880 sip_new: *** Our capabilities are (ulaw)
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: chan_sip.c:7881 sip_new: *** AST_CODEC_CHOOSE formats are ulaw
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: chan_sip.c:7909 sip_new: This channel will not be able to handle video.
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: chan_sip.c:16067 build_route: build_route: Contact hop: <sip:10...@192.168.180.99:5062>
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: chan_sip.c:25399 handle_request_invite: SIP/1001-00000000: New call is still down.... Trying...
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: chan_sip.c:3864 __sip_xmit: Trying to put 'SIP/2.0 100' onto UDP socket destined for 192.168.180.99:5062
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: logger.c:1337 ast_callid_threadassoc_remove: Call_ID [C-00000000] being removed from thread.
[Jan 17 13:29:03] DEBUG[3306][C-00000000]: logger.c:1315 ast_callid_threadassoc_add: CALL_ID [C-00000000] bound to thread.
[Jan 17 13:29:03] DEBUG[3206]: devicestate.c:344 _ast_device_state: No provider found, checking channel drivers for SIP - 1001
[Jan 17 13:29:03] DEBUG[3206]: chan_sip.c:29242 sip_devicestate: Checking device state for peer 1001
[Jan 17 13:29:03] DEBUG[3206]: devicestate.c:467 do_state_change: Changing state for SIP/1001 - state 1 (Not in use)
[Jan 17 13:29:03] DEBUG[3206]: devicestate.c:442 devstate_event: device 'SIP/1001' state '1'
[Jan 17 13:29:03] DEBUG[3306][C-00000000]: pbx.c:4410 pbx_extension_helper: Launching 'NoOp' -- Executing [1008@users:1] NoOp("SIP/1001-00000000", "") in new stack
[Jan 17 13:29:03] DEBUG[3306][C-00000000]: pbx.c:4410 pbx_extension_helper: Launching 'MRCPSynth' -- Executing [1008@users:2] MRCPSynth("SIP/1001-00000000", "Hello world!,p=default&i=any&f=/tmp/synth.raw") in new stack
[Jan 17 13:29:03] NOTICE[3306][C-00000000]: app_unimrcp.c:4423 app_synth_exec: Option=|p=default|
[Jan 17 13:29:03] NOTICE[3306][C-00000000]: app_unimrcp.c:4423 app_synth_exec: Option=|i=any|
[Jan 17 13:29:03] NOTICE[3306][C-00000000]: app_unimrcp.c:4423 app_synth_exec: Option=|f=/tmp/synth.raw|
[Jan 17 13:29:03] NOTICE[3306][C-00000000]: app_unimrcp.c:4489 app_synth_exec: Profile to use: default
[Jan 17 13:29:03] NOTICE[3306][C-00000000]: app_unimrcp.c:4492 app_synth_exec: Text to synthesize is: Hello world!
[Jan 17 13:29:03] NOTICE[3306][C-00000000]: app_unimrcp.c:4495 app_synth_exec: Filename to save to: /tmp/synth.raw
[Jan 17 13:29:03] DEBUG[3241]: app_queue.c:1806 handle_statechange: Device 'SIP/1001' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Jan 17 13:29:03] NOTICE[3306][C-00000000]: app_unimrcp.c:4531 app_synth_exec: DTMF enable: 1
[Jan 17 13:29:03] DEBUG[3306][C-00000000]: chan_sip.c:7228 sip_answer: SIP answering channel: SIP/1001-00000000
[Jan 17 13:29:03] DEBUG[3206]: devicestate.c:344 _ast_device_state: No provider found, checking channel drivers for SIP - 1001
[Jan 17 13:29:03] DEBUG[3306][C-00000000]: res_rtp_asterisk.c:2085 ast_rtp_update_source: Setting the marker bit due to a source update
[Jan 17 13:29:03] DEBUG[3206]: chan_sip.c:29242 sip_devicestate: Checking device state for peer 1001
[Jan 17 13:29:03] DEBUG[3206]: devicestate.c:467 do_state_change: Changing state for SIP/1001 - state 1 (Not in use)
[Jan 17 13:29:03] DEBUG[3206]: devicestate.c:442 devstate_event: device 'SIP/1001' state '1'
[Jan 17 13:29:03] DEBUG[3306][C-00000000]: chan_sip.c:13463 transmit_response_with_sdp: Setting framing from config on incoming call
[Jan 17 13:29:03] DEBUG[3241]: app_queue.c:1806 handle_statechange: Device 'SIP/1001' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Jan 17 13:29:03] DEBUG[3306][C-00000000]: chan_sip.c:13011 add_sdp: ** Our capability: (ulaw) Video flag: True Text flag: True
[Jan 17 13:29:03] DEBUG[3306][C-00000000]: chan_sip.c:13012 add_sdp: ** Our prefcodec: (nothing)
[Jan 17 13:29:03] DEBUG[3306][C-00000000]: chan_sip.c:13149 add_sdp: -- Done with adding codecs to SDP
[Jan 17 13:29:03] DEBUG[3306][C-00000000]: chan_sip.c:13352 add_sdp: Done building SDP. Settling with this capability: (ulaw)
[Jan 17 13:29:03] DEBUG[3306][C-00000000]: chan_sip.c:3864 __sip_xmit: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.180.99:5062
[Jan 17 13:29:03] DEBUG[3215]: chan_sip.c:9090 find_call: = Looking for Call ID: 18422...@192.168.180.99 (Checking From) --From tag 119259022 --To-tag as6d638251
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: logger.c:1315 ast_callid_threadassoc_add: CALL_ID [C-00000000] bound to thread.
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: chan_sip.c:27811 handle_incoming: **** Received ACK (6) - Command in SIP ACK
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: chan_sip.c:4556 __sip_ack: Stopping retransmission on '18422...@192.168.180.99' of Response 2: Match Found
[Jan 17 13:29:03] DEBUG[3215][C-00000000]: logger.c:1337 ast_callid_threadassoc_remove: Call_ID [C-00000000] being removed from thread.
[Jan 17 13:29:03] DEBUG[3306][C-00000000]: res_rtp_asterisk.c:3502 ast_rtp_read: 0xb7610b80 -- start learning mode pass with addr = 192.168.180.99:11796
[Jan 17 13:29:03] DEBUG[3306][C-00000000]: res_rtp_asterisk.c:1605 rtp_learning_rtp_seq_update: 0xb7610b80 -- probation = 4, seq = 4
[Jan 17 13:29:03] DEBUG[3306][C-00000000]: res_rtp_asterisk.c:3508 ast_rtp_read: 0xb7610b80 -- Condition for learning hasn't exited, so reject the frame.
[Jan 17 13:29:03] DEBUG[3306][C-00000000]: res_rtp_asterisk.c:3502 ast_rtp_read: 0xb7610b80 -- start learning mode pass with addr = 192.168.180.99:11796
[Jan 17 13:29:03] DEBUG[3306][C-00000000]: res_rtp_asterisk.c:1605 rtp_learning_rtp_seq_update: 0xb7610b80 -- probation = 3, seq = 5
[Jan 17 13:29:03] DEBUG[3306][C-00000000]: res_rtp_asterisk.c:3508 ast_rtp_read: 0xb7610b80 -- Condition for learning hasn't exited, so reject the frame.
[Jan 17 13:29:03] DEBUG[3306][C-00000000]: res_rtp_asterisk.c:3502 ast_rtp_read: 0xb7610b80 -- start learning mode pass with addr = 192.168.180.99:11796
[Jan 17 13:29:03] DEBUG[3306][C-00000000]: res_rtp_asterisk.c:1605 rtp_learning_rtp_seq_update: 0xb7610b80 -- probation = 2, seq = 6
[Jan 17 13:29:03] DEBUG[3306][C-00000000]: res_rtp_asterisk.c:3508 ast_rtp_read: 0xb7610b80 -- Condition for learning hasn't exited, so reject the frame.
[Jan 17 13:29:03] DEBUG[3306][C-00000000]: res_rtp_asterisk.c:3502 ast_rtp_read: 0xb7610b80 -- start learning mode pass with addr = 192.168.180.99:11796
[Jan 17 13:29:03] DEBUG[3306][C-00000000]: res_rtp_asterisk.c:1605 rtp_learning_rtp_seq_update: 0xb7610b80 -- probation = 1, seq = 7
[Jan 17 13:29:03] DEBUG[3306][C-00000000]: res_rtp_asterisk.c:3512 ast_rtp_read: 0xb7610b80 -- Probation Ended. Set strict_rtp_state to STRICT_RTP_CLOSED with address 192.168.180.99:11796
[Jan 17 13:29:03] DEBUG[3306][C-00000000]: app_unimrcp.c:935 audio_queue_create: (TTS-0) audio queue created
[Jan 17 13:29:03] DEBUG[3306][C-00000000]: app_unimrcp.c:1856 speech_channel_create: Created speech channel: Name=TTS-0, Type=SYNTHESIZER, Codec=L16, Rate=8000
[Jan 17 13:29:03] NOTICE[3306][C-00000000]: app_unimrcp.c:4170 unimrcp_log: Create MRCP Handle 0xa303cd8 [speech-nuance5-mrcp2]
[Jan 17 13:29:03] DEBUG[3306][C-00000000]: app_unimrcp.c:4173 unimrcp_log: Create Channel 0xa303cd8 <new>
[Jan 17 13:29:03] DEBUG[3306][C-00000000]: app_unimrcp.c:4176 unimrcp_log: Signal Message to [MRCP Client] [4;0]
[Jan 17 13:29:03] DEBUG[3245]: app_unimrcp.c:4176 unimrcp_log: Process Message [MRCP Client] [4;0]
[Jan 17 13:29:03] DEBUG[3245]: app_unimrcp.c:4173 unimrcp_log: Receive App Request 0xa303cd8 <new> [2]
[Jan 17 13:29:03] DEBUG[3245]: app_unimrcp.c:4173 unimrcp_log: Add MRCP Handle 0xa303cd8 <new>
[Jan 17 13:29:03] DEBUG[3245]: app_unimrcp.c:4176 unimrcp_log: Dispatch App Request 0xa303cd8 <new> [2]
[Jan 17 13:29:03] DEBUG[3245]: app_unimrcp.c:4176 unimrcp_log: Signal Message to [MRCPv2ConnectionAgent] [1;0]
[Jan 17 13:29:03] NOTICE[3245]: app_unimrcp.c:4170 unimrcp_log: Add Control Channel 0xa303cd8 <new@speechsynth>
[Jan 17 13:29:03] DEBUG[3245]: app_unimrcp.c:4176 unimrcp_log: Add Media Termination 0xa303cd8 <new@media-tm>
[Jan 17 13:29:03] DEBUG[3246]: app_unimrcp.c:4176 unimrcp_log: Process Poller Wakeup [MRCPv2ConnectionAgent]
[Jan 17 13:29:03] DEBUG[3245]: app_unimrcp.c:4176 unimrcp_log: Add Media Termination 0xa303cd8 <new@rtp-tm>
[Jan 17 13:29:03] DEBUG[3246]: app_unimrcp.c:4176 unimrcp_log: Process Message [MRCPv2ConnectionAgent] [1;0]
[Jan 17 13:29:03] DEBUG[3245]: app_unimrcp.c:4176 unimrcp_log: Signal Message to [MediaEngine] [1;0]
[Jan 17 13:29:03] DEBUG[3245]: app_unimrcp.c:4176 unimrcp_log: Wait for Messages [MRCP Client]
[Jan 17 13:29:03] DEBUG[3246]: app_unimrcp.c:4176 unimrcp_log: Signal Message to [MRCP Client] [2;0]
[Jan 17 13:29:03] DEBUG[3245]: app_unimrcp.c:4176 unimrcp_log: Process Message [MRCP Client] [2;0]
[Jan 17 13:29:03] DEBUG[3246]: app_unimrcp.c:4176 unimrcp_log: Wait for Messages [MRCPv2ConnectionAgent]
[Jan 17 13:29:03] DEBUG[3245]: app_unimrcp.c:4176 unimrcp_log: Control Channel Added 0xa303cd8 <new@speechsynth>
[Jan 17 13:29:03] DEBUG[3245]: app_unimrcp.c:4176 unimrcp_log: Wait for Messages [MRCP Client]
[Jan 17 13:29:03] DEBUG[3247]: app_unimrcp.c:4176 unimrcp_log: Process Message [MediaEngine] [1;0]
[Jan 17 13:29:03] DEBUG[3247]: app_unimrcp.c:4176 unimrcp_log: Add Media Context 0xa303cd8
[Jan 17 13:29:03] DEBUG[3245]: app_unimrcp.c:4176 unimrcp_log: Process Message [MRCP Client] [3;0]
[Jan 17 13:29:03] DEBUG[3245]: app_unimrcp.c:4176 unimrcp_log: Media Termination Added 0xa303cd8 <new@media-tm>
[Jan 17 13:29:03] DEBUG[3245]: app_unimrcp.c:4176 unimrcp_log: Media Termination Added 0xa303cd8 <new@rtp-tm>
[Jan 17 13:29:03] DEBUG[3245]: app_unimrcp.c:4173 unimrcp_log: Send Offer 0xa303cd8 <new> [c:1 a:1 v:0] to 192.168.180.33:5060
[Jan 17 13:29:03] DEBUG[3245]: app_unimrcp.c:4173 unimrcp_log: Local SDP 0xa303cd8 <new>
v=0
o=Asterisk 0 0 IN IP4 192.168.180.22
s=-
c=IN IP4 192.168.180.22
t=0 0
m=application 9 TCP/MRCPv2 1
a=setup:active
a=connection:new
a=resource:speechsynth
a=cmid:1
m=audio 4990 RTP/AVP 0 8 96
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:96 L16/8000
a=recvonly
a=ptime:20
a=mid:1

[Jan 17 13:29:03] DEBUG[3245]: app_unimrcp.c:4176 unimrcp_log: Wait for Messages [MRCP Client]
[Jan 17 13:29:17] DEBUG[3215]: chan_sip.c:9090 find_call: = Looking for Call ID: 18422...@192.168.180.99 (Checking From) --From tag 119259022 --To-tag as6d638251
[Jan 17 13:29:17] DEBUG[3215][C-00000000]: logger.c:1315 ast_callid_threadassoc_add: CALL_ID [C-00000000] bound to thread.
[Jan 17 13:29:17] DEBUG[3215][C-00000000]: chan_sip.c:27811 handle_incoming: **** Received BYE (8) - Command in SIP BYE
[Jan 17 13:29:17] DEBUG[3215][C-00000000]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '192.168.180.99:5062' into...
[Jan 17 13:29:17] DEBUG[3215][C-00000000]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '192.168.180.99' and port '5062'.
[Jan 17 13:29:17] DEBUG[3215][C-00000000]: chan_sip.c:3520 sip_alreadygone: Setting SIP_ALREADYGONE on dialog 18422...@192.168.180.99
[Jan 17 13:29:17] DEBUG[3215][C-00000000]: res_rtp_asterisk.c:3893 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0xb760c674'
[Jan 17 13:29:17] DEBUG[3215][C-00000000]: chan_sip.c:26438 handle_request_bye: Received bye, issuing owner hangup
[Jan 17 13:29:17] DEBUG[3215][C-00000000]: chan_sip.c:3864 __sip_xmit: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.180.99:5062
[Jan 17 13:29:17] DEBUG[3215][C-00000000]: logger.c:1337 ast_callid_threadassoc_remove: Call_ID [C-00000000] being removed from thread.
[Jan 17 13:29:49] WARNING[3215]: chan_sip.c:4398 __sip_autodestruct: Autodestruct on dialog '18422...@192.168.180.99' with owner SIP/1001-00000000 in place (Method: BYE). Rescheduling destruction for 10000 ms

mrcp.conf

[general]
default-asr-profile = speech-nuance5-mrcp2
default-tts-profile = speech-nuance5-mrcp2
; UniMRCP logging level to appear in Asterisk logs.  Options are:
; EMERGENCY|ALERT|CRITICAL|ERROR|WARNING|NOTICE|INFO|DEBUG -->
log-level = DEBUG
max-connection-count = 100
offer-new-connection = 1
; rx-buffer-size = 1024
; tx-buffer-size = 1024
; request-timeout = 60

[speech-nuance5-mrcp1]
; +++ MRCP settings +++
version = 1
;
; +++ RTSP +++
; === RSTP settings ===
server-ip = 192.168.180.33
server-port = 1554
; force-destination = 1
resource-location = media
speechsynth = speechsynthesizer
speechrecog = speechrecognizer
;
; +++ RTP +++
; === RTP factory ===
; rtp-ip = 0.0.0.0
rtp-ip = 192.168.180.22
; rtp-ext-ip = auto
rtp-port-min = 4990
rtp-port-max = 5000
; === RTP settings ===
; --- Jitter buffer settings ---
playout-delay = 50
; min-playout-delay = 20
max-playout-delay = 200
; --- RTP settings ---
ptime = 20
codecs = PCMU PCMA L16/96/8000
; --- RTCP settings ---
rtcp = 1
rtcp-bye = 2
rtcp-tx-interval = 5000
rtcp-rx-resolution = 1000


[speech-nuance5-mrcp2]
; +++ MRCP settings +++
version = 2
;
; +++ SIP +++
; === SIP settings ===
server-ip = 192.168.180.33
server-port = 5060
; server-username = test
force-destination = 1
; === SIP agent ===
; client-ip = 0.0.0.0
client-ip = 192.168.180.22
; client-ext-ip = auto
client-port = 5060
sip-transport = udp
; ua-name = Asterisk
; sdp-origin = Asterisk
;
; +++ RTP +++
; === RTP factory ===
; rtp-ip = 0.0.0.0
rtp-ip = 192.168.180.22
; rtp-ext-ip = auto
rtp-port-min = 4990
rtp-port-max = 5000
; === RTP settings ===
; --- Jitter buffer settings ---
playout-delay = 50
; min-playout-delay = 20
max-playout-delay = 200
; --- RTP settings ---
ptime = 20
codecs = PCMU PCMA L16/96/8000
; --- RTCP settings ---
rtcp = 1
rtcp-bye = 2
rtcp-tx-interval = 5000
rtcp-rx-resolution = 1000

[Weiyun]

Hi Ashik,

After I changed server sip port to 8060, and client sip port to 5093, problem solved.
Now client and server can communicate with each other.

Thanks you very much!

Weiyun