Are there known issues using Google for recognition, and another provider like AWS for synthesis?

237 views
Skip to first unread message

Sean DiSanti

unread,
Oct 1, 2020, 9:07:22 PM10/1/20
to UniMRCP
We have been able to use each module independently through freeswitch 1.10.3 with unimrcp, but when we try to use both on the same call it will end up killing either freeswitch or unimrcp alternatingly. Here are the relevant logs:
1st attempt at synthesis works (freeswitch side):

b997fa2d-87c1-4a74-b08c-fb208c17d276 EXECUTE [depth=0] sofia/external/70255...@172.16.0.14 speak(unimrcp:betaspeechdetection1|emma|Welcome to FreeSWITCH)
2020-10-01 17:03:10.415794 [INFO] mod_unimrcp.c:1631 speech_handle: name = unimrcp, rate = 8000, speed = 0, samples = 160, voice = , engine = unimrcp, param = betaspeechdetection1
2020-10-01 17:03:10.415794 [INFO] mod_unimrcp.c:1634 voice = emma, rate = 8000
2020-10-01 17:03:10.415794 [DEBUG] mod_unimrcp.c:686 (TTS-0) audio queue created
2020-10-01 17:03:10.415794 [NOTICE] mrcp_application.c:96 (TTS-0) Create MRCP Handle 0x7fb4d410b000 [betaspeechdetection1]
2020-10-01 17:03:10.415794 [INFO] mrcp_client_session.c:133 (TTS-0) Create Channel TTS-0 <new>
2020-10-01 17:03:10.415794 [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7fb4d40f11d0;4;0]
2020-10-01 17:03:10.415794 [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7fb4d40f11d0;4;0]
2020-10-01 17:03:10.415794 [INFO] mrcp_client_session.c:387 (TTS-0) Receive App Request TTS-0 <new> [2]
2020-10-01 17:03:10.415794 [INFO] mrcp_client.c:700 (TTS-0) Add MRCP Handle TTS-0 <new>
2020-10-01 17:03:10.415794 [DEBUG] mrcp_client_session.c:1283 (TTS-0) Dispatch App Request TTS-0 <new> [2]
2020-10-01 17:03:10.415794 [DEBUG] apt_task.c:265 () Signal Message to [MRCPv2ConnectionAgent] [0x7fb540000ce0;1;0]
2020-10-01 17:03:10.415794 [NOTICE] mrcp_client_session.c:719 (TTS-0) Add Control Channel TTS-0 <new@speechsynth>
2020-10-01 17:03:10.415794 [DEBUG] mrcp_client_session.c:745 (TTS-0) Add Media Termination TTS-0 <new@media-tm>
2020-10-01 17:03:10.415794 [DEBUG] mrcp_client_session.c:777 (TTS-0) Add Media Termination TTS-0 <new@rtp-tm>
2020-10-01 17:03:10.415794 [DEBUG] apt_task.c:265 () Signal Message to [MediaEngine] [0x7fb53c004fe0;1;0]
2020-10-01 17:03:10.415794 [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client]
2020-10-01 17:03:10.415794 [DEBUG] apt_poller_task.c:261 () Process Poller Wakeup [MRCPv2ConnectionAgent]
2020-10-01 17:03:10.415794 [DEBUG] apt_task.c:337 () Process Message [MRCPv2ConnectionAgent] [0x7fb540000ce0;1;0]
2020-10-01 17:03:10.415794 [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7fb540000c90;2;0]
2020-10-01 17:03:10.415794 [DEBUG] apt_poller_task.c:251 () Wait for Messages [MRCPv2ConnectionAgent]
2020-10-01 17:03:10.415794 [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7fb540000c90;2;0]
2020-10-01 17:03:10.415794 [DEBUG] mrcp_client_session.c:294 (TTS-0) Control Channel Added TTS-0 <new@speechsynth>
2020-10-01 17:03:10.415794 [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client]
2020-10-01 17:03:10.415794 [DEBUG] apt_task.c:337 () Process Message [MediaEngine] [0x7fb53c004fe0;1;0]
2020-10-01 17:03:10.415794 [DEBUG] mpf_context.c:182 () Add Media Context TTS-0
2020-10-01 17:03:10.415794 [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7fb4e4001340;3;0]
2020-10-01 17:03:10.415794 [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7fb4e4001340;3;0]
2020-10-01 17:03:10.415794 [DEBUG] mrcp_client_session.c:944 (TTS-0) Media Termination Added TTS-0 <new@media-tm>
2020-10-01 17:03:10.415794 [DEBUG] mrcp_client_session.c:944 (TTS-0) Media Termination Added TTS-0 <new@rtp-tm>
2020-10-01 17:03:10.415794 [INFO] mrcp_client_session.c:411 (TTS-0) Send Offer TTS-0 <new> [c:1 a:1 v:0] to 172.21.36.150:8060
2020-10-01 17:03:10.415794 [INFO] mrcp_sofiasip_client_agent.c:354 (TTS-0) Local SDP TTS-0 <new>
v=0
o=FreeSWITCH 0 0 IN IP4 172.21.28.12
s=-
c=IN IP4 172.21.28.12
t=0 0
m=application 9 TCP/MRCPv2 1
a=setup:active
a=connection:new
a=resource:speechsynth
a=cmid:1
m=audio 14000 RTP/AVP 96
a=rtpmap:96 L16/8000
a=recvonly
a=mid:1

2020-10-01 17:03:10.415794 [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client]
2020-10-01 17:03:10.415794 [INFO] mrcp_sofiasip_client_agent.c:609 () Receive SIP Event [nua_i_state] Status 0 INVITE sent [betaspeechdetection1]
2020-10-01 17:03:10.415794 [NOTICE] mrcp_sofiasip_client_agent.c:547 (TTS-0) SIP Call State TTS-0 [calling]
2020-10-01 17:03:10.415794 [INFO] mrcp_sofiasip_client_agent.c:609 () Receive SIP Event [nua_r_invite] Status 200 OK [betaspeechdetection1]
2020-10-01 17:03:10.415794 [INFO] mrcp_sofiasip_client_agent.c:609 () Receive SIP Event [nua_i_state] Status 200 OK [betaspeechdetection1]
2020-10-01 17:03:10.415794 [NOTICE] mrcp_sofiasip_client_agent.c:547 (TTS-0) SIP Call State TTS-0 [ready]
2020-10-01 17:03:10.415794 [INFO] mrcp_sofiasip_client_agent.c:433 (TTS-0) Remote SDP TTS-0 <new>
v=0
o=UniMRCPServer 4376591137823952406 6754721302974012040 IN IP4 172.21.36.150
s=-
c=IN IP4 172.21.36.150
t=0 0
m=application 1544 TCP/MRCPv2 1
a=setup:passive
a=connection:new
a=channel:58a2a080e573419a@speechsynth
a=cmid:1
m=audio 5000 RTP/AVP 96
a=rtpmap:96 L16/8000
a=sendonly
a=mid:1

2020-10-01 17:03:10.415794 [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7fb534002d70;1;0]
2020-10-01 17:03:10.415794 [INFO] mrcp_sofiasip_client_agent.c:609 () Receive SIP Event [nua_i_active] Status 200 Call active [betaspeechdetection1]
2020-10-01 17:03:10.415794 [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7fb534002d70;1;0]
2020-10-01 17:03:10.415794 [INFO] mrcp_client_session.c:151 (TTS-0) Receive Answer TTS-0 <new> [c:1 a:1 v:0] Status 200
2020-10-01 17:03:10.415794 [DEBUG] mrcp_client_session.c:1141 (TTS-0) Modify Control Channel TTS-0 <58a2a080e573419a>
2020-10-01 17:03:10.415794 [DEBUG] apt_task.c:265 () Signal Message to [MRCPv2ConnectionAgent] [0x7fb540000c90;1;0]
2020-10-01 17:03:10.415794 [DEBUG] mrcp_client_session.c:1180 (TTS-0) Modify Media Termination TTS-0 <58a2a080e573419a@rtp-tm>
2020-10-01 17:03:10.415794 [DEBUG] apt_task.c:265 () Signal Message to [MediaEngine] [0x7fb4e4001340;1;0]
2020-10-01 17:03:10.415794 [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client]
2020-10-01 17:03:10.415794 [DEBUG] apt_poller_task.c:261 () Process Poller Wakeup [MRCPv2ConnectionAgent]
2020-10-01 17:03:10.415794 [DEBUG] apt_task.c:337 () Process Message [MRCPv2ConnectionAgent] [0x7fb540000c90;1;0]
2020-10-01 17:03:10.415794 [NOTICE] mrcp_client_connection.c:338 () Established TCP/MRCPv2 Connection 172.21.36.12:54620 <-> 172.21.36.150:1544
2020-10-01 17:03:10.415794 [INFO] mrcp_client_connection.c:435 (TTS-0) Add Control Channel <58a2a080e573419a@speechsynth> 172.21.36.12:54620 <-> 172.21.36.150:1544 [1]
2020-10-01 17:03:10.415794 [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7fb5400039d0;2;1]
2020-10-01 17:03:10.415794 [DEBUG] apt_poller_task.c:251 () Wait for Messages [MRCPv2ConnectionAgent]
2020-10-01 17:03:10.415794 [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7fb5400039d0;2;1]
2020-10-01 17:03:10.415794 [DEBUG] mrcp_client_session.c:311 (TTS-0) Control Channel Modified TTS-0 <58a2a080e573419a@speechsynth>
2020-10-01 17:03:10.415794 [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client]
2020-10-01 17:03:10.435812 [DEBUG] apt_task.c:337 () Process Message [MediaEngine] [0x7fb4e4001340;1;0]
2020-10-01 17:03:10.435812 [INFO] mpf_rtp_stream.c:331 () Enable RTP Session 172.21.28.12:14000
2020-10-01 17:03:10.435812 [DEBUG] mpf_bridge.c:129 () Create Linear Audio Bridge TTS-0
2020-10-01 17:03:10.435812 [INFO] mpf_rtp_stream.c:509 () Open RTP Receiver 172.21.28.12:14000 <- 172.21.36.150:5000 playout [0 ms] bounds [0 - 600 ms] adaptive [0] skew detection [1]
2020-10-01 17:03:10.435812 [INFO] mpf_bridge.c:93 () Media Path TTS-0 Source->[L16/8000/1]->Decoder->[LPCM/8000/1]->Bridge->[LPCM/8000/1]->Sink
2020-10-01 17:03:10.435812 [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7fb53c004fe0;3;0]
2020-10-01 17:03:10.435812 [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7fb53c004fe0;3;0]
2020-10-01 17:03:10.435812 [DEBUG] mrcp_client_session.c:985 (TTS-0) Media Termination Modified TTS-0 <58a2a080e573419a@rtp-tm>
2020-10-01 17:03:10.435812 [INFO] mrcp_client_session.c:455 (TTS-0) Raise App Response TTS-0 <58a2a080e573419a> [2] SUCCESS [0]
2020-10-01 17:03:10.435812 [DEBUG] mod_unimrcp.c:1904 (TTS-0) SYNTHESIZER channel is ready, codec = LPCM, sample rate = 8000, sessionid = 58a2a080e573419a
2020-10-01 17:03:10.435812 [DEBUG] mod_unimrcp.c:1584 (TTS-0) CLOSED ==> READY
2020-10-01 17:03:10.435812 [DEBUG] mod_unimrcp.c:1061 (TTS-0) channel is ready
2020-10-01 17:03:10.435812 [DEBUG] mod_unimrcp.c:1465 (TTS-0) param = Voice-Name, val = emma
2020-10-01 17:03:10.435812 [CRIT] mod_unimrcp.c:1941 global session was null!
b997fa2d-87c1-4a74-b08c-fb208c17d276 2020-10-01 17:03:10.435812 [DEBUG] switch_ivr_play_say.c:3023 OPEN TTS unimrcp:betaspeechdetection1
2020-10-01 17:03:10.435812 [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client]
b997fa2d-87c1-4a74-b08c-fb208c17d276 2020-10-01 17:03:10.435812 [DEBUG] switch_ivr_play_say.c:3033 Raw Codec Activated
2020-10-01 17:03:10.435812 [DEBUG] mod_unimrcp.c:1200 (TTS-0) Voice-Name: emma
2020-10-01 17:03:10.435812 [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7fb4d40f2af0;4;0]
2020-10-01 17:03:10.435812 [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7fb4d40f2af0;4;0]
2020-10-01 17:03:10.435812 [INFO] mrcp_client_session.c:392 (TTS-0) Receive App MRCP Request TTS-0 <58a2a080e573419a>
2020-10-01 17:03:10.435812 [INFO] mrcp_client_session.c:622 (TTS-0) Send MRCP Request TTS-0 <58a2a080e573419a@speechsynth> [1]
2020-10-01 17:03:10.435812 [DEBUG] apt_task.c:265 () Signal Message to [MRCPv2ConnectionAgent] [0x7fb53c0306e0;1;0]
2020-10-01 17:03:10.435812 [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client]
2020-10-01 17:03:10.435812 [DEBUG] apt_poller_task.c:261 () Process Poller Wakeup [MRCPv2ConnectionAgent]
2020-10-01 17:03:10.435812 [DEBUG] apt_task.c:337 () Process Message [MRCPv2ConnectionAgent] [0x7fb53c0306e0;1;0]
2020-10-01 17:03:10.435812 [INFO] mrcp_client_connection.c:530 (TTS-0) Send MRCPv2 Data 172.21.36.12:54620 <-> 172.21.36.150:1544 [159 bytes]
MRCP/2.0 159 SPEAK 1
Channel-Identifier: 58a2a080e573419a@speechsynth
Content-Type: text/plain
Voice-Name: emma
Content-Length: 21

