search

signalwire / freeswitch

FreeSWITCH is a Software Defined Telecom Stack enabling the digital transformation from proprietary telecom switches to a versatile software implementation that runs on any commodity hardware. From a Raspberry PI to a multi-core server, FreeSWITCH can unlock the telecommunications potential of any device.
https://freeswitch.com/#getting-started
Other
3.32k stars 1.38k forks source link

Failed to call detect_speech on both the caller and the callee simultaneously #2486

Closed allanwxm closed 3 weeks ago

allanwxm commented 3 weeks ago

Describe the bug Hello, I'm using detect_speech to implement ASR with mod_unimrcp or mod_vosk for both legs. At first, the speech recognition for both the caller and the callee works normally. However, after a while, both the caller and the callee start playing MOH, and speech recognition also stops functioning properly. Upon checking the logs, it was found that every time this issue occurs, both the caller and the callee simultaneously invoke detect_speech at the same millsecond, and MOH is played after 5 seconds. I tested with both version 1.10.8 and the latest version. The issue occurs for both mod_unimrcp and mod_vosk.

Package version or git hash

Trace logs 2024-06-12 14:16:29.734742 98.70% [NOTICE] sofia.c:8683 Channel [sofia/internal/1003@192.168.0.102:5060] has been answered 2024-06-12 14:16:29.734742 98.70% [DEBUG] switch_channel.c:3950 (sofia/internal/1003@192.168.0.102:5060) Callstate Change RINGING -> ACTIVE 2024-06-12 14:16:29.754666 98.70% [DEBUG] switch_core_codec.c:248 sofia/internal/1004@192.168.0.4:5060 Restore previous codec PCMA:8. 2024-06-12 14:16:29.754666 98.70% [DEBUG] switch_core_media.c:8761 Audio params are unchanged for sofia/internal/1004@192.168.0.4:5060. 2024-06-12 14:16:29.754666 98.70% [DEBUG] mod_sofia.c:913 Local SDP sofia/internal/1004@192.168.0.4:5060: v=0 o=FreeSWITCH 1718152534 1718152536 IN IP4 192.168.0.4 s=FreeSWITCH c=IN IP4 192.168.0.4 t=0 0 m=audio 20450 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=sendrecv

