Building with freeswitch
80 views
Skip to first unread message
Fidel Gil
Dec 19, 2022, 11:37:29 AM12/19/22
to UniMRCP
Dear Group
I would like to have some clarifications.
I am trying to get a server with UNImrcp and freeswitch to work along. I am having a problem when loading the mod_unimrcp.so I get the following error:
2022-12-19 17:16:11.109650 99.97% [INFO] switch_stun.c:896 External ip address detected using STUN: 95.91.222.134
2022-12-19 17:16:11.269645 99.97% [INFO] switch_stun.c:896 External ip address detected using STUN: 95.91.222.134
2022-12-19 17:16:11.309667 99.97% [CRIT] switch_loadable_module.c:1755 Error Loading module /usr/local/freeswitch/mod/module mod_unimrcp.so
**/usr/local/freeswitch/mod/module mod_unimrcp.so: cannot open shared object file: No such file or directory**
2022-12-19 17:16:11.309667 99.97% [INFO] mod_enum.c:883 ENUM Reloaded
2022-12-19 17:16:11.309667 99.97% [INFO] switch_time.c:1431 Timezone reloaded 1750 definitions
2022-12-19 17:16:11.269645 99.97% [INFO] switch_stun.c:896 External ip address detected using STUN: 95.91.222.134
2022-12-19 17:16:11.309667 99.97% [CRIT] switch_loadable_module.c:1755 Error Loading module /usr/local/freeswitch/mod/module mod_unimrcp.so
**/usr/local/freeswitch/mod/module mod_unimrcp.so: cannot open shared object file: No such file or directory**
2022-12-19 17:16:11.309667 99.97% [INFO] mod_enum.c:883 ENUM Reloaded
2022-12-19 17:16:11.309667 99.97% [INFO] switch_time.c:1431 Timezone reloaded 1750 definitions
when executing load module unimrcp from the fs_cli.
The strange part is that when I run show module it appears amongst the modules
speech,unimrcp,mod_unimrcp,/usr/local/freeswitch/mod/mod_unimrcp.so
Vahagn Kocharyan
Dec 21, 2022, 6:05:49 PM12/21/22
to UniMRCP
Hi
you need to deploy it
You can get it from freeswitch signalwire repository based on your os release
or you can build it manually.
For additional help please mention your os release
Thanks
Fidel Gil
Jan 9, 2023, 7:43:17 AM1/9/23
to UniMRCP
Hello,
Well after giving it several attempts I clean installed the OS and rebuilt all from scratch. That was enough to get the module to load. I am currently facing a different Issue I am getting this error when calling the extension I had set up for recognition " [ERR] mod_unimrcp.c:1925 (ASR-1) RECOGNIZER channel error! ". I believe it is a configuration Issue.
From reading this freeswitch mail list they say that [ERR] mod_unimrcp.c:1925 (ASR-1) RECOGNIZER channel error! Is associated with the communication errors between unimrcp server and freeswitch.
Well after giving it several attempts I clean installed the OS and rebuilt all from scratch. That was enough to get the module to load. I am currently facing a different Issue I am getting this error when calling the extension I had set up for recognition " [ERR] mod_unimrcp.c:1925 (ASR-1) RECOGNIZER channel error! ". I believe it is a configuration Issue.
As I understand I needed to modify on the freeswitch side 3 files to get transcriptions result of voice, those files being:
1._ Dialplan as to add the action of recognition and which profile to use.
2._ MRCP profiles which states which is the IP address and ports
2._ MRCP profiles which states which is the IP address and ports
3._ Moudle file to insure module is loaded into the freeswitch.
So starting with the dialplan I have annexed it below it is just one more extension with the instruction and the only interesting addition is the following:
So starting with the dialplan I have annexed it below it is just one more extension with the instruction and the only interesting addition is the following:
<action application="play_and_detect_speech" data="ivr/ivr-welcome_to_freeswitch.wav
detect:unimrcp:mrcpserver02 {start-input-timers=false}builtin:speech/transcribe"/>
detect:unimrcp:mrcpserver02 {start-input-timers=false}builtin:speech/transcribe"/>
After that I added my mrcp profile, called profile2.xml, also annexed. There I specified the IP and ports.
Next I modified my modules.conf.xml file to make sure the module always loads.
Now comes the issue, I am using Zoiper to connect to my freeswitch and place the call. I call the the extension (5012 in my case ) but the call ends after answer and I can see on the freeswitch side the following log output as error.
2023-01-09 13:12:20.198038 89.00% [DEBUG] sofia.c:7502 Channel sofia/internal/10...@10.7.0.182 entering state [completed][200]
2023-01-09 13:12:20.198038 89.00% [NOTICE] mod_dptools.c:1408 Channel [sofia/internal/10...@10.7.0.182] has been answered
2023-01-09 13:12:20.218085 89.00% [DEBUG] switch_channel.c:3950 (sofia/internal/10...@10.7.0.182) Callstate Change EARLY -> ACTIVE
EXECUTE [depth=0] sofia/internal/10...@10.7.0.182 sleep(1000)
EXECUTE [depth=0] sofia/internal/10...@10.7.0.182 play_and_detect_speech(ivr/ivr-welcome_to_freeswitch.wav detect:unimrcp:mrcpserver02 {start-input-timers=false}builtin:speech/transcribe)
2023-01-09 13:12:21.238037 88.90% [INFO] mod_unimrcp.c:3139 asr_handle: name = unimrcp, codec = (null), rate = 48000, grammar = (null), param = mrcpserver02
2023-01-09 13:12:21.238037 88.90% [INFO] mod_unimrcp.c:3141 codec = L16, rate = 48000, dest = (null)
2023-01-09 13:12:21.238037 88.90% [DEBUG] mod_unimrcp.c:688 (ASR-1) audio queue created
2023-01-09 13:12:21.238037 88.90% [NOTICE] mrcp_application.c:117 (ASR-1) Create MRCP Handle 0x7ff2980e2778 [mrcpserver02]
2023-01-09 13:12:21.238037 88.90% [INFO] mrcp_client_session.c:131 (ASR-1) Create Channel ASR-1 <new>
2023-01-09 13:12:21.238037 88.90% [DEBUG] apt_task.c:263 () Signal Message to [MRCP Client] [0x7ff2980af9d0;4;0]
2023-01-09 13:12:21.238037 88.90% [DEBUG] apt_task.c:335 () Process Message [MRCP Client] [0x7ff2980af9d0;4;0]
2023-01-09 13:12:21.238037 88.90% [INFO] mrcp_client_session.c:385 (ASR-1) Receive App Request ASR-1 <new> [2]
2023-01-09 13:12:21.238037 88.90% [INFO] mrcp_client.c:697 (ASR-1) Add MRCP Handle ASR-1 <new>
2023-01-09 13:12:21.238037 88.90% [DEBUG] mrcp_client_session.c:1277 (ASR-1) Dispatch App Request ASR-1 <new> [2]
2023-01-09 13:12:21.238037 88.90% [DEBUG] apt_task.c:263 () Signal Message to [MRCPv2ConnectionAgent] [0x7ff2a801aed0;1;0]
2023-01-09 13:12:21.238037 88.90% [NOTICE] mrcp_client_session.c:717 (ASR-1) Add Control Channel ASR-1 <new@speechrecog>
2023-01-09 13:12:21.238037 88.90% [DEBUG] mrcp_client_session.c:743 (ASR-1) Add Media Termination ASR-1 <new@media-tm>
2023-01-09 13:12:21.238037 88.90% [DEBUG] mrcp_client_session.c:772 (ASR-1) Add Media Termination ASR-1 <new@rtp-tm>
2023-01-09 13:12:21.238037 88.90% [DEBUG] apt_task.c:263 () Signal Message to [MediaEngine] [0x7ff2a8016110;1;0]
2023-01-09 13:12:21.238037 88.90% [DEBUG] apt_consumer_task.c:135 () Wait for Messages [MRCP Client]
2023-01-09 13:12:21.238037 88.90% [DEBUG] apt_poller_task.c:259 () Process Poller Wakeup [MRCPv2ConnectionAgent]
2023-01-09 13:12:21.238037 88.90% [DEBUG] apt_task.c:335 () Process Message [MRCPv2ConnectionAgent] [0x7ff2a801aed0;1;0]
2023-01-09 13:12:21.238037 88.90% [DEBUG] apt_task.c:263 () Signal Message to [MRCP Client] [0x7ff2b0012c30;2;0]
2023-01-09 13:12:21.238037 88.90% [DEBUG] apt_poller_task.c:249 () Wait for Messages [MRCPv2ConnectionAgent]
2023-01-09 13:12:21.238037 88.90% [DEBUG] apt_task.c:335 () Process Message [MRCP Client] [0x7ff2b0012c30;2;0]
2023-01-09 13:12:21.238037 88.90% [DEBUG] mrcp_client_session.c:292 (ASR-1) Control Channel Added ASR-1 <new@speechrecog>
2023-01-09 13:12:21.238037 88.90% [DEBUG] apt_consumer_task.c:135 () Wait for Messages [MRCP Client]
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_task.c:335 () Process Message [MediaEngine] [0x7ff2a8016110;1;0]
2023-01-09 13:12:21.258041 88.90% [DEBUG] mpf_context.c:180 () Add Media Context ASR-1
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_task.c:263 () Signal Message to [MRCP Client] [0x7ff2a00625a0;3;0]
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_task.c:335 () Process Message [MRCP Client] [0x7ff2a00625a0;3;0]
2023-01-09 13:12:21.258041 88.90% [DEBUG] mrcp_client_session.c:939 (ASR-1) Media Termination Added ASR-1 <new@media-tm>
2023-01-09 13:12:21.258041 88.90% [DEBUG] mrcp_client_session.c:939 (ASR-1) Media Termination Added ASR-1 <new@rtp-tm>
2023-01-09 13:12:21.258041 88.90% [INFO] mrcp_client_session.c:409 (ASR-1) Send Offer ASR-1 <new> [c:1 a:1 v:0] to 10.7.0.198:5060
2023-01-09 13:12:21.258041 88.90% [INFO] mrcp_sofiasip_client_agent.c:357 (ASR-1) Local SDP ASR-1 <new>
v=0
o=FreeSWITCH 0 0 IN IP4 10.7.0.182
s=-
c=IN IP4 10.7.0.182
t=0 0
m=application 9 TCP/MRCPv2 1
a=setup:active
a=connection:new
a=resource:speechrecog
a=cmid:1
m=audio 5002 RTP/AVP 0 8 96
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:96 L16/8000
a=sendonly
a=mid:1
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_consumer_task.c:135 () Wait for Messages [MRCP Client]
2023-01-09 13:12:21.258041 88.90% [INFO] mrcp_sofiasip_client_agent.c:617 () Receive SIP Event [nua_i_state] Status 0 INVITE sent [mrcpserver02]
2023-01-09 13:12:21.258041 88.90% [NOTICE] mrcp_sofiasip_client_agent.c:555 (ASR-1) SIP Call State ASR-1 [calling]
2023-01-09 13:12:21.258041 88.90% [INFO] mrcp_sofiasip_client_agent.c:617 () Receive SIP Event [nua_r_invite] Status 503 Service Unavailable [mrcpserver02]
2023-01-09 13:12:21.258041 88.90% [INFO] mrcp_sofiasip_client_agent.c:617 () Receive SIP Event [nua_i_state] Status 503 Service Unavailable [mrcpserver02]
2023-01-09 13:12:21.258041 88.90% [NOTICE] mrcp_sofiasip_client_agent.c:555 (ASR-1) SIP Call State ASR-1 [terminated]
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_task.c:263 () Signal Message to [MRCP Client] [0x558f49cfc130;1;0]
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_task.c:335 () Process Message [MRCP Client] [0x558f49cfc130;1;0]
2023-01-09 13:12:21.258041 88.90% [INFO] mrcp_client_session.c:149 (ASR-1) Receive Answer ASR-1 <new> [c:0 a:0 v:0] Status 503
2023-01-09 13:12:21.258041 88.90% [INFO] mrcp_client_session.c:453 (ASR-1) Raise App Response ASR-1 <new> [2] FAILURE [2]
2023-01-09 13:12:21.258041 88.90% [ERR] mod_unimrcp.c:1925 (ASR-1) RECOGNIZER channel error!
2023-01-09 13:12:21.258041 88.90% [DEBUG] mod_unimrcp.c:1589 (ASR-1) CLOSED ==> ERROR
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_consumer_task.c:135 () Wait for Messages [MRCP Client]
2023-01-09 13:12:21.258041 88.90% [DEBUG] mod_unimrcp.c:1073 (ASR-1) Terminating MRCP session
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_task.c:263 () Signal Message to [MRCP Client] [0x7ff2980dd6f0;4;0]
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_task.c:335 () Process Message [MRCP Client] [0x7ff2980dd6f0;4;0]
2023-01-09 13:12:21.258041 88.90% [INFO] mrcp_client_session.c:385 (ASR-1) Receive App Request ASR-1 <new> [1]
2023-01-09 13:12:21.258041 88.90% [DEBUG] mrcp_client_session.c:1277 (ASR-1) Dispatch App Request ASR-1 <new> [1]
2023-01-09 13:12:21.258041 88.90% [INFO] mrcp_client_session.c:828 (ASR-1) Terminate Session ASR-1 <new>
2023-01-09 13:12:21.258041 88.90% [DEBUG] mrcp_client_session.c:849 (ASR-1) Remove Control Channel ASR-1 <new>
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_task.c:263 () Signal Message to [MRCPv2ConnectionAgent] [0x7ff2a801ea60;1;0]
2023-01-09 13:12:21.258041 88.90% [DEBUG] mrcp_client_session.c:859 (ASR-1) Subtract Media Termination ASR-1 <new@media-tm>
2023-01-09 13:12:21.258041 88.90% [DEBUG] mrcp_client_session.c:880 (ASR-1) Subtract Media Termination ASR-1 <new@rtp-tm>
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_task.c:263 () Signal Message to [MediaEngine] [0x7ff2a00625a0;1;0]
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_task.c:263 () Signal Message to [MRCP Client] [0x558f49cfc130;1;1]
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_consumer_task.c:135 () Wait for Messages [MRCP Client]
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_task.c:335 () Process Message [MRCP Client] [0x558f49cfc130;1;1]
2023-01-09 13:12:21.258041 88.90% [INFO] mrcp_client_session.c:207 (ASR-1) Session Terminated ASR-1 <new>
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_consumer_task.c:135 () Wait for Messages [MRCP Client]
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_poller_task.c:259 () Process Poller Wakeup [MRCPv2ConnectionAgent]
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_task.c:335 () Process Message [MRCPv2ConnectionAgent] [0x7ff2a801ea60;1;0]
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_task.c:263 () Signal Message to [MRCP Client] [0x7ff2b0004150;2;2]
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_poller_task.c:249 () Wait for Messages [MRCPv2ConnectionAgent]
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_task.c:335 () Process Message [MRCP Client] [0x7ff2b0004150;2;2]
2023-01-09 13:12:21.258041 88.90% [DEBUG] mrcp_client_session.c:329 (ASR-1) Control Channel Removed ASR-1 <new@speechrecog>
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_consumer_task.c:135 () Wait for Messages [MRCP Client]
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_task.c:335 () Process Message [MediaEngine] [0x7ff2a00625a0;1;0]
2023-01-09 13:12:21.258041 88.90% [DEBUG] mpf_context.c:236 () Remove Media Context ASR-1
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_task.c:263 () Signal Message to [MRCP Client] [0x7ff2a8016110;3;0]
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_task.c:335 () Process Message [MRCP Client] [0x7ff2a8016110;3;0]
2023-01-09 13:12:21.258041 88.90% [DEBUG] mrcp_client_session.c:1009 (ASR-1) Media Termination Subtracted ASR-1 <new@media-tm>
2023-01-09 13:12:21.258041 88.90% [DEBUG] mrcp_client_session.c:1009 (ASR-1) Media Termination Subtracted ASR-1 <new@rtp-tm>
2023-01-09 13:12:21.258041 88.90% [INFO] mrcp_client.c:707 (ASR-1) Remove MRCP Handle ASR-1 <new>
2023-01-09 13:12:21.258041 88.90% [INFO] mrcp_client_session.c:453 (ASR-1) Raise App Response ASR-1 <new> [1] SUCCESS [0]
2023-01-09 13:12:21.258041 88.90% [DEBUG] mod_unimrcp.c:1840 (ASR-1) Destroying MRCP session
2023-01-09 13:12:21.258041 88.90% [NOTICE] mrcp_application.c:211 (ASR-1) Destroy MRCP Handle ASR-1
2023-01-09 13:12:21.258041 88.90% [DEBUG] mod_unimrcp.c:1589 (ASR-1) ERROR ==> CLOSED
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_consumer_task.c:135 () Wait for Messages [MRCP Client]
2023-01-09 13:12:21.258041 88.90% [NOTICE] switch_core_state_machine.c:382 sofia/internal/10...@10.7.0.182 has executed the last dialplan instruction, hanging up.
2023-01-09 13:12:21.258041 88.90% [NOTICE] switch_core_state_machine.c:384 Hangup sofia/internal/10...@10.7.0.182 [CS_EXECUTE] [NORMAL_CLEARING]
2023-01-09 13:12:21.258041 88.90% [DEBUG] switch_core_state_machine.c:647 (sofia/internal/10...@10.7.0.182) State EXECUTE going to sleep
2023-01-09 13:12:21.258041 88.90% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/10...@10.7.0.182) Running State Change CS_HANGUP (Cur 1 Tot 2)
2023-01-09 13:12:21.258041 88.90% [DEBUG] switch_core_state_machine.c:844 (sofia/internal/10...@10.7.0.182) Callstate Change ACTIVE -> HANGUP
2023-01-09 13:12:21.258041 88.90% [DEBUG] switch_core_state_machine.c:846 (sofia/internal/10...@10.7.0.182) State HANGUP
2023-01-09 13:12:21.258041 88.90% [DEBUG] mod_sofia.c:468 Channel sofia/internal/10...@10.7.0.182 hanging up, cause: NORMAL_CLEARING
2023-01-09 13:12:21.258041 88.90% [DEBUG] mod_sofia.c:522 Sending BYE to sofia/internal/10...@10.7.0.182
2023-01-09 13:12:21.258041 88.90% [DEBUG] switch_core_state_machine.c:59 sofia/internal/10...@10.7.0.182 Standard HANGUP, cause: NORMAL_CLEARING
2023-01-09 13:12:21.258041 88.90% [DEBUG] switch_core_state_machine.c:846 (sofia/internal/10...@10.7.0.182) State HANGUP going to sleep
2023-01-09 13:12:21.258041 88.90% [DEBUG] switch_core_state_machine.c:616 (sofia/internal/10...@10.7.0.182) State Change CS_HANGUP -> CS_REPORTING
2023-01-09 13:12:21.258041 88.90% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/10...@10.7.0.182) Running State Change CS_REPORTING (Cur 1 Tot 2)
2023-01-09 13:12:21.258041 88.90% [DEBUG] switch_core_state_machine.c:932 (sofia/internal/10...@10.7.0.182) State REPORTING
2023-01-09 13:12:21.258041 88.90% [DEBUG] switch_core_state_machine.c:168 sofia/internal/10...@10.7.0.182 Standard REPORTING, cause: NORMAL_CLEARING
2023-01-09 13:12:21.258041 88.90% [DEBUG] switch_core_state_machine.c:932 (sofia/internal/10...@10.7.0.182) State REPORTING going to sleep
2023-01-09 13:12:21.258041 88.90% [DEBUG] switch_core_state_machine.c:607 (sofia/internal/10...@10.7.0.182) State Change CS_REPORTING -> CS_DESTROY
2023-01-09 13:12:21.258041 88.90% [DEBUG] switch_core_session.c:1747 Session 2 (sofia/internal/10...@10.7.0.182) Locked, Waiting on external entities
2023-01-09 13:12:21.258041 88.90% [NOTICE] switch_core_session.c:1765 Session 2 (sofia/internal/10...@10.7.0.182) Ended
2023-01-09 13:12:21.258041 88.90% [NOTICE] switch_core_session.c:1769 Close Channel sofia/internal/10...@10.7.0.182 [CS_DESTROY]
2023-01-09 13:12:21.258041 88.90% [DEBUG] switch_core_state_machine.c:735 (sofia/internal/10...@10.7.0.182) Running State Change CS_DESTROY (Cur 0 Tot 2)
2023-01-09 13:12:21.258041 88.90% [DEBUG] switch_core_state_machine.c:745 (sofia/internal/10...@10.7.0.182) State DESTROY
2023-01-09 13:12:21.258041 88.90% [DEBUG] mod_sofia.c:379 sofia/internal/10...@10.7.0.182 SOFIA DESTROY
2023-01-09 13:12:21.258041 88.90% [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[0] PLC[0] FEC[0]
2023-01-09 13:12:21.258041 88.90% [DEBUG] mod_opus.c:740 Opus encoder stats: Frames[0] Bytes encoded[0] Encoded length ms[0] Average encoded bitrate bps[0]
2023-01-09 13:12:21.258041 88.90% [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[0] PLC[0] FEC[0]
2023-01-09 13:12:21.258041 88.90% [DEBUG] mod_opus.c:740 Opus encoder stats: Frames[0] Bytes encoded[0] Encoded length ms[0] Average encoded bitrate bps[0]
2023-01-09 13:12:21.258041 88.90% [DEBUG] switch_core_state_machine.c:175 sofia/internal/10...@10.7.0.182 Standard DESTROY
2023-01-09 13:12:21.258041 88.90% [DEBUG] switch_core_state_machine.c:745 (sofia/internal/10...@10.7.0.182) State DESTROY going to sleep
2023-01-09 13:12:20.198038 89.00% [NOTICE] mod_dptools.c:1408 Channel [sofia/internal/10...@10.7.0.182] has been answered
2023-01-09 13:12:20.218085 89.00% [DEBUG] switch_channel.c:3950 (sofia/internal/10...@10.7.0.182) Callstate Change EARLY -> ACTIVE
EXECUTE [depth=0] sofia/internal/10...@10.7.0.182 sleep(1000)
EXECUTE [depth=0] sofia/internal/10...@10.7.0.182 play_and_detect_speech(ivr/ivr-welcome_to_freeswitch.wav detect:unimrcp:mrcpserver02 {start-input-timers=false}builtin:speech/transcribe)
2023-01-09 13:12:21.238037 88.90% [INFO] mod_unimrcp.c:3139 asr_handle: name = unimrcp, codec = (null), rate = 48000, grammar = (null), param = mrcpserver02
2023-01-09 13:12:21.238037 88.90% [INFO] mod_unimrcp.c:3141 codec = L16, rate = 48000, dest = (null)
2023-01-09 13:12:21.238037 88.90% [DEBUG] mod_unimrcp.c:688 (ASR-1) audio queue created
2023-01-09 13:12:21.238037 88.90% [NOTICE] mrcp_application.c:117 (ASR-1) Create MRCP Handle 0x7ff2980e2778 [mrcpserver02]
2023-01-09 13:12:21.238037 88.90% [INFO] mrcp_client_session.c:131 (ASR-1) Create Channel ASR-1 <new>
2023-01-09 13:12:21.238037 88.90% [DEBUG] apt_task.c:263 () Signal Message to [MRCP Client] [0x7ff2980af9d0;4;0]
2023-01-09 13:12:21.238037 88.90% [DEBUG] apt_task.c:335 () Process Message [MRCP Client] [0x7ff2980af9d0;4;0]
2023-01-09 13:12:21.238037 88.90% [INFO] mrcp_client_session.c:385 (ASR-1) Receive App Request ASR-1 <new> [2]
2023-01-09 13:12:21.238037 88.90% [INFO] mrcp_client.c:697 (ASR-1) Add MRCP Handle ASR-1 <new>
2023-01-09 13:12:21.238037 88.90% [DEBUG] mrcp_client_session.c:1277 (ASR-1) Dispatch App Request ASR-1 <new> [2]
2023-01-09 13:12:21.238037 88.90% [DEBUG] apt_task.c:263 () Signal Message to [MRCPv2ConnectionAgent] [0x7ff2a801aed0;1;0]
2023-01-09 13:12:21.238037 88.90% [NOTICE] mrcp_client_session.c:717 (ASR-1) Add Control Channel ASR-1 <new@speechrecog>
2023-01-09 13:12:21.238037 88.90% [DEBUG] mrcp_client_session.c:743 (ASR-1) Add Media Termination ASR-1 <new@media-tm>
2023-01-09 13:12:21.238037 88.90% [DEBUG] mrcp_client_session.c:772 (ASR-1) Add Media Termination ASR-1 <new@rtp-tm>
2023-01-09 13:12:21.238037 88.90% [DEBUG] apt_task.c:263 () Signal Message to [MediaEngine] [0x7ff2a8016110;1;0]
2023-01-09 13:12:21.238037 88.90% [DEBUG] apt_consumer_task.c:135 () Wait for Messages [MRCP Client]
2023-01-09 13:12:21.238037 88.90% [DEBUG] apt_poller_task.c:259 () Process Poller Wakeup [MRCPv2ConnectionAgent]
2023-01-09 13:12:21.238037 88.90% [DEBUG] apt_task.c:335 () Process Message [MRCPv2ConnectionAgent] [0x7ff2a801aed0;1;0]
2023-01-09 13:12:21.238037 88.90% [DEBUG] apt_task.c:263 () Signal Message to [MRCP Client] [0x7ff2b0012c30;2;0]
2023-01-09 13:12:21.238037 88.90% [DEBUG] apt_poller_task.c:249 () Wait for Messages [MRCPv2ConnectionAgent]
2023-01-09 13:12:21.238037 88.90% [DEBUG] apt_task.c:335 () Process Message [MRCP Client] [0x7ff2b0012c30;2;0]
2023-01-09 13:12:21.238037 88.90% [DEBUG] mrcp_client_session.c:292 (ASR-1) Control Channel Added ASR-1 <new@speechrecog>
2023-01-09 13:12:21.238037 88.90% [DEBUG] apt_consumer_task.c:135 () Wait for Messages [MRCP Client]
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_task.c:335 () Process Message [MediaEngine] [0x7ff2a8016110;1;0]
2023-01-09 13:12:21.258041 88.90% [DEBUG] mpf_context.c:180 () Add Media Context ASR-1
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_task.c:263 () Signal Message to [MRCP Client] [0x7ff2a00625a0;3;0]
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_task.c:335 () Process Message [MRCP Client] [0x7ff2a00625a0;3;0]
2023-01-09 13:12:21.258041 88.90% [DEBUG] mrcp_client_session.c:939 (ASR-1) Media Termination Added ASR-1 <new@media-tm>
2023-01-09 13:12:21.258041 88.90% [DEBUG] mrcp_client_session.c:939 (ASR-1) Media Termination Added ASR-1 <new@rtp-tm>
2023-01-09 13:12:21.258041 88.90% [INFO] mrcp_client_session.c:409 (ASR-1) Send Offer ASR-1 <new> [c:1 a:1 v:0] to 10.7.0.198:5060
2023-01-09 13:12:21.258041 88.90% [INFO] mrcp_sofiasip_client_agent.c:357 (ASR-1) Local SDP ASR-1 <new>
v=0
o=FreeSWITCH 0 0 IN IP4 10.7.0.182
s=-
c=IN IP4 10.7.0.182
t=0 0
m=application 9 TCP/MRCPv2 1
a=setup:active
a=connection:new
a=resource:speechrecog
a=cmid:1
m=audio 5002 RTP/AVP 0 8 96
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:96 L16/8000
a=sendonly
a=mid:1
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_consumer_task.c:135 () Wait for Messages [MRCP Client]
2023-01-09 13:12:21.258041 88.90% [INFO] mrcp_sofiasip_client_agent.c:617 () Receive SIP Event [nua_i_state] Status 0 INVITE sent [mrcpserver02]
2023-01-09 13:12:21.258041 88.90% [NOTICE] mrcp_sofiasip_client_agent.c:555 (ASR-1) SIP Call State ASR-1 [calling]
2023-01-09 13:12:21.258041 88.90% [INFO] mrcp_sofiasip_client_agent.c:617 () Receive SIP Event [nua_r_invite] Status 503 Service Unavailable [mrcpserver02]
2023-01-09 13:12:21.258041 88.90% [INFO] mrcp_sofiasip_client_agent.c:617 () Receive SIP Event [nua_i_state] Status 503 Service Unavailable [mrcpserver02]
2023-01-09 13:12:21.258041 88.90% [NOTICE] mrcp_sofiasip_client_agent.c:555 (ASR-1) SIP Call State ASR-1 [terminated]
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_task.c:263 () Signal Message to [MRCP Client] [0x558f49cfc130;1;0]
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_task.c:335 () Process Message [MRCP Client] [0x558f49cfc130;1;0]
2023-01-09 13:12:21.258041 88.90% [INFO] mrcp_client_session.c:149 (ASR-1) Receive Answer ASR-1 <new> [c:0 a:0 v:0] Status 503
2023-01-09 13:12:21.258041 88.90% [INFO] mrcp_client_session.c:453 (ASR-1) Raise App Response ASR-1 <new> [2] FAILURE [2]
2023-01-09 13:12:21.258041 88.90% [ERR] mod_unimrcp.c:1925 (ASR-1) RECOGNIZER channel error!
2023-01-09 13:12:21.258041 88.90% [DEBUG] mod_unimrcp.c:1589 (ASR-1) CLOSED ==> ERROR
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_consumer_task.c:135 () Wait for Messages [MRCP Client]
2023-01-09 13:12:21.258041 88.90% [DEBUG] mod_unimrcp.c:1073 (ASR-1) Terminating MRCP session
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_task.c:263 () Signal Message to [MRCP Client] [0x7ff2980dd6f0;4;0]
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_task.c:335 () Process Message [MRCP Client] [0x7ff2980dd6f0;4;0]
2023-01-09 13:12:21.258041 88.90% [INFO] mrcp_client_session.c:385 (ASR-1) Receive App Request ASR-1 <new> [1]
2023-01-09 13:12:21.258041 88.90% [DEBUG] mrcp_client_session.c:1277 (ASR-1) Dispatch App Request ASR-1 <new> [1]
2023-01-09 13:12:21.258041 88.90% [INFO] mrcp_client_session.c:828 (ASR-1) Terminate Session ASR-1 <new>
2023-01-09 13:12:21.258041 88.90% [DEBUG] mrcp_client_session.c:849 (ASR-1) Remove Control Channel ASR-1 <new>
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_task.c:263 () Signal Message to [MRCPv2ConnectionAgent] [0x7ff2a801ea60;1;0]
2023-01-09 13:12:21.258041 88.90% [DEBUG] mrcp_client_session.c:859 (ASR-1) Subtract Media Termination ASR-1 <new@media-tm>
2023-01-09 13:12:21.258041 88.90% [DEBUG] mrcp_client_session.c:880 (ASR-1) Subtract Media Termination ASR-1 <new@rtp-tm>
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_task.c:263 () Signal Message to [MediaEngine] [0x7ff2a00625a0;1;0]
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_task.c:263 () Signal Message to [MRCP Client] [0x558f49cfc130;1;1]
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_consumer_task.c:135 () Wait for Messages [MRCP Client]
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_task.c:335 () Process Message [MRCP Client] [0x558f49cfc130;1;1]
2023-01-09 13:12:21.258041 88.90% [INFO] mrcp_client_session.c:207 (ASR-1) Session Terminated ASR-1 <new>
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_consumer_task.c:135 () Wait for Messages [MRCP Client]
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_poller_task.c:259 () Process Poller Wakeup [MRCPv2ConnectionAgent]
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_task.c:335 () Process Message [MRCPv2ConnectionAgent] [0x7ff2a801ea60;1;0]
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_task.c:263 () Signal Message to [MRCP Client] [0x7ff2b0004150;2;2]
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_poller_task.c:249 () Wait for Messages [MRCPv2ConnectionAgent]
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_task.c:335 () Process Message [MRCP Client] [0x7ff2b0004150;2;2]
2023-01-09 13:12:21.258041 88.90% [DEBUG] mrcp_client_session.c:329 (ASR-1) Control Channel Removed ASR-1 <new@speechrecog>
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_consumer_task.c:135 () Wait for Messages [MRCP Client]
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_task.c:335 () Process Message [MediaEngine] [0x7ff2a00625a0;1;0]
2023-01-09 13:12:21.258041 88.90% [DEBUG] mpf_context.c:236 () Remove Media Context ASR-1
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_task.c:263 () Signal Message to [MRCP Client] [0x7ff2a8016110;3;0]
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_task.c:335 () Process Message [MRCP Client] [0x7ff2a8016110;3;0]
2023-01-09 13:12:21.258041 88.90% [DEBUG] mrcp_client_session.c:1009 (ASR-1) Media Termination Subtracted ASR-1 <new@media-tm>
2023-01-09 13:12:21.258041 88.90% [DEBUG] mrcp_client_session.c:1009 (ASR-1) Media Termination Subtracted ASR-1 <new@rtp-tm>
2023-01-09 13:12:21.258041 88.90% [INFO] mrcp_client.c:707 (ASR-1) Remove MRCP Handle ASR-1 <new>
2023-01-09 13:12:21.258041 88.90% [INFO] mrcp_client_session.c:453 (ASR-1) Raise App Response ASR-1 <new> [1] SUCCESS [0]
2023-01-09 13:12:21.258041 88.90% [DEBUG] mod_unimrcp.c:1840 (ASR-1) Destroying MRCP session
2023-01-09 13:12:21.258041 88.90% [NOTICE] mrcp_application.c:211 (ASR-1) Destroy MRCP Handle ASR-1
2023-01-09 13:12:21.258041 88.90% [DEBUG] mod_unimrcp.c:1589 (ASR-1) ERROR ==> CLOSED
2023-01-09 13:12:21.258041 88.90% [DEBUG] apt_consumer_task.c:135 () Wait for Messages [MRCP Client]
2023-01-09 13:12:21.258041 88.90% [NOTICE] switch_core_state_machine.c:382 sofia/internal/10...@10.7.0.182 has executed the last dialplan instruction, hanging up.
2023-01-09 13:12:21.258041 88.90% [NOTICE] switch_core_state_machine.c:384 Hangup sofia/internal/10...@10.7.0.182 [CS_EXECUTE] [NORMAL_CLEARING]
2023-01-09 13:12:21.258041 88.90% [DEBUG] switch_core_state_machine.c:647 (sofia/internal/10...@10.7.0.182) State EXECUTE going to sleep
2023-01-09 13:12:21.258041 88.90% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/10...@10.7.0.182) Running State Change CS_HANGUP (Cur 1 Tot 2)
2023-01-09 13:12:21.258041 88.90% [DEBUG] switch_core_state_machine.c:844 (sofia/internal/10...@10.7.0.182) Callstate Change ACTIVE -> HANGUP
2023-01-09 13:12:21.258041 88.90% [DEBUG] switch_core_state_machine.c:846 (sofia/internal/10...@10.7.0.182) State HANGUP
2023-01-09 13:12:21.258041 88.90% [DEBUG] mod_sofia.c:468 Channel sofia/internal/10...@10.7.0.182 hanging up, cause: NORMAL_CLEARING
2023-01-09 13:12:21.258041 88.90% [DEBUG] mod_sofia.c:522 Sending BYE to sofia/internal/10...@10.7.0.182
2023-01-09 13:12:21.258041 88.90% [DEBUG] switch_core_state_machine.c:59 sofia/internal/10...@10.7.0.182 Standard HANGUP, cause: NORMAL_CLEARING
2023-01-09 13:12:21.258041 88.90% [DEBUG] switch_core_state_machine.c:846 (sofia/internal/10...@10.7.0.182) State HANGUP going to sleep
2023-01-09 13:12:21.258041 88.90% [DEBUG] switch_core_state_machine.c:616 (sofia/internal/10...@10.7.0.182) State Change CS_HANGUP -> CS_REPORTING
2023-01-09 13:12:21.258041 88.90% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/10...@10.7.0.182) Running State Change CS_REPORTING (Cur 1 Tot 2)
2023-01-09 13:12:21.258041 88.90% [DEBUG] switch_core_state_machine.c:932 (sofia/internal/10...@10.7.0.182) State REPORTING
2023-01-09 13:12:21.258041 88.90% [DEBUG] switch_core_state_machine.c:168 sofia/internal/10...@10.7.0.182 Standard REPORTING, cause: NORMAL_CLEARING
2023-01-09 13:12:21.258041 88.90% [DEBUG] switch_core_state_machine.c:932 (sofia/internal/10...@10.7.0.182) State REPORTING going to sleep
2023-01-09 13:12:21.258041 88.90% [DEBUG] switch_core_state_machine.c:607 (sofia/internal/10...@10.7.0.182) State Change CS_REPORTING -> CS_DESTROY
2023-01-09 13:12:21.258041 88.90% [DEBUG] switch_core_session.c:1747 Session 2 (sofia/internal/10...@10.7.0.182) Locked, Waiting on external entities
2023-01-09 13:12:21.258041 88.90% [NOTICE] switch_core_session.c:1765 Session 2 (sofia/internal/10...@10.7.0.182) Ended
2023-01-09 13:12:21.258041 88.90% [NOTICE] switch_core_session.c:1769 Close Channel sofia/internal/10...@10.7.0.182 [CS_DESTROY]
2023-01-09 13:12:21.258041 88.90% [DEBUG] switch_core_state_machine.c:735 (sofia/internal/10...@10.7.0.182) Running State Change CS_DESTROY (Cur 0 Tot 2)
2023-01-09 13:12:21.258041 88.90% [DEBUG] switch_core_state_machine.c:745 (sofia/internal/10...@10.7.0.182) State DESTROY
2023-01-09 13:12:21.258041 88.90% [DEBUG] mod_sofia.c:379 sofia/internal/10...@10.7.0.182 SOFIA DESTROY
2023-01-09 13:12:21.258041 88.90% [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[0] PLC[0] FEC[0]
2023-01-09 13:12:21.258041 88.90% [DEBUG] mod_opus.c:740 Opus encoder stats: Frames[0] Bytes encoded[0] Encoded length ms[0] Average encoded bitrate bps[0]
2023-01-09 13:12:21.258041 88.90% [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[0] PLC[0] FEC[0]
2023-01-09 13:12:21.258041 88.90% [DEBUG] mod_opus.c:740 Opus encoder stats: Frames[0] Bytes encoded[0] Encoded length ms[0] Average encoded bitrate bps[0]
2023-01-09 13:12:21.258041 88.90% [DEBUG] switch_core_state_machine.c:175 sofia/internal/10...@10.7.0.182 Standard DESTROY
2023-01-09 13:12:21.258041 88.90% [DEBUG] switch_core_state_machine.c:745 (sofia/internal/10...@10.7.0.182) State DESTROY going to sleep
From reading this freeswitch mail list they say that [ERR] mod_unimrcp.c:1925 (ASR-1) RECOGNIZER channel error! Is associated with the communication errors between unimrcp server and freeswitch.
So I went over to the server side again.
I have run the recog scenario and it completes with success. Now on the server side as I understand I need two files to adapt. The unimrcpserver.xml file (annexed), to show what codecs to use and enable the plugin for speech recog.
And the plugin config file but that one should not need any modifications.
As OS the freeswitch is running on a debian 11.6 with freeswitch version 1.10.8
The unimrcp server is an ubuntu 20.04 with unimrcp server 1.7.0
Any help is appreciated.
Kind Regards
Fidel Gil
Jan 13, 2023, 4:25:09 AM1/13/23
to UniMRCP
Solved it the reason why I am getting a channel Error is because of codec mismatch. I placed exactly the same line on both the profile and and the unimrcpserver config files. And it started to work.
According to this Maillist reply you can get that error only on the following cases for FreeSWITCH:
- The IP connection to the machine hosting the MRCP capable Speech Recognition Server is broken
- The Speech Recognition Server itself is not accepting the connection request
- MRCP profile configuration entry doesn’t have the correct IP address/port number
Kind Regards
Arsen Chaloyan
Jan 26, 2023, 6:50:11 PM1/26/23
to uni...@googlegroups.com
Glad the problem is resolved, Fidel. It looks like you were sending SIP/MRCPv2 INVITE to the 5060 port, whereas UniMRCP Server is listening on 8060 by default.
<param name="server-port" value="5060"/>
--
You received this message because you are subscribed to the Google Groups "UniMRCP" group.
To unsubscribe from this group and stop receiving emails from it, send an email to unimrcp+u...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/unimrcp/9bd38d2d-dea4-40a7-b37b-95e2c229c680n%40googlegroups.com.
--
Reply all
Reply to author
Forward
0 new messages