Welcome to FreeSWITCH
2020-10-01 17:03:10.435812 [DEBUG] apt_poller_task.c:246 () Wait for Messages [MRCPv2ConnectionAgent] timeout [3000]
2020-10-01 17:03:10.435812 [WARNING] switch_cpp.cpp:1447 Entered custom_data_processing.lua
2020-10-01 17:03:10.435812 [WARNING] switch_cpp.cpp:1447 This is NOT a calldata available event. Exiting.
2020-10-01 17:03:10.635885 [DEBUG] apt_poller_task.c:269 () Process Signalled Descriptor [MRCPv2ConnectionAgent]
2020-10-01 17:03:10.635885 [INFO] mrcp_client_connection.c:635 () Receive MRCPv2 Data 172.21.36.12:54620 <-> 172.21.36.150:1544 [83 bytes]
MRCP/2.0 83 1 200 IN-PROGRESS
Channel-Identifier: 58a2a080e573419a@speechsynth


2020-10-01 17:03:10.635885 [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7fb540001290;2;3]
2020-10-01 17:03:10.635885 [DEBUG] apt_poller_task.c:251 () Wait for Messages [MRCPv2ConnectionAgent]
2020-10-01 17:03:10.635885 [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7fb540001290;2;3]
2020-10-01 17:03:10.635885 [INFO] mrcp_client_session.c:500 (TTS-0) Raise App MRCP Response TTS-0 <58a2a080e573419a>
2020-10-01 17:03:10.635885 [DEBUG] mod_unimrcp.c:2006 (TTS-0) REQUEST IN PROGRESS
2020-10-01 17:03:10.635885 [DEBUG] mod_unimrcp.c:1584 (TTS-0) READY ==> PROCESSING
2020-10-01 17:03:10.635885 [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client]
b997fa2d-87c1-4a74-b08c-fb208c17d276 2020-10-01 17:03:10.635885 [DEBUG] switch_ivr_play_say.c:2741 Speaking text: Welcome to FreeSWITCH
2020-10-01 17:03:11.675821 [INFO] mod_shout.c:332 LAME 3.100 64bits (http://lame.sf.net)
2020-10-01 17:03:11.675821 [INFO] mod_shout.c:332 polyphase lowpass filter disabled
2020-10-01 17:03:12.035875 [DEBUG] apt_poller_task.c:269 () Process Signalled Descriptor [MRCPv2ConnectionAgent]
2020-10-01 17:03:12.035875 [INFO] mrcp_client_connection.c:635 () Receive MRCPv2 Data 172.21.36.12:54620 <-> 172.21.36.150:1544 [122 bytes]
MRCP/2.0 122 SPEAK-COMPLETE 1 COMPLETE
Channel-Identifier: 58a2a080e573419a@speechsynth
Completion-Cause: 000 normal


2020-10-01 17:03:12.035875 [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7fb540000d30;2;3]
2020-10-01 17:03:12.035875 [DEBUG] apt_poller_task.c:251 () Wait for Messages [MRCPv2ConnectionAgent]
2020-10-01 17:03:12.035875 [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7fb540000d30;2;3]
2020-10-01 17:03:12.035875 [INFO] mrcp_client_session.c:516 (TTS-0) Raise App MRCP Event TTS-0 <58a2a080e573419a>
2020-10-01 17:03:12.035875 [DEBUG] mod_unimrcp.c:2036 (TTS-0) SPEAK-COMPLETE
2020-10-01 17:03:12.035875 [DEBUG] mod_unimrcp.c:1584 (TTS-0) PROCESSING ==> DONE
2020-10-01 17:03:12.035875 [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client]
2020-10-01 17:03:12.075807 [DEBUG] mod_unimrcp.c:1584 (TTS-0) DONE ==> READY
b997fa2d-87c1-4a74-b08c-fb208c17d276 2020-10-01 17:03:12.075807 [DEBUG] switch_ivr_play_say.c:2905 done speaking text
2020-10-01 17:03:12.075807 [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7fb4d4006a90;4;0]
2020-10-01 17:03:12.075807 [DEBUG] mod_unimrcp.c:926 (TTS-0) Waiting for MRCP session to terminate
2020-10-01 17:03:12.075807 [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7fb4d4006a90;4;0]
2020-10-01 17:03:12.075807 [INFO] mrcp_client_session.c:387 (TTS-0) Receive App Request TTS-0 <58a2a080e573419a> [1]
2020-10-01 17:03:12.075807 [DEBUG] mrcp_client_session.c:1283 (TTS-0) Dispatch App Request TTS-0 <58a2a080e573419a> [1]
2020-10-01 17:03:12.075807 [INFO] mrcp_client_session.c:833 (TTS-0) Terminate Session TTS-0 <58a2a080e573419a>
2020-10-01 17:03:12.075807 [DEBUG] mrcp_client_session.c:854 (TTS-0) Remove Control Channel TTS-0 <58a2a080e573419a>
2020-10-01 17:03:12.075807 [DEBUG] apt_task.c:265 () Signal Message to [MRCPv2ConnectionAgent] [0x7fb540001290;1;0]
2020-10-01 17:03:12.075807 [DEBUG] mrcp_client_session.c:864 (TTS-0) Subtract Media Termination TTS-0 <58a2a080e573419a@media-tm>
2020-10-01 17:03:12.075807 [DEBUG] mrcp_client_session.c:885 (TTS-0) Subtract Media Termination TTS-0 <58a2a080e573419a@rtp-tm>
2020-10-01 17:03:12.075807 [DEBUG] apt_task.c:265 () Signal Message to [MediaEngine] [0x7fb53c004fe0;1;0]
2020-10-01 17:03:12.075807 [DEBUG] apt_poller_task.c:261 () Process Poller Wakeup [MRCPv2ConnectionAgent]
2020-10-01 17:03:12.075807 [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client]
2020-10-01 17:03:12.075807 [DEBUG] apt_task.c:337 () Process Message [MRCPv2ConnectionAgent] [0x7fb540001290;1;0]
2020-10-01 17:03:12.075807 [INFO] mrcp_client_connection.c:459 (TTS-0) Remove Control Channel <58a2a080e573419a@speechsynth> [0]
2020-10-01 17:03:12.075807 [INFO] mrcp_client_connection.c:386 () Close TCP/MRCPv2 Connection 172.21.36.12:54620 <-> 172.21.36.150:1544
2020-10-01 17:03:12.075807 [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7fb5400015d0;2;2]
2020-10-01 17:03:12.075807 [DEBUG] apt_poller_task.c:251 () Wait for Messages [MRCPv2ConnectionAgent]
2020-10-01 17:03:12.075807 [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7fb5400015d0;2;2]
2020-10-01 17:03:12.075807 [DEBUG] mrcp_client_session.c:331 (TTS-0) Control Channel Removed TTS-0 <58a2a080e573419a@speechsynth>
2020-10-01 17:03:12.075807 [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client]
2020-10-01 17:03:12.075807 [DEBUG] apt_task.c:337 () Process Message [MediaEngine] [0x7fb53c004fe0;1;0]
2020-10-01 17:03:12.075807 [DEBUG] mpf_bridge.c:100 () Destroy Audio Bridge TTS-0
2020-10-01 17:03:12.075807 [INFO] mpf_rtp_stream.c:541 () Close RTP Receiver 172.21.28.12:14000 <- 172.21.36.150:5000 [r:70 l:0 j:54 p:0 d:0 i:0]
2020-10-01 17:03:12.075807 [DEBUG] mpf_context.c:238 () Remove Media Context TTS-0
2020-10-01 17:03:12.075807 [INFO] mpf_rtp_stream.c:418 () Remove RTP Session 172.21.28.12:14000
2020-10-01 17:03:12.075807 [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7fb4e4001340;3;0]
2020-10-01 17:03:12.075807 [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7fb4e4001340;3;0]
2020-10-01 17:03:12.075807 [DEBUG] mrcp_client_session.c:1014 (TTS-0) Media Termination Subtracted TTS-0 <58a2a080e573419a@media-tm>
2020-10-01 17:03:12.075807 [DEBUG] mrcp_client_session.c:1014 (TTS-0) Media Termination Subtracted TTS-0 <58a2a080e573419a@rtp-tm>
2020-10-01 17:03:12.075807 [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client]
2020-10-01 17:03:12.075807 [INFO] mrcp_sofiasip_client_agent.c:609 () Receive SIP Event [nua_r_bye] Status 200 OK [betaspeechdetection1]
2020-10-01 17:03:12.075807 [INFO] mrcp_sofiasip_client_agent.c:609 () Receive SIP Event [nua_i_state] Status 200 to BYE [betaspeechdetection1]
2020-10-01 17:03:12.075807 [NOTICE] mrcp_sofiasip_client_agent.c:547 (TTS-0) SIP Call State TTS-0 [terminated]
2020-10-01 17:03:12.075807 [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7fb534002fd0;1;1]
2020-10-01 17:03:12.075807 [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7fb534002fd0;1;1]
2020-10-01 17:03:12.075807 [INFO] mrcp_client_session.c:209 (TTS-0) Session Terminated TTS-0 <58a2a080e573419a>
2020-10-01 17:03:12.075807 [NOTICE] mrcp_client_connection.c:235 () Destroy TCP/MRCPv2 Connection 172.21.36.12:54620 <-> 172.21.36.150:1544
2020-10-01 17:03:12.075807 [INFO] mrcp_client.c:710 (TTS-0) Remove MRCP Handle TTS-0 <58a2a080e573419a>
2020-10-01 17:03:12.075807 [INFO] mrcp_client_session.c:455 (TTS-0) Raise App Response TTS-0 <58a2a080e573419a> [1] SUCCESS [0]
2020-10-01 17:03:12.075807 [DEBUG] mod_unimrcp.c:1835 (TTS-0) Destroying MRCP session
2020-10-01 17:03:12.075807 [NOTICE] mrcp_application.c:182 (TTS-0) Destroy MRCP Handle TTS-0
2020-10-01 17:03:12.075807 [DEBUG] mod_unimrcp.c:1584 (TTS-0) READY ==> CLOSED
2020-10-01 17:03:12.075807 [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client]
2020-10-01 17:03:12.075807 [DEBUG] mod_unimrcp.c:854 (TTS-0) audio queue destroyed

Immediately after on the same call we go to do a gather that receives a 407 status on recognize failed, and while that's happening unimrcp server actually dies and restarts itself here is the freeswitch side of the event:

b997fa2d-87c1-4a74-b08c-fb208c17d276 EXECUTE [depth=0] sofia/external/70255...@172.16.0.14 play_and_detect_speech(detect:unimrcp:betaspeechdetection1 {model=phone_call, use-enhanced=true} builtin:speech/transcribe)
b997fa2d-87c1-4a74-b08c-fb208c17d276 2020-10-01 17:03:12.095803 [INFO] mod_unimrcp.c:3174 asr_handle: name = unimrcp, codec = (null), rate = 8000, grammar = (null), param = betaspeechdetection1
b997fa2d-87c1-4a74-b08c-fb208c17d276 2020-10-01 17:03:12.095803 [INFO] mod_unimrcp.c:3176 codec = L16, rate = 8000, dest = (null)
b997fa2d-87c1-4a74-b08c-fb208c17d276 2020-10-01 17:03:12.095803 [DEBUG] mod_unimrcp.c:686 (ASR-1) audio queue created
2020-10-01 17:03:12.095803 [NOTICE] mrcp_application.c:96 (ASR-1) Create MRCP Handle 0x7fb4d4168620 [betaspeechdetection1]
2020-10-01 17:03:12.095803 [INFO] mrcp_client_session.c:133 (ASR-1) Create Channel ASR-1 <new>
2020-10-01 17:03:12.095803 [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7fb4d40e68c0;4;0]
2020-10-01 17:03:12.095803 [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7fb4d40e68c0;4;0]
2020-10-01 17:03:12.095803 [INFO] mrcp_client_session.c:387 (ASR-1) Receive App Request ASR-1 <new> [2]
2020-10-01 17:03:12.095803 [INFO] mrcp_client.c:700 (ASR-1) Add MRCP Handle ASR-1 <new>
2020-10-01 17:03:12.095803 [DEBUG] mrcp_client_session.c:1283 (ASR-1) Dispatch App Request ASR-1 <new> [2]
2020-10-01 17:03:12.095803 [DEBUG] apt_task.c:265 () Signal Message to [MRCPv2ConnectionAgent] [0x7fb53c005220;1;0]
2020-10-01 17:03:12.095803 [NOTICE] mrcp_client_session.c:719 (ASR-1) Add Control Channel ASR-1 <new@speechrecog>
2020-10-01 17:03:12.095803 [DEBUG] mrcp_client_session.c:745 (ASR-1) Add Media Termination ASR-1 <new@media-tm>
2020-10-01 17:03:12.095803 [DEBUG] mrcp_client_session.c:777 (ASR-1) Add Media Termination ASR-1 <new@rtp-tm>
2020-10-01 17:03:12.095803 [DEBUG] apt_task.c:265 () Signal Message to [MediaEngine] [0x7fb4e4001340;1;0]
2020-10-01 17:03:12.095803 [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client]
2020-10-01 17:03:12.095803 [DEBUG] apt_poller_task.c:261 () Process Poller Wakeup [MRCPv2ConnectionAgent]
2020-10-01 17:03:12.095803 [DEBUG] apt_task.c:337 () Process Message [MRCPv2ConnectionAgent] [0x7fb53c005220;1;0]
2020-10-01 17:03:12.095803 [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7fb5400015d0;2;0]
2020-10-01 17:03:12.095803 [DEBUG] apt_poller_task.c:251 () Wait for Messages [MRCPv2ConnectionAgent]
2020-10-01 17:03:12.095803 [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7fb5400015d0;2;0]
2020-10-01 17:03:12.095803 [DEBUG] mrcp_client_session.c:294 (ASR-1) Control Channel Added ASR-1 <new@speechrecog>
2020-10-01 17:03:12.095803 [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client]
2020-10-01 17:03:12.095803 [DEBUG] apt_task.c:337 () Process Message [MediaEngine] [0x7fb4e4001340;1;0]
2020-10-01 17:03:12.095803 [DEBUG] mpf_context.c:182 () Add Media Context ASR-1
2020-10-01 17:03:12.095803 [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7fb53c004fe0;3;0]
2020-10-01 17:03:12.095803 [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7fb53c004fe0;3;0]
2020-10-01 17:03:12.095803 [DEBUG] mrcp_client_session.c:944 (ASR-1) Media Termination Added ASR-1 <new@media-tm>
2020-10-01 17:03:12.095803 [DEBUG] mrcp_client_session.c:944 (ASR-1) Media Termination Added ASR-1 <new@rtp-tm>
2020-10-01 17:03:12.095803 [INFO] mrcp_client_session.c:411 (ASR-1) Send Offer ASR-1 <new> [c:1 a:1 v:0] to 172.21.36.150:8060
2020-10-01 17:03:12.095803 [INFO] mrcp_sofiasip_client_agent.c:354 (ASR-1) Local SDP ASR-1 <new>
v=0
o=FreeSWITCH 0 0 IN IP4 172.21.28.12
s=-
c=IN IP4 172.21.28.12
t=0 0
m=application 9 TCP/MRCPv2 1
a=setup:active
a=connection:new
a=resource:speechrecog
a=cmid:1
m=audio 14002 RTP/AVP 96
a=rtpmap:96 L16/8000
a=sendonly
a=mid:1

2020-10-01 17:03:12.095803 [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client]
2020-10-01 17:03:12.095803 [INFO] mrcp_sofiasip_client_agent.c:609 () Receive SIP Event [nua_i_state] Status 0 INVITE sent [betaspeechdetection1]
2020-10-01 17:03:12.095803 [NOTICE] mrcp_sofiasip_client_agent.c:547 (ASR-1) SIP Call State ASR-1 [calling]
2020-10-01 17:03:12.135809 [INFO] mrcp_sofiasip_client_agent.c:609 () Receive SIP Event [nua_r_invite] Status 200 OK [betaspeechdetection1]
2020-10-01 17:03:12.135809 [INFO] mrcp_sofiasip_client_agent.c:609 () Receive SIP Event [nua_i_state] Status 200 OK [betaspeechdetection1]
2020-10-01 17:03:12.135809 [NOTICE] mrcp_sofiasip_client_agent.c:547 (ASR-1) SIP Call State ASR-1 [ready]
2020-10-01 17:03:12.135809 [INFO] mrcp_sofiasip_client_agent.c:433 (ASR-1) Remote SDP ASR-1 <new>
v=0
o=UniMRCPServer 7363628002949451152 324806840264421206 IN IP4 172.21.36.150
s=-
c=IN IP4 172.21.36.150
t=0 0
m=application 1544 TCP/MRCPv2 1
a=setup:passive
a=connection:new
a=channel:06a2ce4ce3784a9a@speechrecog
a=cmid:1
m=audio 5002 RTP/AVP 96
a=rtpmap:96 L16/8000
a=recvonly
a=mid:1

2020-10-01 17:03:12.135809 [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7fb5340037a0;1;0]
2020-10-01 17:03:12.135809 [INFO] mrcp_sofiasip_client_agent.c:609 () Receive SIP Event [nua_i_active] Status 200 Call active [betaspeechdetection1]
2020-10-01 17:03:12.135809 [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7fb5340037a0;1;0]
2020-10-01 17:03:12.135809 [INFO] mrcp_client_session.c:151 (ASR-1) Receive Answer ASR-1 <new> [c:1 a:1 v:0] Status 200
2020-10-01 17:03:12.135809 [DEBUG] mrcp_client_session.c:1141 (ASR-1) Modify Control Channel ASR-1 <06a2ce4ce3784a9a>
2020-10-01 17:03:12.135809 [DEBUG] apt_task.c:265 () Signal Message to [MRCPv2ConnectionAgent] [0x7fb53c030850;1;0]
2020-10-01 17:03:12.135809 [DEBUG] mrcp_client_session.c:1180 (ASR-1) Modify Media Termination ASR-1 <06a2ce4ce3784a9a@rtp-tm>
2020-10-01 17:03:12.135809 [DEBUG] apt_task.c:265 () Signal Message to [MediaEngine] [0x7fb53c004fe0;1;0]
2020-10-01 17:03:12.135809 [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client]
2020-10-01 17:03:12.135809 [DEBUG] apt_poller_task.c:261 () Process Poller Wakeup [MRCPv2ConnectionAgent]
2020-10-01 17:03:12.135809 [DEBUG] apt_task.c:337 () Process Message [MRCPv2ConnectionAgent] [0x7fb53c030850;1;0]
2020-10-01 17:03:12.135809 [NOTICE] mrcp_client_connection.c:338 () Established TCP/MRCPv2 Connection 172.21.36.12:54622 <-> 172.21.36.150:1544
2020-10-01 17:03:12.135809 [INFO] mrcp_client_connection.c:435 (ASR-1) Add Control Channel <06a2ce4ce3784a9a@speechrecog> 172.21.36.12:54622 <-> 172.21.36.150:1544 [1]
2020-10-01 17:03:12.135809 [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7fb540003990;2;1]
2020-10-01 17:03:12.135809 [DEBUG] apt_poller_task.c:251 () Wait for Messages [MRCPv2ConnectionAgent]
2020-10-01 17:03:12.135809 [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7fb540003990;2;1]
2020-10-01 17:03:12.135809 [DEBUG] mrcp_client_session.c:311 (ASR-1) Control Channel Modified ASR-1 <06a2ce4ce3784a9a@speechrecog>
2020-10-01 17:03:12.135809 [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client]
2020-10-01 17:03:12.135809 [DEBUG] apt_task.c:337 () Process Message [MediaEngine] [0x7fb53c004fe0;1;0]
2020-10-01 17:03:12.135809 [INFO] mpf_rtp_stream.c:331 () Enable RTP Session 172.21.28.12:14002
2020-10-01 17:03:12.135809 [DEBUG] mpf_bridge.c:129 () Create Linear Audio Bridge ASR-1
2020-10-01 17:03:12.135809 [INFO] mpf_rtp_stream.c:921 () Open RTP Transmitter 172.21.28.12:14002 -> 172.21.36.150:5002
2020-10-01 17:03:12.135809 [INFO] mpf_bridge.c:93 () Media Path ASR-1 Source->[LPCM/8000/1]->Bridge->[LPCM/8000/1]->Encoder->[L16/8000/1]->Sink
2020-10-01 17:03:12.135809 [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7fb4e4001340;3;0]
2020-10-01 17:03:12.135809 [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7fb4e4001340;3;0]
2020-10-01 17:03:12.135809 [DEBUG] mrcp_client_session.c:985 (ASR-1) Media Termination Modified ASR-1 <06a2ce4ce3784a9a@rtp-tm>
2020-10-01 17:03:12.135809 [INFO] mrcp_client_session.c:455 (ASR-1) Raise App Response ASR-1 <06a2ce4ce3784a9a> [2] SUCCESS [0]
b997fa2d-87c1-4a74-b08c-fb208c17d276 2020-10-01 17:03:12.135809 [DEBUG] mod_unimrcp.c:1904 (ASR-1) RECOGNIZER channel is ready, codec = LPCM, sample rate = 8000, sessionid = 06a2ce4ce3784a9a
b997fa2d-87c1-4a74-b08c-fb208c17d276 2020-10-01 17:03:12.135809 [DEBUG] mod_unimrcp.c:1584 (ASR-1) CLOSED ==> READY
b997fa2d-87c1-4a74-b08c-fb208c17d276 2020-10-01 17:03:12.135809 [DEBUG] mod_unimrcp.c:1061 (ASR-1) channel is ready
b997fa2d-87c1-4a74-b08c-fb208c17d276 2020-10-01 17:03:12.135809 [DEBUG] mod_unimrcp.c:1932 MRCP-Channel-Id: 06a2ce4ce3784a9a
2020-10-01 17:03:12.135809 [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client]
b997fa2d-87c1-4a74-b08c-fb208c17d276 2020-10-01 17:03:12.135809 [DEBUG] switch_core_media_bug.c:970 Attaching BUG to sofia/external/70255...@172.16.0.14
b997fa2d-87c1-4a74-b08c-fb208c17d276 2020-10-01 17:03:12.135809 [DEBUG] mod_unimrcp.c:1465 (ASR-1) param = model, val = phone_call
b997fa2d-87c1-4a74-b08c-fb208c17d276 2020-10-01 17:03:12.135809 [DEBUG] mod_unimrcp.c:1465 (ASR-1) param = use-enhanced, val = true
b997fa2d-87c1-4a74-b08c-fb208c17d276 2020-10-01 17:03:12.135809 [DEBUG] mod_unimrcp.c:3241 (ASR-1) grammar =  builtin:speech/transcribe, name =
b997fa2d-87c1-4a74-b08c-fb208c17d276 2020-10-01 17:03:12.135809 [DEBUG] mod_unimrcp.c:3258 (ASR-1) Grammar is URI
b997fa2d-87c1-4a74-b08c-fb208c17d276 2020-10-01 17:03:12.135809 [DEBUG] mod_unimrcp.c:3330 (ASR-1) grammar is text/uri-list
b997fa2d-87c1-4a74-b08c-fb208c17d276 2020-10-01 17:03:12.135809 [DEBUG] mod_unimrcp.c:2394 (ASR-1) Loading grammar 044cdbf4-a726-4cdc-88f9-faaee0478f5f, data = builtin:speech/transcribe
b997fa2d-87c1-4a74-b08c-fb208c17d276 2020-10-01 17:03:12.135809 [DEBUG] mod_unimrcp.c:2559 (ASR-1) Disabling all grammars
b997fa2d-87c1-4a74-b08c-fb208c17d276 2020-10-01 17:03:12.135809 [DEBUG] mod_unimrcp.c:2518 (ASR-1) Enabling grammar 044cdbf4-a726-4cdc-88f9-faaee0478f5f
b997fa2d-87c1-4a74-b08c-fb208c17d276 2020-10-01 17:03:12.135809 [DEBUG] mod_unimrcp.c:2893 (ASR-1) (vendor-specific value) model: phone_call
b997fa2d-87c1-4a74-b08c-fb208c17d276 2020-10-01 17:03:12.135809 [DEBUG] mod_unimrcp.c:2897 (ASR-1) creating vendor specific pair array
b997fa2d-87c1-4a74-b08c-fb208c17d276 2020-10-01 17:03:12.135809 [DEBUG] mod_unimrcp.c:2893 (ASR-1) (vendor-specific value) use-enhanced: true
2020-10-01 17:03:12.135809 [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7fb4d414ba30;4;0]
2020-10-01 17:03:12.135809 [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7fb4d414ba30;4;0]
2020-10-01 17:03:12.135809 [INFO] mrcp_client_session.c:392 (ASR-1) Receive App MRCP Request ASR-1 <06a2ce4ce3784a9a>
2020-10-01 17:03:12.135809 [INFO] mrcp_client_session.c:622 (ASR-1) Send MRCP Request ASR-1 <06a2ce4ce3784a9a@speechrecog> [1]
2020-10-01 17:03:12.135809 [DEBUG] apt_task.c:265 () Signal Message to [MRCPv2ConnectionAgent] [0x7fb53c032ae0;1;0]
2020-10-01 17:03:12.135809 [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client]
2020-10-01 17:03:12.135809 [DEBUG] apt_poller_task.c:261 () Process Poller Wakeup [MRCPv2ConnectionAgent]
2020-10-01 17:03:12.135809 [DEBUG] apt_task.c:337 () Process Message [MRCPv2ConnectionAgent] [0x7fb53c032ae0;1;0]
2020-10-01 17:03:12.135809 [INFO] mrcp_client_connection.c:530 (ASR-1) Send MRCPv2 Data 172.21.36.12:54622 <-> 172.21.36.150:1544 [240 bytes]
MRCP/2.0 240 RECOGNIZE 1
Channel-Identifier: 06a2ce4ce3784a9a@speechrecog
Content-Type: text/uri-list
Cancel-If-Queue: false
Vendor-Specific-Parameters: model=phone_call;use-enhanced=true
Content-Length: 25

builtin:speech/transcribe
2020-10-01 17:03:12.135809 [DEBUG] apt_poller_task.c:246 () Wait for Messages [MRCPv2ConnectionAgent] timeout [3000]
2020-10-01 17:03:12.135809 [DEBUG] apt_poller_task.c:269 () Process Signalled Descriptor [MRCPv2ConnectionAgent]
2020-10-01 17:03:12.135809 [INFO] mrcp_client_connection.c:635 () Receive MRCPv2 Data 172.21.36.12:54622 <-> 172.21.36.150:1544 [83 bytes]
MRCP/2.0 83 1 200 IN-PROGRESS
Channel-Identifier: 06a2ce4ce3784a9a@speechrecog


2020-10-01 17:03:12.135809 [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7fb5400015d0;2;3]
2020-10-01 17:03:12.135809 [DEBUG] apt_poller_task.c:251 () Wait for Messages [MRCPv2ConnectionAgent]
2020-10-01 17:03:12.135809 [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7fb5400015d0;2;3]
2020-10-01 17:03:12.135809 [INFO] mrcp_client_session.c:500 (ASR-1) Raise App MRCP Response ASR-1 <06a2ce4ce3784a9a>
b997fa2d-87c1-4a74-b08c-fb208c17d276 2020-10-01 17:03:12.135809 [DEBUG] mod_unimrcp.c:3650 (ASR-1) RECOGNIZE IN PROGRESS
b997fa2d-87c1-4a74-b08c-fb208c17d276 2020-10-01 17:03:12.135809 [DEBUG] mod_unimrcp.c:1584 (ASR-1) READY ==> PROCESSING
2020-10-01 17:03:12.135809 [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client]
b997fa2d-87c1-4a74-b08c-fb208c17d276 2020-10-01 17:03:12.135809 [DEBUG] mod_unimrcp.c:1395 (ASR-1) Stopping RECOGNIZER
2020-10-01 17:03:12.135809 [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7fb4d4011900;4;0]
2020-10-01 17:03:12.135809 [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7fb4d4011900;4;0]
2020-10-01 17:03:12.135809 [INFO] mrcp_client_session.c:392 (ASR-1) Receive App MRCP Request ASR-1 <06a2ce4ce3784a9a>
2020-10-01 17:03:12.135809 [INFO] mrcp_client_session.c:622 (ASR-1) Send MRCP Request ASR-1 <06a2ce4ce3784a9a@speechrecog> [2]
2020-10-01 17:03:12.135809 [DEBUG] apt_task.c:265 () Signal Message to [MRCPv2ConnectionAgent] [0x7fb53c032ae0;1;0]
2020-10-01 17:03:12.135809 [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client]
2020-10-01 17:03:12.135809 [DEBUG] apt_poller_task.c:261 () Process Poller Wakeup [MRCPv2ConnectionAgent]
2020-10-01 17:03:12.135809 [DEBUG] apt_task.c:337 () Process Message [MRCPv2ConnectionAgent] [0x7fb53c032ae0;1;0]
2020-10-01 17:03:12.135809 [INFO] mrcp_client_connection.c:530 (ASR-1) Send MRCPv2 Data 172.21.36.12:54622 <-> 172.21.36.150:1544 [72 bytes]
MRCP/2.0 72 STOP 2
Channel-Identifier: 06a2ce4ce3784a9a@speechrecog


2020-10-01 17:03:12.135809 [DEBUG] apt_poller_task.c:246 () Wait for Messages [MRCPv2ConnectionAgent] timeout [3000]
2020-10-01 17:03:12.155802 [WARNING] switch_cpp.cpp:1447 Entered custom_data_processing.lua
2020-10-01 17:03:12.155802 [WARNING] switch_cpp.cpp:1447 This is NOT a calldata available event. Exiting.
2020-10-01 17:03:12.475882 [DEBUG] apt_poller_task.c:269 () Process Signalled Descriptor [MRCPv2ConnectionAgent]
2020-10-01 17:03:12.475882 [INFO] mrcp_client_connection.c:623 () TCP/MRCPv2 Peer Disconnected 172.21.36.12:54622 <-> 172.21.36.150:1544
2020-10-01 17:03:12.475882 [WARNING] mrcp_client_connection.c:477 (ASR-1) Cancel MRCP Request <06a2ce4ce3784a9a@speechrecog> [2]
2020-10-01 17:03:12.475882 [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7fb5400015d0;2;3]
2020-10-01 17:03:12.475882 [DEBUG] apt_poller_task.c:251 () Wait for Messages [MRCPv2ConnectionAgent]
2020-10-01 17:03:12.475882 [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7fb5400015d0;2;3]
2020-10-01 17:03:12.475882 [INFO] mrcp_client_session.c:500 (ASR-1) Raise App MRCP Response ASR-1 <06a2ce4ce3784a9a>
b997fa2d-87c1-4a74-b08c-fb208c17d276 2020-10-01 17:03:12.475882 [DEBUG] mod_unimrcp.c:3675 (ASR-1) RECOGNIZE STOPPED
b997fa2d-87c1-4a74-b08c-fb208c17d276 2020-10-01 17:03:12.475882 [DEBUG] mod_unimrcp.c:1584 (ASR-1) PROCESSING ==> READY
2020-10-01 17:03:12.475882 [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client]
b997fa2d-87c1-4a74-b08c-fb208c17d276 2020-10-01 17:03:12.475882 [DEBUG] mod_unimrcp.c:1417 (ASR-1) RECOGNIZER stopped
b997fa2d-87c1-4a74-b08c-fb208c17d276 2020-10-01 17:03:12.495809 [DEBUG] switch_ivr_play_say.c:1488 Codec Activated L16@8000hz 1 channels 20ms
b997fa2d-87c1-4a74-b08c-fb208c17d276 2020-10-01 17:03:15.015878 [DEBUG] switch_core_media_bug.c:1295 Removing BUG from sofia/external/70255...@172.16.0.14
b997fa2d-87c1-4a74-b08c-fb208c17d276 2020-10-01 17:03:16.975822 [DEBUG] switch_ivr_play_say.c:1933 done playing file /usr/share/freeswitch/sounds/en/us/callie/etel/dnisvoice/9960939/intro.wav
b997fa2d-87c1-4a74-b08c-fb208c17d276 EXECUTE [depth=0] sofia/external/70255...@172.16.0.14 detect_speech(resume)
b997fa2d-87c1-4a74-b08c-fb208c17d276 2020-10-01 17:03:16.975822 [DEBUG] mod_unimrcp.c:2893 (ASR-1) (vendor-specific value) model: phone_call
b997fa2d-87c1-4a74-b08c-fb208c17d276 2020-10-01 17:03:16.975822 [DEBUG] mod_unimrcp.c:2897 (ASR-1) creating vendor specific pair array
b997fa2d-87c1-4a74-b08c-fb208c17d276 2020-10-01 17:03:16.975822 [DEBUG] mod_unimrcp.c:2893 (ASR-1) (vendor-specific value) use-enhanced: true
2020-10-01 17:03:16.975822 [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7fb4d4009a20;4;0]
2020-10-01 17:03:16.975822 [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7fb4d4009a20;4;0]
2020-10-01 17:03:16.975822 [INFO] mrcp_client_session.c:392 (ASR-1) Receive App MRCP Request ASR-1 <06a2ce4ce3784a9a>
2020-10-01 17:03:16.975822 [INFO] mrcp_client_session.c:622 (ASR-1) Send MRCP Request ASR-1 <06a2ce4ce3784a9a@speechrecog> [3]
2020-10-01 17:03:16.975822 [DEBUG] apt_task.c:265 () Signal Message to [MRCPv2ConnectionAgent] [0x7fb53c032ae0;1;0]
2020-10-01 17:03:16.975822 [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client]
2020-10-01 17:03:16.975822 [DEBUG] apt_poller_task.c:261 () Process Poller Wakeup [MRCPv2ConnectionAgent]
2020-10-01 17:03:16.975822 [DEBUG] apt_task.c:337 () Process Message [MRCPv2ConnectionAgent] [0x7fb53c032ae0;1;0]
2020-10-01 17:03:16.975822 [WARNING] mrcp_client_connection.c:518 (ASR-1) Null MRCPv2 Connection <06a2ce4ce3784a9a@speechrecog>
2020-10-01 17:03:16.975822 [WARNING] mrcp_client_connection.c:477 (ASR-1) Cancel MRCP Request <06a2ce4ce3784a9a@speechrecog> [3]
2020-10-01 17:03:16.975822 [DEBUG] apt_task.c:265 () Signal Message to [MRCP Client] [0x7fb540003990;2;3]
2020-10-01 17:03:16.975822 [DEBUG] apt_poller_task.c:251 () Wait for Messages [MRCPv2ConnectionAgent]
2020-10-01 17:03:16.975822 [DEBUG] apt_task.c:337 () Process Message [MRCP Client] [0x7fb540003990;2;3]
2020-10-01 17:03:16.975822 [INFO] mrcp_client_session.c:500 (ASR-1) Raise App MRCP Response ASR-1 <06a2ce4ce3784a9a>
b997fa2d-87c1-4a74-b08c-fb208c17d276 2020-10-01 17:03:16.975822 [DEBUG] mod_unimrcp.c:3655 (ASR-1) RECOGNIZE failed: status = 407
b997fa2d-87c1-4a74-b08c-fb208c17d276 2020-10-01 17:03:16.975822 [DEBUG] mod_unimrcp.c:1584 (ASR-1) READY ==> ERROR
2020-10-01 17:03:16.975822 [DEBUG] apt_consumer_task.c:141 () Wait for Messages [MRCP Client]

The unimrcp log portion is being created by combining the end of the log from the successful end of the TTS, and the beginning of the next log after restart:

2020-10-01 17:03:12:050231 [NOTICE] Speech Complete <58a2a080e573419a@polly>
2020-10-01 17:03:12:050279 [INFO]   Process SPEAK-COMPLETE Event <58a2a080e573419a@speechsynth> [1]
2020-10-01 17:03:12:050286 [NOTICE] State Transition SPEAKING -> IDLE <58a2a080e573419a@speechsynth>
2020-10-01 17:03:12:050315 [INFO]   Send MRCPv2 Data 172.21.36.150:1544 <-> 172.21.36.12:54620 [122 bytes]
MRCP/2.0 122 SPEAK-COMPLETE 1 COMPLETE
Channel-Identifier: 58a2a080e573419a@speechsynth
Completion-Cause: 000 normal


2020-10-01 17:03:12:078798 [INFO]   TCP/MRCPv2 Peer Disconnected 172.21.36.150:1544 <-> 172.21.36.12:54620
2020-10-01 17:03:12:078992 [INFO]   Receive SIP Event [nua_i_bye] Status 200 Session Terminated [SIP-Agent-1]
2020-10-01 17:03:12:078998 [INFO]   Receive SIP Event [nua_i_state] Status 200 Session Terminated [SIP-Agent-1]
2020-10-01 17:03:12:079010 [NOTICE] SIP Call State 0x7ff010001a68 [terminated]
2020-10-01 17:03:12:079016 [INFO]   Receive SIP Event [nua_i_terminated] Status 200 Session Terminated [SIP-Agent-1]
2020-10-01 17:03:12:079036 [INFO]   Deactivate Session 0x7ff010001a68 <58a2a080e573419a>
2020-10-01 17:03:12:079043 [INFO]   Terminate Session 0x7ff010001a68 <58a2a080e573419a>
2020-10-01 17:03:12:079079 [INFO]   Close <58a2a080e573419a@polly>
2020-10-01 17:03:12:079084 [INFO]   Remove Control Channel <58a2a080e573419a@speechsynth> [0]
2020-10-01 17:03:12:079086 [NOTICE] Polly Usage: 0/1/4
2020-10-01 17:03:12:080225 [INFO]   Close RTP Transmitter 172.21.36.150:5000 -> 172.21.28.12:14000 [s:70 o:22400]
2020-10-01 17:03:12:080232 [INFO]   Remove RTP Session 172.21.36.150:5000
2020-10-01 17:03:12:080264 [NOTICE] Destroy TCP/MRCPv2 Connection 172.21.36.150:1544 <-> 172.21.36.12:54620
2020-10-01 17:03:12:080284 [NOTICE] Remove Session <58a2a080e573419a>
2020-10-01 17:03:12:080286 [INFO]   Session Terminated 0x7ff010001a68 <58a2a080e573419a>
2020-10-01 17:03:12:080296 [NOTICE] Destroy Session <58a2a080e573419a>
2020-10-01 17:03:12:109450 [INFO]   Receive SIP Event [nua_i_invite] Status 100 Trying [SIP-Agent-1]
2020-10-01 17:03:12:109458 [INFO]   Receive SIP Event [nua_i_state] Status 100 Trying [SIP-Agent-1]
2020-10-01 17:03:12:109461 [NOTICE] SIP Call State  [received]
2020-10-01 17:03:12:109466 [INFO]   Create Session 0x7ff010001a68 <new> [flspeechdetection1]
2020-10-01 17:03:12:109468 [INFO]   Remote SDP 0x7ff010001a68 <new>
v=0
o=FreeSWITCH 62819260113102936 2483964911160478401 IN IP4 172.21.28.12
s=-
c=IN IP4 172.21.28.12
t=0 0
m=application 9 TCP/MRCPv2 1
a=setup:active
a=connection:new
a=resource:speechrecog
a=cmid:1
m=audio 14002 RTP/AVP 96
a=rtpmap:96 L16/8000
a=sendonly
a=mid:1

2020-10-01 17:03:12:109527 [NOTICE] Add Session <06a2ce4ce3784a9a>
2020-10-01 17:03:12:109533 [INFO]   Receive Offer 0x7ff010001a68 <06a2ce4ce3784a9a> [c:1 a:1 v:0]
2020-10-01 17:03:12:109536 [INFO]   Found MRCP Engine [GSR-1] for Resource [speechrecog] 0x7ff010001a68 <06a2ce4ce3784a9a>
2020-10-01 17:03:12:109567 [INFO]   Add Pending Control Channel <06a2ce4ce3784a9a@speechrecog> [1]
2020-10-01 17:03:12:110235 [INFO]   Enable RTP Session 172.21.36.150:5002
2020-10-01 17:03:12:110246 [INFO]   Open RTP Receiver 172.21.36.150:5002 <- 172.21.28.12:14002 playout [50 ms] bounds [0 - 600 ms] adaptive [1] skew detection [1]
2020-10-01 17:03:12:110249 [INFO]   Media Path 0x7ff010001a68 Source->[L16/8000/1]->Decoder->[LPCM/8000/1]->Bridge->[LPCM/8000/1]->Sink
2020-10-01 17:03:12:110327 [INFO]   Open <06a2ce4ce3784a9a@gsr>
2020-10-01 17:03:12:110396 [NOTICE] GSR Usage: 1/1/14
2020-10-01 17:03:12:140453 [INFO]   Send Answer 0x7ff010001a68 <06a2ce4ce3784a9a> [c:1 a:1 v:0] Status OK
2020-10-01 17:03:12:140473 [INFO]   Local SDP 0x7ff010001a68 <06a2ce4ce3784a9a>
v=0
o=UniMRCPServer 0 0 IN IP4 172.21.36.150
s=-
c=IN IP4 172.21.36.150
t=0 0
m=application 1544 TCP/MRCPv2 1
a=setup:passive
a=connection:new
a=channel:06a2ce4ce3784a9a@speechrecog
a=cmid:1
m=audio 5002 RTP/AVP 96
a=rtpmap:96 L16/8000
a=recvonly
a=mid:1

2020-10-01 17:03:12:140762 [INFO]   Receive SIP Event [nua_i_state] Status 200 OK [SIP-Agent-1]
2020-10-01 17:03:12:140769 [NOTICE] SIP Call State 0x7ff010001a68 [completed]
2020-10-01 17:03:12:141284 [INFO]   Receive SIP Event [nua_i_ack] Status 200 OK [SIP-Agent-1]
2020-10-01 17:03:12:141309 [INFO]   Receive SIP Event [nua_i_state] Status 200 OK [SIP-Agent-1]
2020-10-01 17:03:12:141313 [NOTICE] SIP Call State 0x7ff010001a68 [ready]
2020-10-01 17:03:12:141315 [INFO]   Receive SIP Event [nua_i_active] Status 200 Call active [SIP-Agent-1]
2020-10-01 17:03:12:141598 [NOTICE] Accepted TCP/MRCPv2 Connection 172.21.36.150:1544 <-> 172.21.36.12:54622
2020-10-01 17:03:12:150942 [INFO]   Receive MRCPv2 Data 172.21.36.150:1544 <-> 172.21.36.12:54622 [240 bytes]
MRCP/2.0 240 RECOGNIZE 1
Channel-Identifier: 06a2ce4ce3784a9a@speechrecog
Content-Type: text/uri-list
Cancel-If-Queue: false
Vendor-Specific-Parameters: model=phone_call;use-enhanced=true
Content-Length: 25

builtin:speech/transcribe
2020-10-01 17:03:12:150955 [INFO]   Assign Control Channel <06a2ce4ce3784a9a@speechrecog> to Connection 172.21.36.150:1544 <-> 172.21.36.12:54622 [0] -> [1]
2020-10-01 17:03:12:150981 [INFO]   Process RECOGNIZE Request <06a2ce4ce3784a9a@speechrecog> [1]
2020-10-01 17:03:12:151038 [INFO]   Init Speech Detector: frame-size=160, max-frame-count=330, output-frame-count=20, vad-mode=2, noinput-timeout=5000 ms, input-timeout=15000 ms, start-timeout=50 ms, complete-timeout=1000 ms, incomplete-timeout=3000 ms, leading-silence=100 ms, trailing-silence=300 ms, interim-results=1, start-of-input=external <06a2ce4ce3784a9a>
2020-10-01 17:03:12:151051 [INFO]   Start No-Input Timer [5000 ms] <06a2ce4ce3784a9a>
2020-10-01 17:03:12:151055 [INFO]   Open Waveform File for Writing /opt/unimrcp/var/utterances/umsgsr-06a2ce4ce3784a9a-1.wav, sampling-rate [8000]
2020-10-01 17:03:12:151098 [INFO]   Create gRPC Stream <06a2ce4ce3784a9a@gsr>
2020-10-01 17:03:12:151238 [INFO]   Process RECOGNIZE Response <06a2ce4ce3784a9a@speechrecog> [1]
2020-10-01 17:03:12:151255 [INFO]   State Transition IDLE -> RECOGNIZING <06a2ce4ce3784a9a@speechrecog>
2020-10-01 17:03:12:151284 [INFO]   Send MRCPv2 Data 172.21.36.150:1544 <-> 172.21.36.12:54622 [83 bytes]
MRCP/2.0 83 1 200 IN-PROGRESS
Channel-Identifier: 06a2ce4ce3784a9a@speechrecog


2020-10-01 17:03:12:151791 [INFO]   Receive MRCPv2 Data 172.21.36.150:1544 <-> 172.21.36.12:54622 [72 bytes]
MRCP/2.0 72 STOP 2
Channel-Identifier: 06a2ce4ce3784a9a@speechrecog


2020-10-01 17:03:12:151827 [INFO]   Process STOP Request <06a2ce4ce3784a9a@speechrecog> [2]
2020-10-01 17:03:12:160251 [INFO]   Input Complete [stopped] size=0 bytes, dur=0 ms <06a2ce4ce3784a9a@gsr>

------------------------------first log cuts off here-----------------------------------------------------

2020-10-01 17:03:12:855259 [NOTICE] Run as Daemon
2020-10-01 17:03:12:855276 [NOTICE] UniMRCP Server [1.7.0]
2020-10-01 17:03:12:855279 [INFO]   APR [1.5.2]
2020-10-01 17:03:12:855283 [NOTICE] Create MRCP Server
2020-10-01 17:03:12:855297 [NOTICE] Open Config File [/opt/unimrcp/conf/unimrcpserver.xml]
2020-10-01 17:03:12:855693 [INFO]   Set Property ip:172.21.36.150
2020-10-01 17:03:12:855698 [INFO]   Set Property ip:172.21.36.150
2020-10-01 17:03:12:855702 [INFO]   Register Codec [PCMU]
2020-10-01 17:03:12:855704 [INFO]   Register Codec [PCMA]
2020-10-01 17:03:12:855706 [INFO]   Register Codec [L16]
2020-10-01 17:03:12:855712 [NOTICE] Register Resource [speechsynth]
2020-10-01 17:03:12:855716 [NOTICE] Register Resource [speechrecog]
2020-10-01 17:03:12:855718 [NOTICE] Register Resource [recorder]
2020-10-01 17:03:12:855720 [INFO]   Register Resource Factory
2020-10-01 17:03:12:855726 [NOTICE] Create SofiaSIP Agent [SIP-Agent-1] [1.12.11-234-gd74df2e] sip:172.21.36.150:8060;transport=udp,tcp
2020-10-01 17:03:12:855729 [INFO]   Register Signaling Agent [SIP-Agent-1]
2020-10-01 17:03:12:855735 [NOTICE] Create RTSP Server [RTSP-Agent-1] 172.21.36.150:1554 [100] connection timeout [600 sec]
2020-10-01 17:03:12:855765 [INFO]   Register Signaling Agent [RTSP-Agent-1]
2020-10-01 17:03:12:855770 [NOTICE] Create MRCPv2 Agent [MRCPv2-Agent-1] 172.21.36.150:1544 [100]
2020-10-01 17:03:12:855782 [INFO]   Register Connection Agent [MRCPv2-Agent-1]
2020-10-01 17:03:12:855785 [NOTICE] Create Media Engine [Media-Engine-1]
2020-10-01 17:03:12:855788 [INFO]   Register Media Engine [Media-Engine-1]
2020-10-01 17:03:12:855791 [NOTICE] Create RTP Termination Factory 172.21.36.150:[5000,6000]
2020-10-01 17:03:12:855794 [INFO]   Register RTP Termination Factory [RTP-Factory-1]
2020-10-01 17:03:12:855797 [INFO]   Load Plugin [Recorder-1] [/opt/unimrcp/plugin/mrcprecorder.so]
2020-10-01 17:03:12:855847 [INFO]   Register MRCP Engine [Recorder-1]
2020-10-01 17:03:12:855851 [INFO]   Load Plugin [GSR-1] [/opt/unimrcp/plugin/umsgsr.so]
2020-10-01 17:03:12:868191 [NOTICE] GSR Plugin Version [1.14.0] Date [2019-05-09]
2020-10-01 17:03:12:869491 [INFO]   Register MRCP Engine [GSR-1]
2020-10-01 17:03:12:869498 [INFO]   Load Plugin [Polly-1] [/opt/unimrcp/plugin/umspolly.so]
2020-10-01 17:03:12:880089 [NOTICE] POLLY Plugin Version [1.6.0] Date [2020-07-01]
2020-10-01 17:03:12:880231 [INFO]   Register MRCP Engine [Polly-1]
2020-10-01 17:03:12:880241 [INFO]   Register RTP Settings [RTP-Settings-1]
2020-10-01 17:03:12:880248 [WARN]   No Such Codec [telephoneevent]
2020-10-01 17:03:12:880250 [INFO]   Register RTP Settings [RTP-Settings-2]
. . . profiles created
2020-10-01 17:03:12:880377 [NOTICE] Create MRCPv2 Profile [betaspeechdetection1]
2020-10-01 17:03:12:880380 [INFO]   Associate Resource [speechsynth] to Engine [Polly-1] in Profile [betaspeechdetection1]
2020-10-01 17:03:12:880382 [INFO]   Associate Resource [speechrecog] to Engine [GSR-1] in Profile [betaspeechdetection1]
2020-10-01 17:03:12:880384 [INFO]   Associate Resource [recorder] to Engine [Recorder-1] in Profile [betaspeechdetection1]
2020-10-01 17:03:12:880386 [INFO]   Register Profile [betaspeechdetection1]
. . . certs and licenses load successfully

2020-10-01 17:03:12:915751 [INFO]   Start Task [Task]
2020-10-01 17:03:12:915769 [INFO]   Create Utterance Manager
2020-10-01 17:03:12:915839 [NOTICE] Populate files from /opt/unimrcp/var/utterances/ pattern [umsgsr-*.wav] max-count [0] max-age [0 min] purge-existing [0]
2020-10-01 17:03:12:916759 [INFO]   Create RDR Manager
2020-10-01 17:03:12:916777 [NOTICE] Populate files from /opt/unimrcp/var/rdrs/ pattern [umsgsr-*.json] max-count [0] max-age [0 min] purge-existing [0]
2020-10-01 17:03:12:917675 [NOTICE] GSR Usage: 0/0/0
2020-10-01 17:03:12:917722 [INFO]   Set Usage Refresh Timer [10 sec]
2020-10-01 17:03:13:169661 [INFO]   Add Voice name [Lotte] gender [Female] language [nl-NL] engine [standard]
2020-10-01 17:03:13:169670 [INFO]   Add Voice name [Maxim] gender [Male] language [ru-RU] engine [standard]
2020-10-01 17:03:13:169673 [INFO]   Add Voice name [Salli] gender [Female] language [en-US] engine [neural standard]
2020-10-01 17:03:13:169675 [INFO]   Add Voice name [Geraint] gender [Male] language [en-GB-WLS] engine [standard]
2020-10-01 17:03:13:169677 [INFO]   Add Voice name [Miguel] gender [Male] language [es-US] engine [standard]
2020-10-01 17:03:13:169679 [INFO]   Add Voice name [Marlene] gender [Female] language [de-DE] engine [standard]
2020-10-01 17:03:13:169685 [INFO]   Add Voice name [Giorgio] gender [Male] language [it-IT] engine [standard]
2020-10-01 17:03:13:169687 [INFO]   Add Voice name [Inês] gender [Female] language [pt-PT] engine [standard]
2020-10-01 17:03:13:169689 [INFO]   Add Voice name [Zeina] gender [Female] language [arb] engine [standard]
2020-10-01 17:03:13:169691 [INFO]   Add Voice name [Zhiyu] gender [Female] language [cmn-CN] engine [standard]
2020-10-01 17:03:13:169693 [INFO]   Add Voice name [Gwyneth] gender [Female] language [cy-GB] engine [standard]
2020-10-01 17:03:13:169695 [INFO]   Add Voice name [Karl] gender [Male] language [is-IS] engine [standard]
2020-10-01 17:03:13:169697 [INFO]   Add Voice name [Joanna] gender [Female] language [en-US] engine [neural standard]
2020-10-01 17:03:13:169699 [INFO]   Add Voice name [Lucia] gender [Female] language [es-ES] engine [standard]
2020-10-01 17:03:13:169701 [INFO]   Add Voice name [Cristiano] gender [Male] language [pt-PT] engine [standard]
2020-10-01 17:03:13:169703 [INFO]   Add Voice name [Astrid] gender [Female] language [sv-SE] engine [standard]
2020-10-01 17:03:13:169705 [INFO]   Add Voice name [Vicki] gender [Female] language [de-DE] engine [standard]
2020-10-01 17:03:13:169707 [INFO]   Add Voice name [Mia] gender [Female] language [es-MX] engine [standard]
2020-10-01 17:03:13:169709 [INFO]   Add Voice name [Bianca] gender [Female] language [it-IT] engine [standard]
2020-10-01 17:03:13:169711 [INFO]   Add Voice name [Vitória] gender [Female] language [pt-BR] engine [standard]
2020-10-01 17:03:13:169713 [INFO]   Add Voice name [Raveena] gender [Female] language [en-IN] engine [standard]
2020-10-01 17:03:13:169715 [INFO]   Add Voice name [Chantal] gender [Female] language [fr-CA] engine [standard]
2020-10-01 17:03:13:169717 [INFO]   Add Voice name [Amy] gender [Female] language [en-GB] engine [neural standard]
2020-10-01 17:03:13:169719 [INFO]   Add Voice name [Brian] gender [Male] language [en-GB] engine [neural standard]
2020-10-01 17:03:13:169721 [INFO]   Add Voice name [Kevin] gender [Male] language [en-US] engine [neural]
2020-10-01 17:03:13:169723 [INFO]   Add Voice name [Russell] gender [Male] language [en-AU] engine [standard]
2020-10-01 17:03:13:169725 [INFO]   Add Voice name [Aditi] gender [Female] language [en-IN] engine [standard]
2020-10-01 17:03:13:169727 [INFO]   Add Voice name [Matthew] gender [Male] language [en-US] engine [neural standard]
2020-10-01 17:03:13:169729 [INFO]   Add Voice name [Dóra] gender [Female] language [is-IS] engine [standard]
2020-10-01 17:03:13:169731 [INFO]   Add Voice name [Enrique] gender [Male] language [es-ES] engine [standard]
2020-10-01 17:03:13:169733 [INFO]   Add Voice name [Hans] gender [Male] language [de-DE] engine [standard]
2020-10-01 17:03:13:169735 [INFO]   Add Voice name [Carmen] gender [Female] language [ro-RO] engine [standard]
2020-10-01 17:03:13:169737 [INFO]   Add Voice name [Ivy] gender [Female] language [en-US] engine [neural standard]
2020-10-01 17:03:13:169739 [INFO]   Add Voice name [Ewa] gender [Female] language [pl-PL] engine [standard]
2020-10-01 17:03:13:169741 [INFO]   Add Voice name [Maja] gender [Female] language [pl-PL] engine [standard]
2020-10-01 17:03:13:169743 [INFO]   Add Voice name [Nicole] gender [Female] language [en-AU] engine [standard]
2020-10-01 17:03:13:169745 [INFO]   Add Voice name [Camila] gender [Female] language [pt-BR] engine [neural standard]
2020-10-01 17:03:13:169747 [INFO]   Add Voice name [Filiz] gender [Female] language [tr-TR] engine [standard]
2020-10-01 17:03:13:169749 [INFO]   Add Voice name [Jacek] gender [Male] language [pl-PL] engine [standard]
2020-10-01 17:03:13:169751 [INFO]   Add Voice name [Justin] gender [Male] language [en-US] engine [neural standard]
2020-10-01 17:03:13:169753 [INFO]   Add Voice name [Céline] gender [Female] language [fr-FR] engine [standard]
2020-10-01 17:03:13:169754 [INFO]   Add Voice name [Kendra] gender [Female] language [en-US] engine [neural standard]
2020-10-01 17:03:13:169756 [INFO]   Add Voice name [Ricardo] gender [Male] language [pt-BR] engine [standard]
2020-10-01 17:03:13:169760 [INFO]   Add Voice name [Mads] gender [Male] language [da-DK] engine [standard]
2020-10-01 17:03:13:169763 [INFO]   Add Voice name [Mathieu] gender [Male] language [fr-FR] engine [standard]
2020-10-01 17:03:13:169765 [INFO]   Add Voice name [Léa] gender [Female] language [fr-FR] engine [standard]
2020-10-01 17:03:13:169767 [INFO]   Add Voice name [Naja] gender [Female] language [da-DK] engine [standard]
2020-10-01 17:03:13:169768 [INFO]   Add Voice name [Penélope] gender [Female] language [es-US] engine [standard]
2020-10-01 17:03:13:169770 [INFO]   Add Voice name [Tatyana] gender [Female] language [ru-RU] engine [standard]
2020-10-01 17:03:13:169772 [INFO]   Add Voice name [Ruben] gender [Male] language [nl-NL] engine [standard]
2020-10-01 17:03:13:169774 [INFO]   Add Voice name [Mizuki] gender [Female] language [ja-JP] engine [standard]
2020-10-01 17:03:13:169776 [INFO]   Add Voice name [Takumi] gender [Male] language [ja-JP] engine [standard]
2020-10-01 17:03:13:169778 [INFO]   Add Voice name [Conchita] gender [Female] language [es-ES] engine [standard]
2020-10-01 17:03:13:169780 [INFO]   Add Voice name [Carla] gender [Female] language [it-IT] engine [standard]
2020-10-01 17:03:13:169782 [INFO]   Add Voice name [Kimberly] gender [Female] language [en-US] engine [neural standard]
2020-10-01 17:03:13:169784 [INFO]   Add Voice name [Jan] gender [Male] language [pl-PL] engine [standard]
2020-10-01 17:03:13:169786 [INFO]   Add Voice name [Liv] gender [Female] language [nb-NO] engine [standard]
2020-10-01 17:03:13:169788 [INFO]   Add Voice name [Joey] gender [Male] language [en-US] engine [neural standard]
2020-10-01 17:03:13:169791 [INFO]   Add Voice name [Lupe] gender [Female] language [es-US] engine [neural standard]
2020-10-01 17:03:13:169793 [INFO]   Add Voice name [Seoyeon] gender [Female] language [ko-KR] engine [standard]
2020-10-01 17:03:13:169795 [INFO]   Add Voice name [Emma] gender [Female] language [en-GB] engine [neural standard]
2020-10-01 17:03:13:169800 [INFO]   Create Waveform Manager
2020-10-01 17:03:13:169822 [NOTICE] Populate files from /opt/unimrcp/var/ pattern [umspolly-*.wav] max-count [100] max-age [60 min] purge-existing [0]
2020-10-01 17:03:13:169922 [INFO]   Create SDR Manager
2020-10-01 17:03:13:169953 [NOTICE] Populate files from /opt/unimrcp/var/ pattern [umspolly-*.json] max-count [100] max-age [60 min] purge-existing [0]
2020-10-01 17:03:13:170017 [NOTICE] Polly Usage: 0/0/0
2020-10-01 17:03:13:170042 [NOTICE] MRCP Server Started
2020-10-01 17:03:13:315431 [NOTICE] UniMRCP Polly License:

-store id:        redacted
-product name:    umspolly
-product version: 1.0.0
-license type:    trial
-exp date:        2020-11-03
-channel count:   4
-feature set:     0

2020-10-01 17:03:13:315438 [NOTICE] Polly Usage: 0/0/4
2020-10-01 17:03:13:316391 [NOTICE] UniMRCP GSR License:

-store id:        redacted
-product name:    umsgsr
-product version: 1.0.0
-license type:    production
-channel count:   14
-feature set:     0

2020-10-01 17:03:13:316396 [NOTICE] GSR Usage: 0/0/14

. . . new call after the first one timed out when unimrcp went away

2020-10-01 17:03:45:239498 [INFO]   Receive SIP Event [nua_i_invite] Status 100 Trying [SIP-Agent-1]
2020-10-01 17:03:45:239519 [INFO]   Receive SIP Event [nua_i_state] Status 100 Trying [SIP-Agent-1]
2020-10-01 17:03:45:239524 [NOTICE] SIP Call State  [received]
2020-10-01 17:03:45:239532 [INFO]   Create Session 0x7f9b68001a68 <new> [etel_primary]
2020-10-01 17:03:45:239537 [INFO]   Remote SDP 0x7f9b68001a68 <new>
v=0
o=FreeSWITCH 6596304207945579727 4884868027883013020 IN IP4 172.21.28.12
s=-
c=IN IP4 172.21.28.12
t=0 0
m=application 9 TCP/MRCPv2 1
a=setup:active
a=connection:new
a=resource:speechsynth
a=cmid:1
m=audio 14004 RTP/AVP 96
a=rtpmap:96 L16/8000
a=recvonly
a=mid:1

2020-10-01 17:03:45:239618 [NOTICE] Add Session <a966f12a56c04825>
2020-10-01 17:03:45:239628 [INFO]   Receive Offer 0x7f9b68001a68 <a966f12a56c04825> [c:1 a:1 v:0]
2020-10-01 17:03:45:239633 [INFO]   Found MRCP Engine [Polly-1] for Resource [speechsynth] 0x7f9b68001a68 <a966f12a56c04825>
2020-10-01 17:03:45:239691 [INFO]   Add Pending Control Channel <a966f12a56c04825@speechsynth> [1]
2020-10-01 17:03:45:242066 [INFO]   Enable RTP Session 172.21.36.150:5000
2020-10-01 17:03:45:242075 [INFO]   Open RTP Transmitter 172.21.36.150:5000 -> 172.21.28.12:14004
2020-10-01 17:03:45:242078 [INFO]   Media Path 0x7f9b68001a68 Source->[LPCM/8000/1]->Bridge->[LPCM/8000/1]->Encoder->[L16/8000/1]->Sink
2020-10-01 17:03:45:242144 [INFO]   Open <a966f12a56c04825@polly>
2020-10-01 17:03:45:242162 [NOTICE] Polly Usage: 1/1/4
2020-10-01 17:03:45:242188 [INFO]   Send Answer 0x7f9b68001a68 <a966f12a56c04825> [c:1 a:1 v:0] Status OK
2020-10-01 17:03:45:242210 [INFO]   Local SDP 0x7f9b68001a68 <a966f12a56c04825>
v=0
o=UniMRCPServer 0 0 IN IP4 172.21.36.150
s=-
c=IN IP4 172.21.36.150
t=0 0
m=application 1544 TCP/MRCPv2 1
a=setup:passive
a=connection:new
a=channel:a966f12a56c04825@speechsynth
a=cmid:1
m=audio 5000 RTP/AVP 96
a=rtpmap:96 L16/8000
a=sendonly
a=mid:1

2020-10-01 17:03:45:242552 [INFO]   Receive SIP Event [nua_i_state] Status 200 OK [SIP-Agent-1]
2020-10-01 17:03:45:242568 [NOTICE] SIP Call State 0x7f9b68001a68 [completed]
2020-10-01 17:03:45:242832 [INFO]   Receive SIP Event [nua_i_ack] Status 200 OK [SIP-Agent-1]
2020-10-01 17:03:45:242839 [INFO]   Receive SIP Event [nua_i_state] Status 200 OK [SIP-Agent-1]
2020-10-01 17:03:45:242851 [NOTICE] SIP Call State 0x7f9b68001a68 [ready]
2020-10-01 17:03:45:242853 [INFO]   Receive SIP Event [nua_i_active] Status 200 Call active [SIP-Agent-1]
2020-10-01 17:03:45:243049 [NOTICE] Accepted TCP/MRCPv2 Connection 172.21.36.150:1544 <-> 172.21.36.12:54636
2020-10-01 17:03:45:256539 [INFO]   TCP/MRCPv2 Peer Disconnected 172.21.36.150:1544 <-> 172.21.36.12:54636
2020-10-01 17:03:45:256554 [NOTICE] Destroy TCP/MRCPv2 Connection 172.21.36.150:1544 <-> 172.21.36.12:54636
2020-10-01 17:04:13:408387 [NOTICE] Polly Usage: 1/1/4

At this point the freeswitch instance dies

Any thoughts that anyone has would be appreciated, we've enjoyed using GSR through unimrcp for almost two years now, but are running into a wall trying to add TTS.

Arsen Chaloyan

unread,
Oct 13, 2020, 10:51:26 PM10/13/20
to UniMRCP
To start off, it is not uncommon to use GSR or GDF with AWS Polly. We also tried to set up the exact same environment using a license server as you do, everything seems to work as intended.

Next, I checked the exact versions of the software components you have installed, and this raised a red flag to me.
  • UniMRCP Server [1.7.0]
  • GSR Plugin Version [1.14.0] Date [2019-05-09]
  • POLLY Plugin Version [1.6.0] Date [2020-07-01]
    Please note that GSR 1.14.0 was built against UniMRCP server 1.6.0. You may easily run into binary incompatibility problems trying to use GSR 1.14.0 with UniMRCP server 1.7.0. If you use yum or apt, then these tools should take good care of dependencies and prompt you to install appropriate versions.


    --
    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/2e3abd94-8fd4-4bad-8b0b-2d00f169f98bo%40googlegroups.com.


    --
    Arsen Chaloyan
    Author of UniMRCP
    http://www.unimrcp.org

    Sean DiSanti

    unread,
    Nov 2, 2020, 7:10:02 PM11/2/20
    to uni...@googlegroups.com
    We actually use 1.6.0 in production, and that box had been upgraded based on dependencies for the most recent polly plugin at the time. I reverted to 1.6.0 on the box, and went back through polly releases for one that was built against that version, and added it (1.5.1) to our local repo and installed it according to the manual. Now when I start unimrcpserver though, there are no warnings or complaints, it just crashes after selecting the credentials file:

    2020-11-02 16:01:58:827272 [NOTICE] Run as Daemon
    2020-11-02 16:01:58:827287 [NOTICE] UniMRCP Server [1.6.0]
    2020-11-02 16:01:58:827290 [INFO]   APR [1.5.2]
    2020-11-02 16:01:58:827293 [NOTICE] Create MRCP Server
    2020-11-02 16:01:58:827302 [NOTICE] Open Config File [/opt/unimrcp/conf/unimrcpserver.xml]
    2020-11-02 16:01:58:827618 [INFO]   Set Property ip:172.21.36.150
    2020-11-02 16:01:58:827622 [INFO]   Set Property ip:172.21.36.150
    2020-11-02 16:01:58:827626 [INFO]   Register Codec [PCMU]
    2020-11-02 16:01:58:827628 [INFO]   Register Codec [PCMA]
    2020-11-02 16:01:58:827629 [INFO]   Register Codec [L16]
    2020-11-02 16:01:58:827634 [NOTICE] Register Resource [speechsynth]
    2020-11-02 16:01:58:827636 [NOTICE] Register Resource [speechrecog]
    2020-11-02 16:01:58:827638 [INFO]   Register Resource Factory
    2020-11-02 16:01:58:827643 [NOTICE] Create SofiaSIP Agent [SIP-Agent-1] [1.12.11-234-gd74df2e] sip:172.21.36.150:8060;transport=udp,tcp
    2020-11-02 16:01:58:827645 [INFO]   Register Signaling Agent [SIP-Agent-1]
    2020-11-02 16:01:58:827649 [NOTICE] Create RTSP Server [RTSP-Agent-1] 172.21.36.150:1554 [100] connection timeout [600 sec]
    2020-11-02 16:01:58:827672 [INFO]   Register Signaling Agent [RTSP-Agent-1]
    2020-11-02 16:01:58:827676 [NOTICE] Create MRCPv2 Agent [MRCPv2-Agent-1] 172.21.36.150:1544 [100]
    2020-11-02 16:01:58:827685 [INFO]   Register Connection Agent [MRCPv2-Agent-1]
    2020-11-02 16:01:58:827688 [NOTICE] Create Media Engine [Media-Engine-1]
    2020-11-02 16:01:58:827690 [INFO]   Register Media Engine [Media-Engine-1]
    2020-11-02 16:01:58:827692 [NOTICE] Create RTP Termination Factory 172.21.36.150:[5000,6000]
    2020-11-02 16:01:58:827693 [INFO]   Register RTP Termination Factory [RTP-Factory-1]
    2020-11-02 16:01:58:827696 [INFO]   Load Plugin [GSR-1] [/opt/unimrcp/plugin/umsgsr.so]
    2020-11-02 16:01:58:834414 [NOTICE] GSR Plugin Version [1.14.0] Date [2019-05-09]
    2020-11-02 16:01:58:835378 [INFO]   Register MRCP Engine [GSR-1]
    2020-11-02 16:01:58:835384 [INFO]   Load Plugin [Polly-1] [/opt/unimrcp/plugin/umspolly.so]
    2020-11-02 16:01:58:842037 [NOTICE] POLLY Plugin Version [1.1.0] Date [2018-09-15]
    2020-11-02 16:01:58:842127 [INFO]   Register MRCP Engine [Polly-1]
    2020-11-02 16:01:58:842135 [INFO]   Register RTP Settings [RTP-Settings-1]
    2020-11-02 16:01:58:842142 [INFO]   Register RTP Settings [RTP-Settings-2]
    2020-11-02 16:01:58:842220 [NOTICE] Create MRCPv2 Profile [betaspeechdetection1]
    2020-11-02 16:01:58:842222 [INFO]   Assign MRCP Engine [speechsynth] [Polly-1]
    2020-11-02 16:01:58:842223 [INFO]   Assign MRCP Engine [speechrecog] [GSR-1]
    2020-11-02 16:01:58:842224 [INFO]   Register Profile [betaspeechdetection1]
    2020-11-02 16:01:58:842227 [NOTICE] Create MRCPv2 Profile [betaspeechdetection1_tts]
    2020-11-02 16:01:58:842230 [INFO]   Assign MRCP Engine [speechsynth] [Polly-1]
    2020-11-02 16:01:58:842231 [INFO]   Assign MRCP Engine [speechrecog] [GSR-1]
    2020-11-02 16:01:58:842233 [INFO]   Register Profile [betaspeechdetection1_tts]
    2020-11-02 16:01:58:842256 [INFO]   Start Task [MRCP Server]
    2020-11-02 16:01:58:842324 [INFO]   Open Engine [GSR-1]
    2020-11-02 16:01:58:842335 [NOTICE] Open Config File [/opt/unimrcp/conf/umsgsr.xml]
    2020-11-02 16:01:58:842567 [NOTICE] Determined License Certificate File /opt/unimrcp/data/unilic_client.cer
    2020-11-02 16:01:58:842620 [NOTICE] Determined Credentials File /opt/unimrcp/data/TwilioClone-a072568c20af.json
    2020-11-02 16:01:58:842757 [INFO]   Open Engine [Polly-1]
    2020-11-02 16:01:58:842761 [NOTICE] Open Config File [/opt/unimrcp/conf/umspolly.xml]
    2020-11-02 16:01:58:842765 [NOTICE] GSR Usage: 0/0/0
    2020-11-02 16:01:58:842869 [NOTICE] Determined License Certificate File /opt/unimrcp/data/synthesis/unilic_client_redacted.crt
    2020-11-02 16:01:58:842902 [NOTICE] Init AWS API
    2020-11-02 16:01:58:842906 [NOTICE] Polly Usage: 0/0/0
    2020-11-02 16:01:58:842923 [INFO]   Retreive UniMRCP Polly License from 35.192.62.90
    2020-11-02 16:01:58:842952 [NOTICE] Read AWS Credentials /opt/unimrcp/data/synthesis/aws.credentials
    2020-11-02 16:01:58:842996 [INFO]   Create Polly Client: thread pool [1] region []

    It tries to start 5 times with the same output and then gives up. I've reverted the configs to remove polly, and then the server runs fine and GSR works, but obviously not Polly.


    Arsen Chaloyan

    unread,
    Nov 3, 2020, 7:58:46 PM11/3/20
    to UniMRCP
    Sorry, but the right approach in the long run would be to stick with the latest or at least more recent versions of the plugins based on the 1.7.0 version. There are very minor changes introduced in 1.7.0, which may require no changes in your current configuration files and very minor changes in the infrastructure. I understand, though, that such an upgrade may formally require a full revalidation.

    Reply all
    Reply to author
    Forward
    0 new messages