2024-06-12 14:16:29.754666 98.70% [NOTICE] switch_ivr_originate.c:3834 Channel [sofia/internal/1004@192.168.0.4:5060] has been answered 2024-06-12 14:16:29.754666 98.70% [DEBUG] switch_channel.c:3950 (sofia/internal/1004@192.168.0.4:5060) Callstate Change EARLY -> ACTIVE 2024-06-12 14:16:29.754666 98.70% [DEBUG] sofia.c:7499 Channel sofia/internal/1004@192.168.0.4:5060 entering state [completed][200] 2024-06-12 14:16:29.754666 98.70% [DEBUG] switch_ivr_originate.c:3892 Originate Resulted in Success: [sofia/internal/1003@192.168.0.102:5060] Peer UUID: 60a796f2-3870-42b0-b53b-f3836d19ae86 2024-06-12 14:16:29.754666 98.70% [DEBUG] switch_ivr_originate.c:3892 Originate Resulted in Success: [sofia/internal/1003@192.168.0.102:5060] Peer UUID: 60a796f2-3870-42b0-b53b-f3836d19ae86 2024-06-12 14:16:29.754666 98.70% [DEBUG] switch_ivr_bridge.c:1793 (sofia/internal/1003@192.168.0.102:5060) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA 2024-06-12 14:16:29.754666 98.70% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/1003@192.168.0.102:5060) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 50) 2024-06-12 14:16:29.754666 98.70% [DEBUG] switch_core_state_machine.c:650 (sofia/internal/1003@192.168.0.102:5060) State EXCHANGE_MEDIA 2024-06-12 14:16:29.754666 98.70% [DEBUG] mod_sofia.c:671 SOFIA EXCHANGE_MEDIA 2024-06-12 14:16:29.794667 98.70% [DEBUG] switch_rtp.c:7934 Correct audio ip/port confirmed. 2024-06-12 14:16:29.814669 98.70% [DEBUG] switch_rtp.c:7934 Correct audio ip/port confirmed. 2024-06-12 14:16:29.874665 98.60% [DEBUG] sofia.c:7499 Channel sofia/internal/1004@192.168.0.4:5060 entering state [ready][200] 2024-06-12 14:16:30.114743 98.60% [DEBUG] switch_ivr.c:632 sofia/internal/1004@192.168.0.4:5060 Command Execute [depth=0] detect_speech(unimrcp {start-input-timers=true,no-input-timeout=30000,recognition-timeout=30000}hello default) 2024-06-12 14:16:30.114743 98.60% [DEBUG] switch_ivr.c:632 sofia/internal/1003@192.168.0.102:5060 Command Execute [depth=0] detect_speech(unimrcp {start-input-timers=true,no-input-timeout=30000,recognition-timeout=30000}hello default) EXECUTE [depth=0] sofia/internal/1004@192.168.0.4:5060 detect_speech(unimrcp {start-input-timers=true,no-input-timeout=30000,recognition-timeout=30000}hello default) EXECUTE [depth=0] sofia/internal/1003@192.168.0.102:5060 detect_speech(unimrcp {start-input-timers=true,no-input-timeout=30000,recognition-timeout=30000}hello default) 2024-06-12 14:16:30.114743 98.60% [INFO] mod_unimrcp.c:3128 asr_handle: name = unimrcp, codec = (null), rate = 8000, grammar = (null), param = (null) 2024-06-12 14:16:30.114743 98.60% [INFO] mod_unimrcp.c:3128 asr_handle: name = unimrcp, codec = (null), rate = 8000, grammar = (null), param = (null) 2024-06-12 14:16:30.114743 98.60% [INFO] mod_unimrcp.c:3130 codec = L16, rate = 8000, dest = (null) 2024-06-12 14:16:30.114743 98.60% [INFO] mod_unimrcp.c:3130 codec = L16, rate = 8000, dest = (null) 2024-06-12 14:16:30.114743 98.60% [DEBUG] mod_unimrcp.c:684 (ASR-35) audio queue created 2024-06-12 14:16:30.114743 98.60% [DEBUG] mod_unimrcp.c:684 (ASR-36) audio queue created 2024-06-12 14:16:30.114743 98.60% [NOTICE] mrcp_application.c:96 (ASR-35) Create MRCP Handle 0x7f9764090320 [unimrcpserver-mrcp2] 2024-06-12 14:16:30.114743 98.60% [INFO] mrcp_client_session.c:133 (ASR-35) Create Channel ASR-35 2024-06-12 14:16:30.114743 98.60% [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7f976404da50;4;0] 2024-06-12 14:16:30.114743 98.60% [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7f976404da50;4;0] 2024-06-12 14:16:30.114743 98.60% [INFO] mrcp_client_session.c:387 (ASR-35) Receive App Request ASR-35 [2] 2024-06-12 14:16:30.114743 98.60% [INFO] mrcp_client.c:700 (ASR-35) Add MRCP Handle ASR-35 2024-06-12 14:16:30.114743 98.60% [DEBUG] mrcp_client_session.c:1283 (ASR-35) Dispatch App Request ASR-35 [2] 2024-06-12 14:16:30.114743 98.60% [DEBUG] apt_task.c:265 () Signal Message to [MRCPv2ConnectionAgent] [0x7f970c00e090;1;0] 2024-06-12 14:16:30.114743 98.60% [NOTICE] mrcp_client_session.c:719 (ASR-35) Add Control Channel ASR-35 new@speechrecog 2024-06-12 14:16:30.114743 98.60% [DEBUG] mrcp_client_session.c:745 (ASR-35) Add Media Termination ASR-35 new@media-tm 2024-06-12 14:16:30.114743 98.60% [DEBUG] mrcp_client_session.c:777 (ASR-35) Add Media Termination ASR-35 new@rtp-tm 2024-06-12 14:16:30.114743 98.60% [DEBUG] apt_task.c:265 () Signal Message to [MediaEngine] [0x7f970c030ae0;1;0] 2024-06-12 14:16:30.114743 98.60% [DEBUG] apt_poller_task.c:261 () Process Poller Wakeup [MRCPv2ConnectionAgent] 2024-06-12 14:16:30.114743 98.60% [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client] 2024-06-12 14:16:30.114743 98.60% [DEBUG] apt_task.c:337 () Process Message [MRCPv2ConnectionAgent] [0x7f970c00e090;1;0] 2024-06-12 14:16:30.114743 98.60% [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7f9708000ef0;2;0] 2024-06-12 14:16:30.114743 98.60% [DEBUG] apt_poller_task.c:251 () Wait for Messages [MRCPv2ConnectionAgent] 2024-06-12 14:16:30.114743 98.60% [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7f9708000ef0;2;0] 2024-06-12 14:16:30.114743 98.60% [DEBUG] mrcp_client_session.c:294 (ASR-35) Control Channel Added ASR-35 new@speechrecog 2024-06-12 14:16:30.114743 98.60% [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client] 2024-06-12 14:16:30.114743 98.60% [NOTICE] mrcp_application.c:96 (ASR-36) Create MRCP Handle 0x7f976c021ae0 [unimrcpserver-mrcp2] 2024-06-12 14:16:30.114743 98.60% [INFO] mrcp_client_session.c:133 (ASR-36) Create Channel ASR-36 2024-06-12 14:16:30.114743 98.60% [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7f976c01b0e0;4;0] 2024-06-12 14:16:30.114743 98.60% [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7f976c01b0e0;4;0] 2024-06-12 14:16:30.114743 98.60% [INFO] mrcp_client_session.c:387 (ASR-36) Receive App Request ASR-36 [2] 2024-06-12 14:16:30.114743 98.60% [INFO] mrcp_client.c:700 (ASR-36) Add MRCP Handle ASR-36 2024-06-12 14:16:30.114743 98.60% [DEBUG] mrcp_client_session.c:1283 (ASR-36) Dispatch App Request ASR-36 [2] 2024-06-12 14:16:30.114743 98.60% [DEBUG] apt_task.c:265 () Signal Message to [MRCPv2ConnectionAgent] [0x7f970c0012b0;1;0] 2024-06-12 14:16:30.114743 98.60% [NOTICE] mrcp_client_session.c:719 (ASR-36) Add Control Channel ASR-36 new@speechrecog 2024-06-12 14:16:30.114743 98.60% [DEBUG] mrcp_client_session.c:745 (ASR-36) Add Media Termination ASR-36 new@media-tm 2024-06-12 14:16:30.114743 98.60% [DEBUG] mrcp_client_session.c:777 (ASR-36) Add Media Termination ASR-36 new@rtp-tm 2024-06-12 14:16:30.114743 98.60% [DEBUG] apt_task.c:265 () Signal Message to [MediaEngine] [0x7f970c000b20;1;0] 2024-06-12 14:16:30.114743 98.60% [DEBUG] apt_poller_task.c:261 () Process Poller Wakeup [MRCPv2ConnectionAgent] 2024-06-12 14:16:30.114743 98.60% [DEBUG] apt_task.c:337 () Process Message [MRCPv2ConnectionAgent] [0x7f970c0012b0;1;0] 2024-06-12 14:16:30.114743 98.60% [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7f9708005d60;2;0] 2024-06-12 14:16:30.114743 98.60% [DEBUG] apt_poller_task.c:251 () Wait for Messages [MRCPv2ConnectionAgent] 2024-06-12 14:16:30.114743 98.60% [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client] 2024-06-12 14:16:30.114743 98.60% [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7f9708005d60;2;0] 2024-06-12 14:16:30.114743 98.60% [DEBUG] mrcp_client_session.c:294 (ASR-36) Control Channel Added ASR-36 new@speechrecog 2024-06-12 14:16:30.114743 98.60% [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client] 2024-06-12 14:16:30.114743 98.60% [DEBUG] apt_task.c:337 () Process Message [MediaEngine] [0x7f970c030ae0;1;0] 2024-06-12 14:16:30.114743 98.60% [DEBUG] mpf_context.c:182 () Add Media Context ASR-35 2024-06-12 14:16:30.114743 98.60% [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7f970c03bbc0;3;0] 2024-06-12 14:16:30.114743 98.60% [DEBUG] apt_task.c:337 () Process Message [MediaEngine] [0x7f970c000b20;1;0] 2024-06-12 14:16:30.114743 98.60% [DEBUG] mpf_context.c:182 () Add Media Context ASR-36 2024-06-12 14:16:30.114743 98.60% [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7f970c030ae0;3;0] 2024-06-12 14:16:30.114743 98.60% [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7f970c03bbc0;3;0] 2024-06-12 14:16:30.114743 98.60% [DEBUG] mrcp_client_session.c:944 (ASR-35) Media Termination Added ASR-35 new@media-tm 2024-06-12 14:16:30.114743 98.60% [DEBUG] mrcp_client_session.c:944 (ASR-35) Media Termination Added ASR-35 new@rtp-tm 2024-06-12 14:16:30.114743 98.60% [INFO] mrcp_client_session.c:411 (ASR-35) Send Offer ASR-35 [c:1 a:1 v:0] to 192.168.0.4:8060 2024-06-12 14:16:30.114743 98.60% [INFO] mrcp_sofiasip_client_agent.c:354 (ASR-35) Local SDP ASR-35 v=0 o=FreeSWITCH 0 0 IN IP4 127.0.0.1 s=- c=IN IP4 127.0.0.1 t=0 0 m=application 9 TCP/MRCPv2 1 a=setup:active a=connection:new a=resource:speechrecog a=cmid:1 m=audio 4070 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

