Closed dcropp closed 6 years ago
Dan,
Thanks for bringing this up. The following commit should fix the problem 87bff90fb1ba1c376a4d42b92518000833b338b4.
Please give it a try.
Hi Arsen,
I finally had a chance to try this. I am still not seeing any notification of the RECOG_COMPLETION_CAUSE being set with this patch. I retrieve the latest from the git repository.
[06/14 09:44:03.393] DEBUG[890] threadpool.c: Worker thread idle timeout reached. Dying.
[06/14 09:44:03.393] DEBUG[886] threadpool.c: Destroying worker thread 1
[06/14 09:44:06.098] DEBUG[959] manager.c: Running action 'AGI'
[06/14 09:44:06.107] DEBUG[959] manager.c: Examining AMI event:
Event: AGIExecStart
Privilege: agi,all
Channel: PJSIP/1004-00000000
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1004
CallerIDName: 1004
ConnectedLineNum:
[06/14 09:44:06.107] DEBUG[1176][C-00000000] app_mrcprecog.c: Apply option p: 1
[06/14 09:44:06.107] DEBUG[1176][C-00000000] app_mrcprecog.c: Apply option gd: ^
[06/14 09:44:06.107] DEBUG[1176][C-00000000] app_mrcprecog.c: Apply option f: /var/lib/asterisk/sounds/sox/IS/3319a8f37ab15b57e6d6ddf38d7d7164
[06/14 09:44:06.107] DEBUG[1176][C-00000000] app_mrcprecog.c: Apply option b: 1
[06/14 09:44:06.107] DEBUG[1176][C-00000000] app_mrcprecog.c: Apply option sw: false
[06/14 09:44:06.107] DEBUG[1176][C-00000000] app_mrcprecog.c: Apply option nac: false
[06/14 09:44:06.107] DEBUG[1176][C-00000000] app_mrcprecog.c: Apply option cdb: true
[06/14 09:44:06.107] DEBUG[1176][C-00000000] app_mrcprecog.c: Apply option enm: false
[06/14 09:44:06.107] DEBUG[1176][C-00000000] app_mrcprecog.c: Apply option epe: 0
[06/14 09:44:06.107] DEBUG[1176][C-00000000] app_mrcprecog.c: Apply option uer: 0
[06/14 09:44:06.107] DEBUG[1176][C-00000000] app_mrcprecog.c: Apply option sit: 2
[06/14 09:44:06.107] DEBUG[1176][C-00000000] app_mrcprecog.c: Apply option spl: en-US
[06/14 09:44:06.107] DEBUG[1176][C-00000000] app_mrcprecog.c: Apply option rm: normal
[06/14 09:44:06.107] DEBUG[1176][C-00000000] app_mrcprecog.c: Apply option sl: 0.5
[06/14 09:44:06.107] DEBUG[1176][C-00000000] app_mrcprecog.c: Apply option ct: 0.7
[06/14 09:44:06.107] DEBUG[1176][C-00000000] app_mrcprecog.c: Apply option dit: 5000
[06/14 09:44:06.107] DEBUG[1176][C-00000000] app_mrcprecog.c: Apply option dtt: 10000
[06/14 09:44:06.107] DEBUG[1176][C-00000000] app_mrcprecog.c: Apply option nb: 10
[06/14 09:44:06.107] DEBUG[1176][C-00000000] app_mrcprecog.c: Apply option sva: 0.5
[06/14 09:44:06.108] DEBUG[1176][C-00000000] audio_queue.c: (ASR-0) Audio queue created
[06/14 09:44:06.108] DEBUG[1176][C-00000000] speech_channel.c: Created speech channel: Name=ASR-0, Type=RECOGNIZER, Codec=PCMU, Rate=8000 on PJSIP/1004-00000000
[06/14 09:44:06.108] DEBUG[1176][C-00000000] src/apt_task.c: Signal Message to [MRCP Client] [0x7f99c0003570;4;0]
[06/14 09:44:06.108] DEBUG[947] src/apt_task.c: Process Message [MRCP Client] [0x7f99c0003570;4;0]
[06/14 09:44:06.108] DEBUG[947] src/mrcp_client_session.c: Dispatch App Request ASR-0
[06/14 09:44:06.228] DEBUG[1176][C-00000000] speech_channel.c: Destroy speech channel: Name=ASR-0, Type=RECOGNIZER, Codec=PCMU, Rate=8000
[06/14 09:44:06.228] DEBUG[1176][C-00000000] src/apt_task.c: Signal Message to [MRCP Client] [0x7f99c0005e70;4;0]
[06/14 09:44:06.228] DEBUG[947] src/apt_task.c: Process Message [MRCP Client] [0x7f99c0005e70;4;0]
[06/14 09:44:06.228] DEBUG[947] src/mrcp_client_session.c: Dispatch App Request ASR-0 <37> [1]
[06/14 09:44:06.228] DEBUG[947] src/mrcp_client_session.c: Remove Control Channel ASR-0 <37>
[06/14 09:44:06.228] DEBUG[947] src/apt_task.c: Signal Message to [MRCPv2ConnectionAgent] [0x7f99c8010730;1;0]
[06/14 09:44:06.228] DEBUG[947] src/mrcp_client_session.c: Subtract Media Termination ASR-0 37@media-tm
[06/14 09:44:06.228] DEBUG[947] src/mrcp_client_session.c: Subtract Media Termination ASR-0 37@rtp-tm
[06/14 09:44:06.228] DEBUG[947] src/apt_task.c: Signal Message to [MediaEngine] [0x7f99c80091a0;1;0]
[06/14 09:44:06.228] DEBUG[947] src/apt_consumer_task.c: Wait for Messages [MRCP Client]
[06/14 09:44:06.228] DEBUG[948] src/apt_poller_task.c: Process Poller Wakeup [MRCPv2ConnectionAgent]
[06/14 09:44:06.228] DEBUG[948] src/apt_task.c: Process Message [MRCPv2ConnectionAgent] [0x7f99c8010730;1;0]
[06/14 09:44:06.228] DEBUG[948] src/apt_task.c: Signal Message to [MRCP Client] [0x7f99a8001fd0;2;2]
[06/14 09:44:06.228] DEBUG[948] src/apt_poller_task.c: Wait for Messages [MRCPv2ConnectionAgent]
[06/14 09:44:06.228] DEBUG[947] src/apt_task.c: Process Message [MRCP Client] [0x7f99a8001fd0;2;2]
[06/14 09:44:06.228] DEBUG[947] src/mrcp_client_session.c: Control Channel Removed ASR-0 37@speechrecog
[06/14 09:44:06.228] DEBUG[947] src/apt_consumer_task.c: Wait for Messages [MRCP Client]
[06/14 09:44:06.228] DEBUG[1176][C-00000000] speech_channel.c: (ASR-0) Waiting for MRCP session to terminate
[06/14 09:44:06.233] DEBUG[949] src/apt_task.c: Process Message [MediaEngine] [0x7f99c80091a0;1;0]
[06/14 09:44:06.233] DEBUG[949] src/mpf_bridge.c: Destroy Audio Bridge ASR-0
[06/14 09:44:06.233] DEBUG[949] src/mpf_context.c: Remove Media Context ASR-0
[06/14 09:44:06.233] DEBUG[949] src/apt_task.c: Signal Message to [MRCP Client] [0x7f99c800fa10;3;0]
[06/14 09:44:06.233] DEBUG[947] src/apt_task.c: Process Message [MRCP Client] [0x7f99c800fa10;3;0]
[06/14 09:44:06.233] DEBUG[947] src/mrcp_client_session.c: Media Termination Subtracted ASR-0 37@media-tm
[06/14 09:44:06.233] DEBUG[947] src/mrcp_client_session.c: Media Termination Subtracted ASR-0 37@rtp-tm
[06/14 09:44:06.233] DEBUG[947] src/apt_consumer_task.c: Wait for Messages [MRCP Client]
[06/14 09:44:06.433] DEBUG[950] src/apt_task.c: Signal Message to [MRCP Client] [0x6ea2ef0;1;1]
[06/14 09:44:06.433] DEBUG[947] src/apt_task.c: Process Message [MRCP Client] [0x6ea2ef0;1;1]
[06/14 09:44:06.433] DEBUG[947] app_mrcprecog.c: (ASR-0) speech_on_session_terminate
[06/14 09:44:06.433] DEBUG[947] app_mrcprecog.c: (ASR-0) DTMF generator destroyed
[06/14 09:44:06.433] DEBUG[947] app_mrcprecog.c: (ASR-0) Destroying MRCP session
[06/14 09:44:06.433] DEBUG[947] speech_channel.c: (ASR-0) ERROR ==> CLOSED
[06/14 09:44:06.433] DEBUG[947] src/apt_consumer_task.c: Wait for Messages [MRCP Client]
[06/14 09:44:06.433] DEBUG[1176][C-00000000] audio_queue.c: (ASR-0) Audio queue destroyed
[06/14 09:44:06.433] DEBUG[959] manager.c: Examining AMI event:
Event: VarSet
Privilege: dialplan,all
Channel: PJSIP/1004-00000000
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1004
CallerIDName: 1004
ConnectedLineNum:
[06/14 09:44:06.433] DEBUG[959] manager.c: Examining AMI event:
Event: AGIExecEnd
Privilege: agi,all
Channel: PJSIP/1004-00000000
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1004
CallerIDName: 1004
ConnectedLineNum:
[06/14 09:44:06.434] DEBUG[959] manager.c: Examining AMI event:
Event: AsyncAGIExec
Privilege: agi,all
Channel: PJSIP/1004-00000000
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 1004
CallerIDName: 1004
ConnectedLineNum:
Dan
Hi Dan,
Then I should take a closer look at this issue, hopefully sometime next week.
Hi Dan,
The problem must be finally fixed in c9820654d5c39d17fea0966f0a85902e66071b8c. Please give it another try.
Hi Arsen,
I just ran two different tests and it doesn't seem to fix the problem. It's not outputting either of the debug statements from the unimrcp code section you modified. "Unable to load grammar..." or "Unable to start grammar..."
Test 1, I used a grammar without any rules in it. This trace is same as before. Completion cause of 005 is showing up in the asterisk debug file.
Test 2, I passed a grammar file name that doesn't exist. In this case, I clearly see unimrcp code showing the completion-cause of 009, but no indication of any variable being set for the channel. [06/25 10:11:51.097] DEBUG[873] app_mrcprecog.c: (ASR-3) RECOGNIZE failed: status = 407, completion-cause = 009 Again, not outputting either "Unable to load grammar..." or "Unable to start grammar..."
Have a great day!
Dan
Hi Dan,
Unless I am missing something very obvious, there is an inconsistency here.
I checked once again the logs that you last provided, and the log statement "Recognizing, enable DTMFs:" produced by this line is missing. This statement must appear after "Add prompt", produced by line, but before the call for recog_channel_start(), where all the header fields are dumped. Here is the corresponding fragment from your logs.
[06/14 09:44:06.205] DEBUG[1176][C-00000000] app_mrcprecog.c: (ASR-0) Add prompt: /var/lib/asterisk/sounds/sox/IS/3319a8f37ab15b57e6d6ddf38d7d7164 [06/14 09:44:06.205] DEBUG[1176][C-00000000] speech_channel.c: (ASR-0) New-Audio-Channel: false
Please confirm that you do not have any modifications in the code, and also provide a complete output for such a session, including MRCP message exchange.
Hi Arsen,
Sorry for the delay in responding. I have been out for awhile due to surgery.
Not sure what I did previously, but I just verified it is setting the RECOG_COMPLETION_CAUSE variable. In the scenario I have been using, it's passing a cause of 005 (which is correct because one of the grammars has no valid rules).
Thanks for your help with this.
Have a great day!
Hi Dan,
Not sure about the cause, but I wish you speedy and fully recovery!
Glad that everything works as intended now. Thanks for your input.
Have a great day you too!
Hi Arsen,
How would I go about building an ubuntu package with this fix?
Have a great day!
Dan
Hi Dan,
A new Asterisk release 1.5.1 will be published by the of end of next week along with the binary packages for Ubuntu 16.04 and Red Hat 7.
Have a great day!
Thank you Arsen
Hi Dan,
Just wanted to let you know that 1.5.1 version is available in both source and binary distribution forms.
Thank you for your input.
Have a nice weekend.
Thank you Arsen
Have a great weekend!
Hi Arsen,
I have no problem making this work on my development VM by compiling the change. However, i need to install this on other VMs for testing.
Can I retrieve both of these packages and install them on a box with an asterisk 13.22.0 to make this work?
asterisk-app-unimrcp_1-5-1~13-17-0-xenial_amd64-deb.deb asterisk-res-speech-unimrcp_1.5.1_13.17.0-xenial_amd64.deb
Have a great day!
Dan
Hi Dan,
The binary packages are compiled against Asterisk 13.17.0 and will not be compatible with other versions.
Have you built Asterisk 13.22.0 from source or installed binary packages from a different repository?
Not only the version of Asterisk matters, but also compilation flags. In other words, UniMRCP modules need to be compiled against the same asterisk-dev package.
Have a great day you too!
Hi Arsen,
Thanks for the information. I didn't realize UniMRCP modules need to be compiled again the same asterisk-dev package.
We do build our own asterisk package from source. At times, I have had to submit work to asterisk for fixes to problems we are seeing. We cannot let our customers continue to have problems when we can patch and receive approval for the patch from asterisk submission process.
Is it possible for us to build both the asterisk and UniMRCP packages from source for distribution to our customers?
Have a great day!
Dan
Hi Dan,
If you have your own Asterisk packages, then you would need to build and distribute UniMRCP modules too. However, you may continue using UniMRCP client/deps packages. The procedure for building the modules would basically be:
Alternatively, if you can provide me with your Asterisk distribution, including asterisk-dev package, then I can build corresponding packages for UniMRCP modules and make them available back to you.
Have a nice weekend!
Hi Arsen,
Thank you. I believe we have everything compiling and working with our asterisk and UniMRCP package installation. I will put it through more thorough testing, but my first few tests I'm already seeing the RECOG_COMPLETION_CAUSE change.
Thanks again for all your help.
Have a great day!
Dan
The scenario we are encountering, the Recognition fails and we do not receive a RECOG_RESULT. In this situation, UniMRCP is seeing the 005 completion cause. However, it never passes it through to us via AMI. Since we see it in other calls (RECOG_RESULT set), I suspect the logic may not be setting RECOG_COMPLETION_CAUSE in this flow. Would it be possible to modify it to give us this completion cause? That way we can pass along the failure (completion-cause) to the user without having to diagnose the Asterisk logs.
Below is the debug information from Asterisk for the failure. It shows the Recognition failed with a status of 407 and completion cause of 005. This completion cause is not being passed through to the RECOG_COMPLETION_CAUSE variable.
[11/08 10:47:27.515] DEBUG[1365] src/apt_task.c: Process Message [MRCP Client] [0x7f1c580008c0;2;3] [11/08 10:47:27.516] DEBUG[1365] app_mrcprecog.c: (ASR-0) RECOGNIZE failed: status = 407, completion-cause = 005 [11/08 10:47:27.516] DEBUG[1365] speech_channel.c: (ASR-0) READY ==> ERROR [11/08 10:47:27.516] DEBUG[1365] src/apt_consumer_task.c: Wait for Messages [MRCP Client] [11/08 10:47:27.516] DEBUG[1674][C-00000000] speech_channel.c: Destroy speech channel: Name=ASR-0, Type=RECOGNIZER, Codec=PCMU, Rate=8000 [11/08 10:47:27.516] DEBUG[1674][C-00000000] src/apt_task.c: Signal Message to [MRCP Client] [0x7f1c78006640;4;0] [11/08 10:47:27.516] DEBUG[1674][C-00000000] speech_channel.c: (ASR-0) Waiting for MRCP session to terminate [11/08 10:47:27.516] DEBUG[1322] manager.c: Examining AMI event: Event: VarSet^M Privilege: dialplan,all^M Channel: PJSIP/1002-00000000^M ChannelState: 6^M ChannelStateDesc: Up^M CallerIDNum: 1002^M CallerIDName: XYZ^M ConnectedLineNum:^M
ConnectedLineName: ^M
Language: en^M
AccountCode: 6^M
Context: IS^M
Exten: 2093^M
Priority: 6^M
Uniqueid: 1510159646.0^M
Linkedid: 1510159646.0^M
Variable: RECOG_SID^M
Value: 1^M
^M
[11/08 10:47:27.516] DEBUG[1365] src/apt_task.c: Process Message [MRCP Client] [0x7f1c78006640;4;0] [11/08 10:47:27.516] DEBUG[1365] src/mrcp_client_session.c: Dispatch App Request ASR-0 <1> [1] [11/08 10:47:27.516] DEBUG[1365] src/mrcp_client_session.c: Remove Control Channel ASR-0 <1> [11/08 10:47:27.516] DEBUG[1365] src/apt_task.c: Signal Message to [MRCPv2ConnectionAgent] [0x1a42e30;1;0] [11/08 10:47:27.516] DEBUG[1365] src/mrcp_client_session.c: Subtract Media Termination ASR-0 1@media-tm [11/08 10:47:27.516] DEBUG[1365] src/mrcp_client_session.c: Subtract Media Termination ASR-0 1@rtp-tm [11/08 10:47:27.516] DEBUG[1365] src/apt_task.c: Signal Message to [MediaEngine] [0x2f6e830;1;0] [11/08 10:47:27.516] DEBUG[1365] src/apt_consumer_task.c: Wait for Messages [MRCP Client] [11/08 10:47:27.516] DEBUG[1366] src/apt_poller_task.c: Process Poller Wakeup [MRCPv2ConnectionAgent] [11/08 10:47:27.516] DEBUG[1366] src/apt_task.c: Process Message [MRCPv2ConnectionAgent] [0x1a42e30;1;0] [11/08 10:47:27.516] DEBUG[1366] src/apt_task.c: Signal Message to [MRCP Client] [0x7f1c580008c0;2;2] [11/08 10:47:27.516] DEBUG[1366] src/apt_poller_task.c: Wait for Messages [MRCPv2ConnectionAgent] [11/08 10:47:27.516] DEBUG[1365] src/apt_task.c: Process Message [MRCP Client] [0x7f1c580008c0;2;2] [11/08 10:47:27.516] DEBUG[1365] src/mrcp_client_session.c: Control Channel Removed ASR-0 1@speechrecog [11/08 10:47:27.516] DEBUG[1365] src/apt_consumer_task.c: Wait for Messages [MRCP Client] [11/08 10:47:27.522] DEBUG[1367] src/apt_task.c: Process Message [MediaEngine] [0x2f6e830;1;0] [11/08 10:47:27.522] DEBUG[1367] src/mpf_bridge.c: Destroy Audio Bridge ASR-0 [11/08 10:47:27.522] DEBUG[1367] src/mpf_context.c: Remove Media Context ASR-0 [11/08 10:47:27.522] DEBUG[1367] src/apt_task.c: Signal Message to [MRCP Client] [0x1e1a270;3;0] [11/08 10:47:27.522] DEBUG[1365] src/apt_task.c: Process Message [MRCP Client] [0x1e1a270;3;0] [11/08 10:47:27.522] DEBUG[1365] src/mrcp_client_session.c: Media Termination Subtracted ASR-0 1@media-tm [11/08 10:47:27.522] DEBUG[1365] src/mrcp_client_session.c: Media Termination Subtracted ASR-0 1@rtp-tm [11/08 10:47:27.522] DEBUG[1365] src/apt_consumer_task.c: Wait for Messages [MRCP Client] [11/08 10:47:27.618] DEBUG[1368] src/apt_task.c: Signal Message to [MRCP Client] [0x7f1c64001430;1;1] [11/08 10:47:27.618] DEBUG[1365] src/apt_task.c: Process Message [MRCP Client] [0x7f1c64001430;1;1] [11/08 10:47:27.618] DEBUG[1365] app_mrcprecog.c: (ASR-0) speech_on_session_terminate [11/08 10:47:27.618] DEBUG[1365] app_mrcprecog.c: (ASR-0) DTMF generator destroyed [11/08 10:47:27.618] DEBUG[1365] app_mrcprecog.c: (ASR-0) Destroying MRCP session [11/08 10:47:27.618] DEBUG[1365] speech_channel.c: (ASR-0) ERROR ==> CLOSED [11/08 10:47:27.618] DEBUG[1365] src/apt_consumer_task.c: Wait for Messages [MRCP Client] [11/08 10:47:27.618] DEBUG[1674][C-00000000] audio_queue.c: (ASR-0) Audio queue destroyed [11/08 10:47:27.619] DEBUG[1322] manager.c: Examining AMI event: Event: VarSet^M Privilege: dialplan,all^M Channel: PJSIP/1002-00000000^M ChannelState: 6^M ChannelStateDesc: Up^M CallerIDNum: 1002^M CallerIDName: XYZ^M ConnectedLineNum:^M
ConnectedLineName: ^M
Language: en^M
AccountCode: 6^M
Context: IS^M
Exten: 2093^M
Priority: 6^M
Uniqueid: 1510159646.0^M
Linkedid: 1510159646.0^M
Variable: RECOGSTATUS^M
Value: ERROR^M
^M
[11/08 10:47:27.619] DEBUG[1322] manager.c: Examining AMI event: Event: AGIExecEnd^M Privilege: agi,all^M Channel: PJSIP/1002-00000000^M ChannelState: 6^M ChannelStateDesc: Up^M CallerIDNum: 1002^M CallerIDName: XYZ^M ConnectedLineNum:^M
ConnectedLineName: ^M
Language: en^M
AccountCode: 6^M
Context: IS^M
Exten: 2093^M
Priority: 6^M
Uniqueid: 1510159646.0^M
Linkedid: 1510159646.0^M
Result: Unknown Result^M
CommandId: 1844242488^M
Command: EXEC MRCPRecog ____^M
ResultCode: 200^M
[11/08 10:47:27.619] DEBUG[1322] manager.c: Examining AMI event: Event: AsyncAGIExec^M Privilege: agi,all^M Channel: PJSIP/1002-00000000^M ChannelState: 6^M ChannelStateDesc: Up^M CallerIDNum: 1002^M CallerIDName: XYZ^M ConnectedLineNum:^M
ConnectedLineName: ^M
Language: en^M
AccountCode: 6^M
Context: IS^M
Exten: 2093^M
Priority: 6^M
Uniqueid: 1510159646.0^M
Linkedid: 1510159646.0^M
CommandId: C20^M
Result: 200%20result%3D-1%0A^M
^M
Have a great day!
Dan