2024-06-12 14:16:30.114743 98.60% [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client] 2024-06-12 14:16:30.114743 98.60% [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7f970c030ae0;3;0] 2024-06-12 14:16:30.114743 98.60% [DEBUG] mrcp_client_session.c:944 (ASR-36) Media Termination Added ASR-36 new@media-tm 2024-06-12 14:16:30.114743 98.60% [DEBUG] mrcp_client_session.c:944 (ASR-36) Media Termination Added ASR-36 new@rtp-tm 2024-06-12 14:16:30.114743 98.60% [INFO] mrcp_client_session.c:411 (ASR-36) Send Offer ASR-36 [c:1 a:1 v:0] to 192.168.0.4:8060 2024-06-12 14:16:30.114743 98.60% [INFO] mrcp_sofiasip_client_agent.c:354 (ASR-36) Local SDP ASR-36 v=0 o=FreeSWITCH 0 0 IN IP4 127.0.0.1 s=- c=IN IP4 127.0.0.1 t=0 0 m=application 9 TCP/MRCPv2 1 a=setup:active a=connection:new a=resource:speechrecog a=cmid:1 m=audio 4072 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

2024-06-12 14:16:30.114743 98.60% [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client] 2024-06-12 14:16:30.114743 98.60% [INFO] mrcp_sofiasip_client_agent.c:609 () Receive SIP Event [nua_i_state] Status 0 INVITE sent [unimrcpserver-mrcp2] 2024-06-12 14:16:30.114743 98.60% [NOTICE] mrcp_sofiasip_client_agent.c:547 (ASR-35) SIP Call State ASR-35 [calling] 2024-06-12 14:16:30.114743 98.60% [INFO] mrcp_sofiasip_client_agent.c:609 () Receive SIP Event [nua_i_state] Status 0 INVITE sent [unimrcpserver-mrcp2] 2024-06-12 14:16:30.114743 98.60% [NOTICE] mrcp_sofiasip_client_agent.c:547 (ASR-36) SIP Call State ASR-36 [calling] 2024-06-12 14:16:30.114743 98.60% [INFO] mrcp_sofiasip_client_agent.c:609 () Receive SIP Event [nua_r_invite] Status 200 OK [unimrcpserver-mrcp2] 2024-06-12 14:16:30.114743 98.60% [INFO] mrcp_sofiasip_client_agent.c:609 () Receive SIP Event [nua_i_state] Status 200 OK [unimrcpserver-mrcp2] 2024-06-12 14:16:30.114743 98.60% [NOTICE] mrcp_sofiasip_client_agent.c:547 (ASR-35) SIP Call State ASR-35 [ready] 2024-06-12 14:16:30.114743 98.60% [INFO] mrcp_sofiasip_client_agent.c:433 (ASR-35) Remote SDP ASR-35 v=0 o=UniMRCPServer 4995887880797188295 3733616210114157843 IN IP4 192.168.0.4 s=- c=IN IP4 192.168.0.4 t=0 0 m=application 1544 TCP/MRCPv2 1 a=setup:passive a=connection:new a=channel:4ee5e7f6288311ef@speechrecog a=cmid:1 m=audio 5026 RTP/AVP 0 a=rtpmap:0 PCMU/8000 a=recvonly a=mid:1

2024-06-12 14:16:30.114743 98.60% [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7f9710005cf0;1;0] 2024-06-12 14:16:30.114743 98.60% [INFO] mrcp_sofiasip_client_agent.c:609 () Receive SIP Event [nua_i_active] Status 200 Call active [unimrcpserver-mrcp2] 2024-06-12 14:16:30.114743 98.60% [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7f9710005cf0;1;0] 2024-06-12 14:16:30.114743 98.60% [INFO] mrcp_client_session.c:151 (ASR-35) Receive Answer ASR-35 [c:1 a:1 v:0] Status 200 2024-06-12 14:16:30.114743 98.60% [DEBUG] mrcp_client_session.c:1141 (ASR-35) Modify Control Channel ASR-35 <4ee5e7f6288311ef> 2024-06-12 14:16:30.114743 98.60% [DEBUG] apt_task.c:265 () Signal Message to [MRCPv2ConnectionAgent] [0x7f970c03bb50;1;0] 2024-06-12 14:16:30.114743 98.60% [DEBUG] mrcp_client_session.c:1180 (ASR-35) Modify Media Termination ASR-35 4ee5e7f6288311ef@rtp-tm 2024-06-12 14:16:30.114743 98.60% [DEBUG] apt_task.c:265 () Signal Message to [MediaEngine] [0x7f970c030ae0;1;0] 2024-06-12 14:16:30.114743 98.60% [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client] 2024-06-12 14:16:30.114743 98.60% [DEBUG] apt_poller_task.c:261 () Process Poller Wakeup [MRCPv2ConnectionAgent] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_task.c:337 () Process Message [MRCPv2ConnectionAgent] [0x7f970c03bb50;1;0] 2024-06-12 14:16:30.134666 98.60% [INFO] mrcp_sofiasip_client_agent.c:609 () Receive SIP Event [nua_r_invite] Status 200 OK [unimrcpserver-mrcp2] 2024-06-12 14:16:30.134666 98.60% [INFO] mrcp_sofiasip_client_agent.c:609 () Receive SIP Event [nua_i_state] Status 200 OK [unimrcpserver-mrcp2] 2024-06-12 14:16:30.134666 98.60% [NOTICE] mrcp_sofiasip_client_agent.c:547 (ASR-36) SIP Call State ASR-36 [ready] 2024-06-12 14:16:30.134666 98.60% [INFO] mrcp_sofiasip_client_agent.c:433 (ASR-36) Remote SDP ASR-36 v=0 o=UniMRCPServer 8629453683458247466 4457562421675229228 IN IP4 192.168.0.4 s=- c=IN IP4 192.168.0.4 t=0 0 m=application 1544 TCP/MRCPv2 1 a=setup:passive a=connection:new a=channel:4ee5f750288311ef@speechrecog a=cmid:1 m=audio 5028 RTP/AVP 0 a=rtpmap:0 PCMU/8000 a=recvonly a=mid:1

2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7f9710001d90;1;0] 2024-06-12 14:16:30.134666 98.60% [INFO] mrcp_sofiasip_client_agent.c:609 () Receive SIP Event [nua_i_active] Status 200 Call active [unimrcpserver-mrcp2] 2024-06-12 14:16:30.134666 98.60% [NOTICE] mrcp_client_connection.c:338 () Established TCP/MRCPv2 Connection 192.168.0.4:53650 <-> 192.168.0.4:1544 2024-06-12 14:16:30.134666 98.60% [INFO] mrcp_client_connection.c:435 (ASR-35) Add Control Channel 4ee5e7f6288311ef@speechrecog 192.168.0.4:53650 <-> 192.168.0.4:1544 [1] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7f9708009750;2;1] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_poller_task.c:251 () Wait for Messages [MRCPv2ConnectionAgent] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7f9710001d90;1;0] 2024-06-12 14:16:30.134666 98.60% [INFO] mrcp_client_session.c:151 (ASR-36) Receive Answer ASR-36 [c:1 a:1 v:0] Status 200 2024-06-12 14:16:30.134666 98.60% [DEBUG] mrcp_client_session.c:1141 (ASR-36) Modify Control Channel ASR-36 <4ee5f750288311ef> 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_task.c:265 () Signal Message to [MRCPv2ConnectionAgent] [0x7f970c020290;1;0] 2024-06-12 14:16:30.134666 98.60% [DEBUG] mrcp_client_session.c:1180 (ASR-36) Modify Media Termination ASR-36 4ee5f750288311ef@rtp-tm 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_task.c:265 () Signal Message to [MediaEngine] [0x7f970c03bbc0;1;0] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_poller_task.c:261 () Process Poller Wakeup [MRCPv2ConnectionAgent] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7f9708009750;2;1] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_task.c:337 () Process Message [MRCPv2ConnectionAgent] [0x7f970c020290;1;0] 2024-06-12 14:16:30.134666 98.60% [DEBUG] mrcp_client_session.c:311 (ASR-35) Control Channel Modified ASR-35 4ee5e7f6288311ef@speechrecog 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client] 2024-06-12 14:16:30.134666 98.60% [NOTICE] mrcp_client_connection.c:338 () Established TCP/MRCPv2 Connection 192.168.0.4:53652 <-> 192.168.0.4:1544 2024-06-12 14:16:30.134666 98.60% [INFO] mrcp_client_connection.c:435 (ASR-36) Add Control Channel 4ee5f750288311ef@speechrecog 192.168.0.4:53652 <-> 192.168.0.4:1544 [1] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7f9708001e00;2;1] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_poller_task.c:251 () Wait for Messages [MRCPv2ConnectionAgent] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7f9708001e00;2;1] 2024-06-12 14:16:30.134666 98.60% [DEBUG] mrcp_client_session.c:311 (ASR-36) Control Channel Modified ASR-36 4ee5f750288311ef@speechrecog 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_task.c:337 () Process Message [MediaEngine] [0x7f970c030ae0;1;0] 2024-06-12 14:16:30.134666 98.60% [INFO] mpf_rtp_stream.c:331 () Enable RTP Session 127.0.0.1:4070 2024-06-12 14:16:30.134666 98.60% [DEBUG] mpf_bridge.c:129 () Create Linear Audio Bridge ASR-35 2024-06-12 14:16:30.134666 98.60% [INFO] mpf_rtp_stream.c:921 () Open RTP Transmitter 127.0.0.1:4070 -> 192.168.0.4:5026 2024-06-12 14:16:30.134666 98.60% [INFO] mpf_bridge.c:93 () Media Path ASR-35 Source->[LPCM/8000/1]->Bridge->[LPCM/8000/1]->Encoder->[PCMU/8000/1]->Sink 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7f970c000b20;3;0] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_task.c:337 () Process Message [MediaEngine] [0x7f970c03bbc0;1;0] 2024-06-12 14:16:30.134666 98.60% [INFO] mpf_rtp_stream.c:331 () Enable RTP Session 127.0.0.1:4072 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7f970c000b20;3;0] 2024-06-12 14:16:30.134666 98.60% [DEBUG] mpf_bridge.c:129 () Create Linear Audio Bridge ASR-36 2024-06-12 14:16:30.134666 98.60% [DEBUG] mrcp_client_session.c:985 (ASR-35) Media Termination Modified ASR-35 4ee5e7f6288311ef@rtp-tm 2024-06-12 14:16:30.134666 98.60% [INFO] mpf_rtp_stream.c:921 () Open RTP Transmitter 127.0.0.1:4072 -> 192.168.0.4:5028 2024-06-12 14:16:30.134666 98.60% [INFO] mrcp_client_session.c:455 (ASR-35) Raise App Response ASR-35 <4ee5e7f6288311ef> [2] SUCCESS [0] 2024-06-12 14:16:30.134666 98.60% [INFO] mpf_bridge.c:93 () Media Path ASR-36 Source->[LPCM/8000/1]->Bridge->[LPCM/8000/1]->Encoder->[PCMU/8000/1]->Sink 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7f970c030ae0;3;0] 2024-06-12 14:16:30.134666 98.60% [DEBUG] mod_unimrcp.c:1894 (ASR-35) RECOGNIZER channel is ready, codec = LPCM, sample rate = 8000 2024-06-12 14:16:30.134666 98.60% [DEBUG] mod_unimrcp.c:1578 (ASR-35) CLOSED ==> READY 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7f970c030ae0;3;0] 2024-06-12 14:16:30.134666 98.60% [DEBUG] mrcp_client_session.c:985 (ASR-36) Media Termination Modified ASR-36 4ee5f750288311ef@rtp-tm 2024-06-12 14:16:30.134666 98.60% [INFO] mrcp_client_session.c:455 (ASR-36) Raise App Response ASR-36 <4ee5f750288311ef> [2] SUCCESS [0] 2024-06-12 14:16:30.134666 98.60% [DEBUG] mod_unimrcp.c:1056 (ASR-35) channel is ready 2024-06-12 14:16:30.134666 98.60% [DEBUG] mod_unimrcp.c:1894 (ASR-36) RECOGNIZER channel is ready, codec = LPCM, sample rate = 8000 2024-06-12 14:16:30.134666 98.60% [DEBUG] mod_unimrcp.c:1578 (ASR-36) CLOSED ==> READY 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client] 2024-06-12 14:16:30.134666 98.60% [DEBUG] switch_core_media_bug.c:978 Attaching BUG to sofia/internal/1004@192.168.0.4:5060 2024-06-12 14:16:30.134666 98.60% [DEBUG] mod_unimrcp.c:1056 (ASR-36) channel is ready 2024-06-12 14:16:30.134666 98.60% [DEBUG] switch_core_media_bug.c:978 Attaching BUG to sofia/internal/1003@192.168.0.102:5060 2024-06-12 14:16:30.134666 98.60% [DEBUG] mod_unimrcp.c:1459 (ASR-35) param = start-input-timers, val = true 2024-06-12 14:16:30.134666 98.60% [DEBUG] mod_unimrcp.c:1459 (ASR-35) param = no-input-timeout, val = 30000 2024-06-12 14:16:30.134666 98.60% [DEBUG] mod_unimrcp.c:1459 (ASR-35) param = recognition-timeout, val = 30000 2024-06-12 14:16:30.134666 98.60% [DEBUG] mod_unimrcp.c:3195 (ASR-35) grammar = hello, name = default 2024-06-12 14:16:30.134666 98.60% [DEBUG] mod_unimrcp.c:3220 (ASR-35) Grammar is inside file 2024-06-12 14:16:30.134666 98.60% [DEBUG] mod_unimrcp.c:3284 (ASR-35) grammar is application/srgs+xml 2024-06-12 14:16:30.134666 98.60% [DEBUG] mod_unimrcp.c:2355 (ASR-35) Loading grammar default, data = <?xml version="1.0" encoding="utf-8" ?>

one two

2024-06-12 14:16:30.134666 98.60% [DEBUG] mod_unimrcp.c:1578 (ASR-35) READY ==> PROCESSING 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7f9764104fe0;4;0] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7f9764104fe0;4;0] 2024-06-12 14:16:30.134666 98.60% [DEBUG] mod_unimrcp.c:1459 (ASR-36) param = start-input-timers, val = true 2024-06-12 14:16:30.134666 98.60% [INFO] mrcp_client_session.c:392 (ASR-35) Receive App MRCP Request ASR-35 <4ee5e7f6288311ef> 2024-06-12 14:16:30.134666 98.60% [DEBUG] mod_unimrcp.c:1459 (ASR-36) param = no-input-timeout, val = 30000 2024-06-12 14:16:30.134666 98.60% [INFO] mrcp_client_session.c:622 (ASR-35) Send MRCP Request ASR-35 4ee5e7f6288311ef@speechrecog [1] 2024-06-12 14:16:30.134666 98.60% [DEBUG] mod_unimrcp.c:1459 (ASR-36) param = recognition-timeout, val = 30000 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_task.c:265 () Signal Message to [MRCPv2ConnectionAgent] [0x7f970c020290;1;0] 2024-06-12 14:16:30.134666 98.60% [DEBUG] mod_unimrcp.c:3195 (ASR-36) grammar = hello, name = default 2024-06-12 14:16:30.134666 98.60% [DEBUG] mod_unimrcp.c:3220 (ASR-36) Grammar is inside file 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_poller_task.c:261 () Process Poller Wakeup [MRCPv2ConnectionAgent] 2024-06-12 14:16:30.134666 98.60% [DEBUG] mod_unimrcp.c:3284 (ASR-36) grammar is application/srgs+xml 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_task.c:337 () Process Message [MRCPv2ConnectionAgent] [0x7f970c020290;1;0] 2024-06-12 14:16:30.134666 98.60% [DEBUG] mod_unimrcp.c:2355 (ASR-36) Loading grammar default, data = <?xml version="1.0" encoding="utf-8" ?>

one two

2024-06-12 14:16:30.134666 98.60% [INFO] mrcp_client_connection.c:530 (ASR-35) Send MRCPv2 Data 192.168.0.4:53650 <-> 192.168.0.4:1544 [453 bytes] MRCP/2.0 453 DEFINE-GRAMMAR 1 Channel-Identifier: 4ee5e7f6288311ef@speechrecog Content-Type: application/srgs+xml Content-Id: default Content-Length: 292

<?xml version="1.0" encoding="utf-8" ?>

one two

2024-06-12 14:16:30.134666 98.60% [DEBUG] mod_unimrcp.c:1578 (ASR-36) READY ==> PROCESSING 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7f976c01ab70;4;0] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_poller_task.c:246 () Wait for Messages [MRCPv2ConnectionAgent] timeout [3000] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7f976c01ab70;4;0] 2024-06-12 14:16:30.134666 98.60% [INFO] mrcp_client_session.c:392 (ASR-36) Receive App MRCP Request ASR-36 <4ee5f750288311ef> 2024-06-12 14:16:30.134666 98.60% [INFO] mrcp_client_session.c:622 (ASR-36) Send MRCP Request ASR-36 4ee5f750288311ef@speechrecog [1] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_task.c:265 () Signal Message to [MRCPv2ConnectionAgent] [0x7f970c00e090;1;0] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_poller_task.c:261 () Process Poller Wakeup [MRCPv2ConnectionAgent] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_task.c:337 () Process Message [MRCPv2ConnectionAgent] [0x7f970c00e090;1;0] 2024-06-12 14:16:30.134666 98.60% [INFO] mrcp_client_connection.c:530 (ASR-36) Send MRCPv2 Data 192.168.0.4:53652 <-> 192.168.0.4:1544 [453 bytes] MRCP/2.0 453 DEFINE-GRAMMAR 1 Channel-Identifier: 4ee5f750288311ef@speechrecog Content-Type: application/srgs+xml Content-Id: default Content-Length: 292

<?xml version="1.0" encoding="utf-8" ?>

one two

2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_poller_task.c:246 () Wait for Messages [MRCPv2ConnectionAgent] timeout [3000] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_poller_task.c:269 () Process Signalled Descriptor [MRCPv2ConnectionAgent] 2024-06-12 14:16:30.134666 98.60% [INFO] mrcp_client_connection.c:635 () Receive MRCPv2 Data 192.168.0.4:53650 <-> 192.168.0.4:1544 [112 bytes] MRCP/2.0 112 1 200 COMPLETE Channel-Identifier: 4ee5e7f6288311ef@speechrecog Completion-Cause: 000 success

2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7f9708000ef0;2;3] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_poller_task.c:246 () Wait for Messages [MRCPv2ConnectionAgent] timeout [3000] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_poller_task.c:269 () Process Signalled Descriptor [MRCPv2ConnectionAgent] 2024-06-12 14:16:30.134666 98.60% [INFO] mrcp_client_connection.c:635 () Receive MRCPv2 Data 192.168.0.4:53652 <-> 192.168.0.4:1544 [112 bytes] MRCP/2.0 112 1 200 COMPLETE Channel-Identifier: 4ee5f750288311ef@speechrecog Completion-Cause: 000 success

2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7f9708001e00;2;3] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_poller_task.c:251 () Wait for Messages [MRCPv2ConnectionAgent] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7f9708000ef0;2;3] 2024-06-12 14:16:30.134666 98.60% [INFO] mrcp_client_session.c:500 (ASR-35) Raise App MRCP Response ASR-35 <4ee5e7f6288311ef> 2024-06-12 14:16:30.134666 98.60% [DEBUG] mod_unimrcp.c:3652 (ASR-35) grammar loaded 2024-06-12 14:16:30.134666 98.60% [DEBUG] mod_unimrcp.c:1578 (ASR-35) PROCESSING ==> READY 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7f9708001e00;2;3] 2024-06-12 14:16:30.134666 98.60% [INFO] mrcp_client_session.c:500 (ASR-36) Raise App MRCP Response ASR-36 <4ee5f750288311ef> 2024-06-12 14:16:30.134666 98.60% [DEBUG] mod_unimrcp.c:3652 (ASR-36) grammar loaded 2024-06-12 14:16:30.134666 98.60% [DEBUG] mod_unimrcp.c:1578 (ASR-36) PROCESSING ==> READY 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client] 2024-06-12 14:16:30.134666 98.60% [DEBUG] mod_unimrcp.c:2520 (ASR-35) Disabling all grammars 2024-06-12 14:16:30.134666 98.60% [DEBUG] mod_unimrcp.c:2479 (ASR-35) Enabling grammar default 2024-06-12 14:16:30.134666 98.60% [DEBUG] mod_unimrcp.c:2842 (ASR-35) "recognition-timeout": "30000" 2024-06-12 14:16:30.134666 98.60% [DEBUG] mod_unimrcp.c:2842 (ASR-35) "start-input-timers": "true" 2024-06-12 14:16:30.134666 98.60% [DEBUG] mod_unimrcp.c:2842 (ASR-35) "no-input-timeout": "30000" 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7f97640f1310;4;0] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7f97640f1310;4;0] 2024-06-12 14:16:30.134666 98.60% [INFO] mrcp_client_session.c:392 (ASR-35) Receive App MRCP Request ASR-35 <4ee5e7f6288311ef> 2024-06-12 14:16:30.134666 98.60% [INFO] mrcp_client_session.c:622 (ASR-35) Send MRCP Request ASR-35 4ee5e7f6288311ef@speechrecog [2] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_task.c:265 () Signal Message to [MRCPv2ConnectionAgent] [0x7f970c0012b0;1;0] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_poller_task.c:261 () Process Poller Wakeup [MRCPv2ConnectionAgent] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_task.c:337 () Process Message [MRCPv2ConnectionAgent] [0x7f970c0012b0;1;0] 2024-06-12 14:16:30.134666 98.60% [INFO] mrcp_client_connection.c:530 (ASR-35) Send MRCPv2 Data 192.168.0.4:53650 <-> 192.168.0.4:1544 [245 bytes] MRCP/2.0 245 RECOGNIZE 2 Channel-Identifier: 4ee5e7f6288311ef@speechrecog Content-Type: text/uri-list Cancel-If-Queue: false Recognition-Timeout: 30000 Start-Input-Timers: true No-Input-Timeout: 30000 Content-Length: 15

session:default 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_poller_task.c:246 () Wait for Messages [MRCPv2ConnectionAgent] timeout [3000] 2024-06-12 14:16:30.134666 98.60% [DEBUG] mod_unimrcp.c:2520 (ASR-36) Disabling all grammars 2024-06-12 14:16:30.134666 98.60% [DEBUG] mod_unimrcp.c:2479 (ASR-36) Enabling grammar default 2024-06-12 14:16:30.134666 98.60% [DEBUG] mod_unimrcp.c:2842 (ASR-36) "recognition-timeout": "30000" 2024-06-12 14:16:30.134666 98.60% [DEBUG] mod_unimrcp.c:2842 (ASR-36) "start-input-timers": "true" 2024-06-12 14:16:30.134666 98.60% [DEBUG] mod_unimrcp.c:2842 (ASR-36) "no-input-timeout": "30000" 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7f976c0458c0;4;0] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7f976c0458c0;4;0] 2024-06-12 14:16:30.134666 98.60% [INFO] mrcp_client_session.c:392 (ASR-36) Receive App MRCP Request ASR-36 <4ee5f750288311ef> 2024-06-12 14:16:30.134666 98.60% [INFO] mrcp_client_session.c:622 (ASR-36) Send MRCP Request ASR-36 4ee5f750288311ef@speechrecog [2] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_task.c:265 () Signal Message to [MRCPv2ConnectionAgent] [0x7f970c03bb50;1;0] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_poller_task.c:261 () Process Poller Wakeup [MRCPv2ConnectionAgent] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_task.c:337 () Process Message [MRCPv2ConnectionAgent] [0x7f970c03bb50;1;0] 2024-06-12 14:16:30.134666 98.60% [INFO] mrcp_client_connection.c:530 (ASR-36) Send MRCPv2 Data 192.168.0.4:53652 <-> 192.168.0.4:1544 [245 bytes] MRCP/2.0 245 RECOGNIZE 2 Channel-Identifier: 4ee5f750288311ef@speechrecog Content-Type: text/uri-list Cancel-If-Queue: false Recognition-Timeout: 30000 Start-Input-Timers: true No-Input-Timeout: 30000 Content-Length: 15

session:default 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_poller_task.c:246 () Wait for Messages [MRCPv2ConnectionAgent] timeout [3000] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_poller_task.c:269 () Process Signalled Descriptor [MRCPv2ConnectionAgent] 2024-06-12 14:16:30.134666 98.60% [INFO] mrcp_client_connection.c:635 () Receive MRCPv2 Data 192.168.0.4:53650 <-> 192.168.0.4:1544 [83 bytes] MRCP/2.0 83 2 200 IN-PROGRESS Channel-Identifier: 4ee5e7f6288311ef@speechrecog

2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7f9708009750;2;3] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7f9708009750;2;3] 2024-06-12 14:16:30.134666 98.60% [INFO] mrcp_client_session.c:500 (ASR-35) Raise App MRCP Response ASR-35 <4ee5e7f6288311ef> 2024-06-12 14:16:30.134666 98.60% [DEBUG] mod_unimrcp.c:3604 (ASR-35) RECOGNIZE IN PROGRESS 2024-06-12 14:16:30.134666 98.60% [DEBUG] mod_unimrcp.c:1578 (ASR-35) READY ==> PROCESSING 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_poller_task.c:246 () Wait for Messages [MRCPv2ConnectionAgent] timeout [3000] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_poller_task.c:269 () Process Signalled Descriptor [MRCPv2ConnectionAgent] 2024-06-12 14:16:30.134666 98.60% [INFO] mrcp_client_connection.c:635 () Receive MRCPv2 Data 192.168.0.4:53652 <-> 192.168.0.4:1544 [83 bytes] MRCP/2.0 83 2 200 IN-PROGRESS Channel-Identifier: 4ee5f750288311ef@speechrecog

2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7f9708009750;2;3] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_poller_task.c:251 () Wait for Messages [MRCPv2ConnectionAgent] 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7f9708009750;2;3] 2024-06-12 14:16:30.134666 98.60% [INFO] mrcp_client_session.c:500 (ASR-36) Raise App MRCP Response ASR-36 <4ee5f750288311ef> 2024-06-12 14:16:30.134666 98.60% [DEBUG] mod_unimrcp.c:3604 (ASR-36) RECOGNIZE IN PROGRESS 2024-06-12 14:16:30.134666 98.60% [DEBUG] mod_unimrcp.c:1578 (ASR-36) READY ==> PROCESSING 2024-06-12 14:16:30.134666 98.60% [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client] 2024-06-12 14:16:35.574701 97.90% [DEBUG] switch_core_io.c:448 Setting BUG Codec PCMA:8 2024-06-12 14:16:35.654666 97.90% [DEBUG] switch_ivr.c:632 sofia/internal/1003@192.168.0.102:5060 Command Execute [depth=0] playback(local_stream://moh) EXECUTE [depth=0] sofia/internal/1003@192.168.0.102:5060 playback(local_stream://moh) 2024-06-12 14:16:35.654666 97.90% [DEBUG] mod_local_stream.c:911 Opening Stream [moh/8000] 8000hz 2024-06-12 14:16:35.654666 97.90% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 20ms 2024-06-12 14:16:35.674670 97.90% [DEBUG] switch_ivr.c:632 sofia/internal/1004@192.168.0.4:5060 Command Execute [depth=0] playback(local_stream://moh) EXECUTE [depth=0] sofia/internal/1004@192.168.0.4:5060 playback(local_stream://moh) 2024-06-12 14:16:35.674670 97.90% [DEBUG] mod_local_stream.c:911 Opening Stream [moh/8000] 8000hz 2024-06-12 14:16:35.674670 97.90% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 20ms 2024-06-12 14:17:00.314743 96.87% [DEBUG] apt_poller_task.c:269 () Process Signalled Descriptor [MRCPv2ConnectionAgent] 2024-06-12 14:17:00.314743 96.87% [INFO] mrcp_client_connection.c:635 () Receive MRCPv2 Data 192.168.0.4:53650 <-> 192.168.0.4:1544 [322 bytes] MRCP/2.0 322 RECOGNITION-COMPLETE 2 COMPLETE Channel-Identifier: 4ee5e7f6288311ef@speechrecog Completion-Cause: 002 no-input-timeout Content-Type: application/nlsml+xml Vendor-Specific-Parameters: Content-Length: 97

{ "grammar" : "session:default", "voiceid" : "124ee5e7f6288311ef-1", "result" : "" }

2024-06-12 14:17:00.314743 96.87% [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7f9708000ef0;2;3] 2024-06-12 14:17:00.314743 96.87% [DEBUG] apt_poller_task.c:251 () Wait for Messages [MRCPv2ConnectionAgent] 2024-06-12 14:17:00.314743 96.87% [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7f9708000ef0;2;3] 2024-06-12 14:17:00.314743 96.87% [INFO] mrcp_client_session.c:516 (ASR-35) Raise App MRCP Event ASR-35 <4ee5e7f6288311ef> 2024-06-12 14:17:00.314743 96.87% [DEBUG] mod_unimrcp.c:3669 (ASR-35) RECOGNITION COMPLETE, Completion-Cause: 002 2024-06-12 14:17:00.314743 96.87% [DEBUG] mod_unimrcp.c:3678 (ASR-35) Recognition result is not null-terminated. Appending null terminator. 2024-06-12 14:17:00.314743 96.87% [DEBUG] mod_unimrcp.c:2727 (ASR-35) ASR adding result headers 2024-06-12 14:17:00.314743 96.87% [DEBUG] mod_unimrcp.c:2622 (ASR-35) result:

{ "grammar" : "session:default", "voiceid" : "124ee5e7f6288311ef-1", "result" : "" }

2024-06-12 14:17:00.314743 96.87% [DEBUG] mod_unimrcp.c:1578 (ASR-35) PROCESSING ==> READY 2024-06-12 14:17:00.314743 96.87% [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client] 2024-06-12 14:17:00.334665 96.87% [DEBUG] mod_unimrcp.c:2539 (ASR-35) SUCCESS, have result 2024-06-12 14:17:00.334665 96.87% [DEBUG] mod_unimrcp.c:2539 (ASR-35) SUCCESS, have result 2024-06-12 14:17:00.334665 96.87% [DEBUG] mod_unimrcp.c:2780 (ASR-35) result:

{ "grammar" : "session:default", "voiceid" : "124ee5e7f6288311ef-1", "result" : "" }

2024-06-12 14:17:00.434714 96.87% [DEBUG] apt_poller_task.c:269 () Process Signalled Descriptor [MRCPv2ConnectionAgent] 2024-06-12 14:17:00.434714 96.87% [INFO] mrcp_client_connection.c:635 () Receive MRCPv2 Data 192.168.0.4:53652 <-> 192.168.0.4:1544 [322 bytes] MRCP/2.0 322 RECOGNITION-COMPLETE 2 COMPLETE Channel-Identifier: 4ee5f750288311ef@speechrecog Completion-Cause: 002 no-input-timeout Content-Type: application/nlsml+xml Vendor-Specific-Parameters: Content-Length: 97

{ "grammar" : "session:default", "voiceid" : "124ee5f750288311ef-1", "result" : "" }

2024-06-12 14:17:00.434714 96.87% [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7f9708001e00;2;3] 2024-06-12 14:17:00.434714 96.87% [DEBUG] apt_poller_task.c:251 () Wait for Messages [MRCPv2ConnectionAgent] 2024-06-12 14:17:00.434714 96.87% [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7f9708001e00;2;3] 2024-06-12 14:17:00.434714 96.87% [INFO] mrcp_client_session.c:516 (ASR-36) Raise App MRCP Event ASR-36 <4ee5f750288311ef> 2024-06-12 14:17:00.434714 96.87% [DEBUG] mod_unimrcp.c:3669 (ASR-36) RECOGNITION COMPLETE, Completion-Cause: 002 2024-06-12 14:17:00.434714 96.87% [DEBUG] mod_unimrcp.c:3678 (ASR-36) Recognition result is not null-terminated. Appending null terminator. 2024-06-12 14:17:00.434714 96.87% [DEBUG] mod_unimrcp.c:2727 (ASR-36) ASR adding result headers 2024-06-12 14:17:00.434714 96.87% [DEBUG] mod_unimrcp.c:2622 (ASR-36) result:

{ "grammar" : "session:default", "voiceid" : "124ee5f750288311ef-1", "result" : "" }

2024-06-12 14:17:00.434714 96.87% [DEBUG] mod_unimrcp.c:1578 (ASR-36) PROCESSING ==> READY 2024-06-12 14:17:00.434714 96.87% [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client] 2024-06-12 14:17:00.434714 96.87% [DEBUG] mod_unimrcp.c:2539 (ASR-36) SUCCESS, have result 2024-06-12 14:17:00.434714 96.87% [DEBUG] mod_unimrcp.c:2539 (ASR-36) SUCCESS, have result 2024-06-12 14:17:00.434714 96.87% [DEBUG] mod_unimrcp.c:2780 (ASR-36) result:

{ "grammar" : "session:default", "voiceid" : "124ee5f750288311ef-1", "result" : "" }

allanwxm commented 3 weeks ago

Trace logs with mod_vosk 2024-06-12 15:26:20.074690 97.03% [DEBUG] switch_ivr.c:632 sofia/internal/1004@192.168.0.4:5060 Command Execute [depth=0] detect_speech(vosk default default) EXECUTE [depth=0] sofia/internal/1004@192.168.0.4:5060 detect_speech(vosk default default) 2024-06-12 15:26:20.074690 97.03% [DEBUG] switch_ivr.c:632 sofia/internal/1003@192.168.0.102:5060 Command Execute [depth=0] detect_speech(vosk default default) EXECUTE [depth=0] sofia/internal/1003@192.168.0.102:5060 detect_speech(vosk default default) 2024-06-12 15:26:20.094669 97.03% [INFO] mod_vosk.c:94 ASR open 2024-06-12 15:26:20.094669 97.03% [DEBUG] switch_core_media_bug.c:978 Attaching BUG to sofia/internal/1003@192.168.0.102:5060 2024-06-12 15:26:20.094669 97.03% [INFO] mod_vosk.c:94 ASR open 2024-06-12 15:26:20.094669 97.03% [DEBUG] switch_core_media_bug.c:978 Attaching BUG to sofia/internal/1004@192.168.0.4:5060 2024-06-12 15:26:25.714742 96.20% [DEBUG] switch_core_io.c:448 Setting BUG Codec PCMA:8 2024-06-12 15:26:25.794742 96.20% [DEBUG] switch_ivr.c:632 sofia/internal/1004@192.168.0.4:5060 Command Execute [depth=0] playback(local_stream://moh) EXECUTE [depth=0] sofia/internal/1004@192.168.0.4:5060 playback(local_stream://moh) 2024-06-12 15:26:25.794742 96.20% [DEBUG] mod_local_stream.c:911 Opening Stream [moh/8000] 8000hz 2024-06-12 15:26:25.794742 96.20% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 20ms 2024-06-12 15:26:25.794742 96.20% [DEBUG] switch_ivr.c:632 sofia/internal/1003@192.168.0.102:5060 Command Execute [depth=0] playback(local_stream://moh) EXECUTE [depth=0] sofia/internal/1003@192.168.0.102:5060 playback(local_stream://moh) 2024-06-12 15:26:25.794742 96.20% [DEBUG] mod_local_stream.c:911 Opening Stream [moh/8000] 8000hz 2024-06-12 15:26:25.794742 96.20% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 20ms 2024-06-12 15:26:25.874670 96.17% [DEBUG] mod_vosk.c:140 Sending data 3200 2024-06-12 15:26:25.874670 96.17% [DEBUG] mod_vosk.c:140 Sending data 3200 2024-06-12 15:26:25.894702 96.17% [DEBUG] mod_vosk.c:164 Recieved 20 bytes: { "partial" : "" } 2024-06-12 15:26:25.894702 96.17% [DEBUG] mod_vosk.c:164 Recieved 20 bytes: { "partial" : "" } 2024-06-12 15:26:26.074742 96.17% [DEBUG] mod_vosk.c:140 Sending data 3200 2024-06-12 15:26:26.074742 96.17% [DEBUG] mod_vosk.c:140 Sending data 3200 2024-06-12 15:26:26.094699 96.17% [DEBUG] mod_vosk.c:164 Recieved 20 bytes: { "partial" : "" } 2024-06-12 15:26:26.094699 96.17% [DEBUG] mod_vosk.c:164 Recieved 20 bytes: { "partial" : "" }

allanwxm commented 3 weeks ago

I forgot to add aleg when using uuid_broadcast with detect_speech. Adding aleg solves the issue.