ERROR Completion-Cause: 006 recognizer-error / Validating Setup for Azure SR plugin launching UniMRCP client application umc

477 views
Skip to first unread message

Antonio D'andrea

unread,
Oct 25, 2019, 8:17:18 AM10/25/19
to UniMRCP
When I try to launch UniMRCP client application umc for testing the AzureSR plugin I got the following error:

logs of MRCP + wireshark in the attached file. Please help to identify what the issue can be....may just a configuration one but I'm not sure, thx in advance.

I'll describe in summary what errors I'm facing ....please look at the logs for more details. I've run both run bsr1 ,recog uni2.
afterward I'd like to understand if UniMRCP is connectiong to Azur Speech Engine or not....

run bsr1
2019-10-25 12:02:21:031028 [DEBUG]  Signal Message to [Framework Agent] [0x616bb0;1;1]
>2019-10-25 12:02:21:031154 [DEBUG]  Process Message [Framework Agent] [0x616bb0;1;1]
[1]
2019-10-25 12:02:21:031236 [NOTICE] Create MRCP Handle 0x7ff680033600 [uni2]
......

2019-10-25 12:02:21:051615 [INFO]   Receive MRCPv2 Data 10.70.4.124:1544 <-> 10.70.4.124:48114 [335 bytes]
MRCP/2.0 335 RECOGNIZE 1
Channel-Identifier: 0faeee5277c546c7@speechrecog
Content-Id: request1@form-level
Content-Type: text/uri-list
Cancel-If-Queue: false
No-Input-Timeout: 5000
Recognition-Timeout: 10000
Start-Input-Timers: true
Confidence-Threshold: 0.5
Save-Waveform: true
Content-Length: 25

builtin:speech/transcribe

2019-10-25 12:02:21:051690 [INFO]   Assign Control Channel <0faeee5277c546c7@speechrecog> to Connection 10.70.4.124:1544 <-> 10.70.4.124:48114 [0] -> [1]
2019-10-25 12:02:21:051704 [DEBUG]  Signal Message to [MRCP Server] [0x7f67f00008c0;2;3]
2019-10-25 12:02:21:051722 [DEBUG]  Wait for Messages [MRCPv2-Agent-1] timeout [600000]
2019-10-25 12:02:21:051730 [DEBUG]  Process Message [MRCP Server] [0x7f67f00008c0;2;3]
2019-10-25 12:02:21:051750 [DEBUG]  Dispatch Signaling Message [1]
2019-10-25 12:02:21:051763 [INFO]   Process RECOGNIZE Request <0faeee5277c546c7@speechrecog> [1]
2019-10-25 12:02:21:051783 [DEBUG]  Wait for Messages [MRCP Server]
2019-10-25 12:02:21:051847 [DEBUG]  Add Speech Grammar [transcribe] <0faeee5277c546c7@azuresr>
2019-10-25 12:02:21:051880 [INFO]   Init Speech Detector: frame-size=320, max-frame-count=350, output-frame-count=20, vad-mode=2, noinput-timeout=5000 ms, input-timeout=10000 ms, start-timeout=50 ms, complete-timeout=1000 ms, incomplete-timeout=3000 ms, leading-silence=300 ms, trailing-silence=300 ms, interim-results=1, start-of-input=external <0faeee5277c546c7>
2019-10-25 12:02:21:051958 [INFO]   Start No-Input Timer [5000 ms] <0faeee5277c546c7>
2019-10-25 12:02:21:051984 [INFO]   Open Waveform File for Writing /opt/unimrcp/var/umsazuresr-0faeee5277c546c7-1-16-kHz.wav, sampling-rate [16000]
2019-10-25 12:02:21:052462 [DEBUG]  Signal Message to [MRCP Server] [0x7f68000009f0;3;4]
2019-10-25 12:02:21:052504 [DEBUG]  Process Message [MRCP Server] [0x7f68000009f0;3;4]
2019-10-25 12:02:21:052522 [INFO]   Process RECOGNIZE Response <0faeee5277c546c7@speechrecog> [1]
2019-10-25 12:02:21:052537 [INFO]   State Transition IDLE -> RECOGNIZING <0faeee5277c546c7@speechrecog>
2019-10-25 12:02:21:052545 [DEBUG]  Signal Message to [MRCPv2-Agent-1] [0x7f680802e0e0;1;0]
2019-10-25 12:02:21:052557 [DEBUG]  Wait for Messages [MRCP Server]
2019-10-25 12:02:21:052567 [DEBUG]  Process Poller Wakeup [MRCPv2-Agent-1]
2019-10-25 12:02:21:052587 [DEBUG]  Process Message [MRCPv2-Agent-1] [0x7f680802e0e0;1;0]
2019-10-25 12:02:21:052605 [INFO]   Send MRCPv2 Data 10.70.4.124:1544 <-> 10.70.4.124:48114 [83 bytes]
MRCP/2.0 83 1 200 IN-PROGRESS
Channel-Identifier: 0faeee5277c546c7@speechrecog

2019-10-25 12:02:21:052642 [DEBUG]  Wait for Messages [MRCPv2-Agent-1] timeout [600000]
2019-10-25 12:02:21:052811 [WARN]   Failed to Connect to Service <0faeee5277c546c7@azuresr>
2019-10-25 12:02:21:246793 [DEBUG]  Start Detector State Probation NO-INPUT -> IN-PROGRESS [200 ms] <0faeee5277c546c7>
2019-10-25 12:02:21:246842 [DEBUG]  Detector: read-marker=0, input-start-marker=12, write-marker=13 <0faeee5277c546c7>
2019-10-25 12:02:21:296809 [INFO]   Speech Detector State Transition NO-INPUT -> IN-PROGRESS [250 ms] <0faeee5277c546c7>
2019-10-25 12:02:21:297040 [INFO]   Start Input Timer [10000 ms] <0faeee5277c546c7>
2019-10-25 12:02:21:297048 [DEBUG]  Set Speech Complete Timeout [3000 ms] <0faeee5277c546c7>
2019-10-25 12:02:21:297056 [DEBUG]  Detector Silence Output: read-marker=0, count=18, write-marker=18 <0faeee5277c546c7>
2019-10-25 12:02:21:297133 [DEBUG]  Stop Input <0faeee5277c546c7@azuresr>
2019-10-25 12:02:21:307110 [INFO]   Input Complete [stopped] size=5760 bytes, dur=360 ms <0faeee5277c546c7@azuresr>
2019-10-25 12:02:21:307135 [DEBUG]  Close Waveform File umsazuresr-0faeee5277c546c7-1-16-kHz.wav, content-length [0]
2019-10-25 12:02:21:307508 [DEBUG]  Signal Message to [MRCP Server] [0x7f6800011940;3;4]
2019-10-25 12:02:21:307556 [DEBUG]  Process Message [MRCP Server] [0x7f6800011940;3;4]
2019-10-25 12:02:21:307586 [INFO]   Process RECOGNITION-COMPLETE Event <0faeee5277c546c7@speechrecog> [1]
2019-10-25 12:02:21:307595 [INFO]   State Transition RECOGNIZING -> RECOGNIZED <0faeee5277c546c7@speechrecog>
2019-10-25 12:02:21:307603 [DEBUG]  Signal Message to [MRCPv2-Agent-1] [0x7f680802e0e0;1;0]
2019-10-25 12:02:21:307623 [DEBUG]  Wait for Messages [MRCP Server]
2019-10-25 12:02:21:307714 [DEBUG]  Process Poller Wakeup [MRCPv2-Agent-1]
2019-10-25 12:02:21:307735 [DEBUG]  Process Message [MRCPv2-Agent-1] [0x7f680802e0e0;1;0]
2019-10-25 12:02:21:307752 [INFO]   Send MRCPv2 Data 10.70.4.124:1544 <-> 10.70.4.124:48114 [247 bytes]
MRCP/2.0 247 RECOGNITION-COMPLETE 1 COMPLETE
Channel-Identifier: 0faeee5277c546c7@speechrecog
Completion-Cause: 006 recognizer-error


run recog uni2
2019-10-25 12:03:33:282358 [DEBUG]  Signal Message to [Framework Agent] [0x616df0;1;1]
>2019-10-25 12:03:33:282450 [DEBUG]  Process Message [Framework Agent] [0x616df0;1;1]
[1]
2019-10-25 12:03:33:282515 [NOTICE] Create MRCP Handle 0x7f450c033600 [uni2]

2019-10-25 12:02:59:193146 [INFO]   Receive MRCPv2 Data 10.70.4.124:1544 <-> 10.70.4.124:48118 [335 bytes]
MRCP/2.0 335 RECOGNIZE 1
Channel-Identifier: 9857108f74744fae@speechrecog
Content-Id: request1@form-level
Content-Type: text/uri-list
Cancel-If-Queue: false
No-Input-Timeout: 5000
Recognition-Timeout: 10000
Start-Input-Timers: true
Confidence-Threshold: 0.5
Save-Waveform: true
Content-Length: 25

builtin:speech/transcribe
2019-10-25 12:02:59:193191 [INFO]   Assign Control Channel <9857108f74744fae@speechrecog> to Connection 10.70.4.124:1544 <-> 10.70.4.124:48118 [0] -> [1]
2019-10-25 12:02:59:193204 [DEBUG]  Signal Message to [MRCP Server] [0x7f67f00008c0;2;3]
2019-10-25 12:02:59:193215 [DEBUG]  Wait for Messages [MRCPv2-Agent-1] timeout [600000]
2019-10-25 12:02:59:193240 [DEBUG]  Process Message [MRCP Server] [0x7f67f00008c0;2;3]
2019-10-25 12:02:59:193253 [DEBUG]  Dispatch Signaling Message [1]
2019-10-25 12:02:59:193259 [INFO]   Process RECOGNIZE Request <9857108f74744fae@speechrecog> [1]
2019-10-25 12:02:59:193271 [DEBUG]  Wait for Messages [MRCP Server]
2019-10-25 12:02:59:193332 [DEBUG]  Add Speech Grammar [transcribe] <9857108f74744fae@azuresr>
2019-10-25 12:02:59:193353 [INFO]   Init Speech Detector: frame-size=320, max-frame-count=350, output-frame-count=20, vad-mode=2, noinput-timeout=5000 ms, input-timeout=10000 ms, start-timeout=50 ms, complete-timeout=1000 ms, incomplete-timeout=3000 ms, leading-silence=300 ms, trailing-silence=300 ms, interim-results=1, start-of-input=external <9857108f74744fae>
2019-10-25 12:02:59:193404 [INFO]   Start No-Input Timer [5000 ms] <9857108f74744fae>
2019-10-25 12:02:59:193429 [INFO]   Open Waveform File for Writing /opt/unimrcp/var/umsazuresr-9857108f74744fae-1-16-kHz.wav, sampling-rate [16000]
2019-10-25 12:02:59:193952 [DEBUG]  Signal Message to [MRCP Server] [0x7f68000008c0;3;4]
2019-10-25 12:02:59:193983 [DEBUG]  Process Message [MRCP Server] [0x7f68000008c0;3;4]
2019-10-25 12:02:59:193994 [INFO]   Process RECOGNIZE Response <9857108f74744fae@speechrecog> [1]
2019-10-25 12:02:59:194011 [INFO]   State Transition IDLE -> RECOGNIZING <9857108f74744fae@speechrecog>
2019-10-25 12:02:59:194020 [DEBUG]  Signal Message to [MRCPv2-Agent-1] [0x7f680802e0e0;1;0]
2019-10-25 12:02:59:194032 [DEBUG]  Wait for Messages [MRCP Server]
2019-10-25 12:02:59:194048 [DEBUG]  Process Poller Wakeup [MRCPv2-Agent-1]
2019-10-25 12:02:59:194057 [DEBUG]  Process Message [MRCPv2-Agent-1] [0x7f680802e0e0;1;0]
2019-10-25 12:02:59:194068 [INFO]   Send MRCPv2 Data 10.70.4.124:1544 <-> 10.70.4.124:48118 [83 bytes]
MRCP/2.0 83 1 200 IN-PROGRESS
Channel-Identifier: 9857108f74744fae@speechrecog

2019-10-25 12:02:59:194078 [WARN]   Failed to Connect to Service <9857108f74744fae@azuresr>

2019-10-25 12:02:59:447596 [INFO]   Send MRCPv2 Data 10.70.4.124:1544 <-> 10.70.4.124:48118 [247 bytes]
MRCP/2.0 247 RECOGNITION-COMPLETE 1 COMPLETE
Channel-Identifier: 9857108f74744fae@speechrecog
Completion-Cause: 006 recognizer-error




SR_test4.rar

Sean DiSanti

unread,
Oct 25, 2019, 1:18:36 PM10/25/19
to uni...@googlegroups.com
The lines that jump out to me are 

2019-10-25 12:02:21:052811 [WARN]   Failed to Connect to Service <0faeee5277c546c7@azuresr>  
and

2019-10-25 12:02:59:194078 [WARN]   Failed to Connect to Service <9857108f74744fae@azuresr> 
I don't see a specific error response like you'd get for unauthorized or bad credentials, so I'd make sure you're getting out correctly.  

--
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/c1f74dcb-ffec-4ee6-9253-445174c89096%40googlegroups.com.

Antonio D'andrea

unread,
Oct 25, 2019, 2:47:56 PM10/25/19
to UniMRCP
Thx Sean to look at my errors, but I removed the error failed to Connect to Service since I was using bing service. Now UniMRCP is using the new speech service but at the end I still having the same error 006 recognizer-error. I've reattached a new set of logs "test6".

both run bsr1 ans bss1 are giving errors , while run dtmf seems to work fine.

now I see:
2019-10-25 20:29:50:320159 [NOTICE] UniMRCP AzureSR License 

-product name:    umsazuresr
-product version: 1.0.0
-license owner:   -
-license type:    trial
-issue date:      2019-10-24
-exp date:        2019-11-23
-channel count:   2
-feature set:     0
.......

2019-10-25 20:29:50:322107 [NOTICE] UniMRCP AzureSS License 

-product name:    umsazuress
-product version: 1.0.0
-license owner:   -
-license type:    trial
-issue date:      2019-10-24
-exp date:        2019-11-23
-channel count:   2
-feature set:     0
............
2019-10-25 20:29:50:322496 [INFO]   Auth Endpoint [https://westeurope.api.cognitive.microsoft.com/sts/v1.0/issueToken] Key [32 bytes] Service Endpoint [https://westeurope.tts.speech.microsoft.com/cognitiveservices/v1]

run bsr1
2019-10-25 20:30:06:561468 [INFO]   Receive MRCPv2 Data 10.70.4.124:1544 <-> 10.70.4.124:50752 [335 bytes]
MRCP/2.0 335 RECOGNIZE 1
Channel-Identifier: 9ccd73bda2fc47cb@speechrecog
Content-Id: request1@form-level
Content-Type: text/uri-list
Cancel-If-Queue: false
No-Input-Timeout: 5000
Recognition-Timeout: 10000
Start-Input-Timers: true
Confidence-Threshold: 0.5
Save-Waveform: true
Content-Length: 25

builtin:speech/transcribe

2019-10-25 20:30:06:562422 [INFO]   Send MRCPv2 Data 10.70.4.124:1544 <-> 10.70.4.124:50752 [83 bytes]
MRCP/2.0 83 1 200 IN-PROGRESS
Channel-Identifier: 9ccd73bda2fc47cb@speechrecog

2019-10-25 20:30:06:562510 [DEBUG]  Wait for Messages [MRCPv2-Agent-1] timeout [600000]
2019-10-25 20:30:06:752636 [DEBUG]  Start Detector State Probation NO-INPUT -> IN-PROGRESS [200 ms] <9ccd73bda2fc47cb>
2019-10-25 20:30:06:752691 [DEBUG]  Detector: read-marker=0, input-start-marker=12, write-marker=13 <9ccd73bda2fc47cb>
2019-10-25 20:30:06:802662 [INFO]   Speech Detector State Transition NO-INPUT -> IN-PROGRESS [250 ms] <9ccd73bda2fc47cb>
2019-10-25 20:30:06:802716 [INFO]   Start Input Timer [10000 ms] <9ccd73bda2fc47cb>
2019-10-25 20:30:06:802724 [DEBUG]  Set Speech Complete Timeout [3000 ms] <9ccd73bda2fc47cb>
2019-10-25 20:30:06:802731 [DEBUG]  Detector Silence Output: read-marker=0, count=18, write-marker=18 <9ccd73bda2fc47cb>
2019-10-25 20:30:06:802798 [DEBUG]  Stop Input <9ccd73bda2fc47cb@azuresr>
2019-10-25 20:30:06:812769 [INFO]   Input Complete [stopped] size=5760 bytes, dur=360 ms <9ccd73bda2fc47cb@azuresr>
2019-10-25 20:30:06:812792 [DEBUG]  Close Waveform File umsazuresr-9ccd73bda2fc47cb-1-16-kHz.wav, content-length [0]
2019-10-25 20:30:06:813179 [DEBUG]  Signal Message to [MRCP Server] [0x7fbd78011980;3;4]
2019-10-25 20:30:06:813234 [DEBUG]  Process Message [MRCP Server] [0x7fbd78011980;3;4]
2019-10-25 20:30:06:813249 [INFO]   Process RECOGNITION-COMPLETE Event <9ccd73bda2fc47cb@speechrecog> [1]
2019-10-25 20:30:06:813258 [INFO]   State Transition RECOGNIZING -> RECOGNIZED <9ccd73bda2fc47cb@speechrecog>
2019-10-25 20:30:06:813267 [DEBUG]  Signal Message to [MRCPv2-Agent-1] [0x7fbd8002e0d0;1;0]
2019-10-25 20:30:06:813283 [DEBUG]  Wait for Messages [MRCP Server]
2019-10-25 20:30:06:813338 [DEBUG]  Process Poller Wakeup [MRCPv2-Agent-1]
2019-10-25 20:30:06:813353 [DEBUG]  Process Message [MRCPv2-Agent-1] [0x7fbd8002e0d0;1;0]
2019-10-25 20:30:06:813368 [INFO]   Send MRCPv2 Data 10.70.4.124:1544 <-> 10.70.4.124:50752 [247 bytes]
MRCP/2.0 247 RECOGNITION-COMPLETE 1 COMPLETE
Channel-Identifier: 9ccd73bda2fc47cb@speechrecog
Completion-Cause: 006 recognizer-error


run bss1
2019-10-25 20:30:14:801272 [INFO]   Receive MRCPv2 Data 10.70.4.124:1544 <-> 10.70.4.124:50754 [289 bytes]
MRCP/2.0 289 SPEAK 1
Channel-Identifier: 8e80f0d66b57431d@speechsynth
Content-Type: application/ssml+xml
Content-Length: 158

<?xml version="1.0"?>
<speak version="1.0" xml:lang="en-US" xmlns="http://www.w3.org/2001/10/synthesis">
  <p>
    <s>Welcome to Uni MRCP.</s>
  </p>
</speak>
......

2019-10-25 20:30:14:801300 [INFO]   Assign Control Channel <8e80f0d66b57431d@speechsynth> to Connection 10.70.4.124:1544 <-> 10.70.4.124:50754 [0] -> [1]
2019-10-25 20:30:14:801322 [DEBUG]  Signal Message to [MRCP Server] [0x7fbd640008c0;2;3]
2019-10-25 20:30:14:801337 [DEBUG]  Wait for Messages [MRCPv2-Agent-1] timeout [600000]
2019-10-25 20:30:14:801365 [DEBUG]  Process Message [MRCP Server] [0x7fbd640008c0;2;3]
2019-10-25 20:30:14:801377 [DEBUG]  Dispatch Signaling Message [1]
2019-10-25 20:30:14:801399 [INFO]   Process SPEAK Request <8e80f0d66b57431d@speechsynth> [1]
2019-10-25 20:30:14:801420 [DEBUG]  Wait for Messages [MRCP Server]
2019-10-25 20:30:14:801559 [DEBUG]  Found voice [Microsoft Server Speech Text to Speech Voice (en-US, JessaRUS)] by language [en-US] and name [JessaRUS] <8e80f0d66b57431d@azuress>
2019-10-25 20:30:14:801709 [DEBUG]  Signal Message to [MRCP Server] [0x7fbd7400d370;3;4]
2019-10-25 20:30:14:801750 [DEBUG]  Process Message [MRCP Server] [0x7fbd7400d370;3;4]
2019-10-25 20:30:14:801764 [INFO]   Process SPEAK Response <8e80f0d66b57431d@speechsynth> [1]
2019-10-25 20:30:14:801772 [DEBUG]  Signal Message to [MRCPv2-Agent-1] [0x7fbd8002e0d0;1;0]
2019-10-25 20:30:14:801784 [DEBUG]  Wait for Messages [MRCP Server]
2019-10-25 20:30:14:801807 [DEBUG]  Process Poller Wakeup [MRCPv2-Agent-1]
2019-10-25 20:30:14:801817 [DEBUG]  Process Message [MRCPv2-Agent-1] [0x7fbd8002e0d0;1;0]
2019-10-25 20:30:14:801828 [INFO]   Send MRCPv2 Data 10.70.4.124:1544 <-> 10.70.4.124:50754 [110 bytes]
MRCP/2.0 110 1 401 COMPLETE
Channel-Identifier: 8e80f0d66b57431d@speechsynth
Completion-Cause: 004 error

run dtmf

2019-10-25 20:30:41:441966 [INFO]   Receive SIP Event [nua_i_invite] Status 100 Trying [SIP-Agent-1]
2019-10-25 20:30:41:442002 [INFO]   Receive SIP Event [nua_i_state] Status 100 Trying [SIP-Agent-1]
2019-10-25 20:30:41:442013 [NOTICE] SIP Call State  [received]
2019-10-25 20:30:41:442031 [INFO]   Create Session 0x7fbd68001b58 <new> [uni2]
2019-10-25 20:30:41:442041 [INFO]   Remote SDP 0x7fbd68001b58 <new>
v=0
o=UniMRCPClient 6277126965011034479 6024674052324674879 IN IP4 10.70.4.124
s=-
c=IN IP4 10.70.4.124
t=0 0
m=application 9 TCP/MRCPv2 1
a=setup:active
a=connection:new
a=resource:speechrecog
a=cmid:1
m=audio 4006 RTP/AVP 0 8 96 101 97 98 99 102
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:96 L16/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=rtpmap:97 PCMU/16000
a=rtpmap:98 PCMA/16000
a=rtpmap:99 L16/16000
a=rtpmap:102 telephone-event/16000
a=fmtp:102 0-15
a=sendonly
a=ptime:20
a=mid:1

2019-10-25 20:30:41:442091 [DEBUG]  Signal Message to [MRCP Server] [0x7fbd68004660;1;0]
2019-10-25 20:30:41:442113 [DEBUG]  Process Message [MRCP Server] [0x7fbd68004660;1;0]
2019-10-25 20:30:41:442124 [DEBUG]  Dispatch Signaling Message [0]
2019-10-25 20:30:41:442256 [NOTICE] Add Session <00ecea3978834c01>
2019-10-25 20:30:41:442269 [INFO]   Receive Offer 0x7fbd68001b58 <00ecea3978834c01> [c:1 a:1 v:0]
2019-10-25 20:30:41:442281 [INFO]   Found MRCP Engine [Azure-SR-1] for Resource [speechrecog] 0x7fbd68001b58 <00ecea3978834c01>
2019-10-25 20:30:41:442297 [DEBUG]  Add Control Channel 0x7fbd68001b58 <00ecea3978834c01@speechrecog> [0]
2019-10-25 20:30:41:442305 [DEBUG]  Signal Message to [MRCPv2-Agent-1] [0x7fbd8002e0d0;1;0]
2019-10-25 20:30:41:442345 [DEBUG]  Add Media Termination 0x7fbd68001b58 <00ecea3978834c01@rtp-tm> [0]
2019-10-25 20:30:41:442355 [DEBUG]  Signal Message to [Media-Engine-1] [0x7fbd8002e120;1;0]
2019-10-25 20:30:41:442363 [DEBUG]  Wait for Messages [MRCP Server]
2019-10-25 20:30:41:442379 [DEBUG]  Process Poller Wakeup [MRCPv2-Agent-1]
2019-10-25 20:30:41:442388 [DEBUG]  Process Message [MRCPv2-Agent-1] [0x7fbd8002e0d0;1;0]
2019-10-25 20:30:41:442397 [INFO]   Add Pending Control Channel <00ecea3978834c01@speechrecog> [1]
2019-10-25 20:30:41:442419 [DEBUG]  Signal Message to [MRCP Server] [0x7fbd640008c0;2;0]
2019-10-25 20:30:41:442431 [DEBUG]  Wait for Messages [MRCPv2-Agent-1]
2019-10-25 20:30:41:442457 [DEBUG]  Process Message [MRCP Server] [0x7fbd640008c0;2;0]
2019-10-25 20:30:41:442468 [DEBUG]  Control Channel Modified 0x7fbd68001b58 <00ecea3978834c01@speechrecog>
2019-10-25 20:30:41:442475 [DEBUG]  Wait for Messages [MRCP Server]
2019-10-25 20:30:41:442614 [DEBUG]  Process Message [Media-Engine-1] [0x7fbd8002e120;1;0]
2019-10-25 20:30:41:442640 [DEBUG]  Add Media Context 0x7fbd68001b58
2019-10-25 20:30:41:442720 [INFO]   Enable RTP Session 10.70.4.124:5006
2019-10-25 20:30:41:442739 [DEBUG]  Create Linear Audio Bridge 0x7fbd68001b58
2019-10-25 20:30:41:442748 [INFO]   Open RTP Receiver 10.70.4.124:5006 <- 10.70.4.124:4006 playout [50 ms] bounds [0 - 600 ms] adaptive [1] skew detection [1]
2019-10-25 20:30:41:442758 [INFO]   Media Path 0x7fbd68001b58 Source->[PCMU/8000/1]->Decoder->[LPCM/8000/1]->Bridge->[LPCM/8000/1]->Sink
2019-10-25 20:30:41:442765 [DEBUG]  Signal Message to [MRCP Server] [0x7fbd500008c0;4;0]
2019-10-25 20:30:41:442799 [DEBUG]  Process Message [MRCP Server] [0x7fbd500008c0;4;0]
2019-10-25 20:30:41:442817 [DEBUG]  Media Termination Modified 0x7fbd68001b58 <00ecea3978834c01@media-tm>
2019-10-25 20:30:41:442825 [DEBUG]  Media Termination Modified 0x7fbd68001b58 <00ecea3978834c01@rtp-tm>
2019-10-25 20:30:41:442846 [DEBUG]  Wait for Messages [MRCP Server]
2019-10-25 20:30:41:442860 [INFO]   Open <00ecea3978834c01@azuresr>
2019-10-25 20:30:41:442888 [NOTICE] AzureSR Usage: 1/1/2
2019-10-25 20:30:41:442898 [DEBUG]  Signal Message to [MRCP Server] [0x7fbd7800b4f0;3;2]
2019-10-25 20:30:41:442950 [DEBUG]  Process Message [MRCP Server] [0x7fbd7800b4f0;3;2]
2019-10-25 20:30:41:442966 [DEBUG]  Engine Channel Opened 0x7fbd68001b58 <00ecea3978834c01@speechrecog> [OK]
2019-10-25 20:30:41:442974 [INFO]   Send Answer 0x7fbd68001b58 <00ecea3978834c01> [c:1 a:1 v:0] Status OK
2019-10-25 20:30:41:442996 [INFO]   Local SDP 0x7fbd68001b58 <00ecea3978834c01>
v=0
o=UniMRCPServer 0 0 IN IP4 10.70.4.124
s=-
c=IN IP4 10.70.4.124
t=0 0
m=application 1544 TCP/MRCPv2 1
a=setup:passive
a=connection:new
a=channel:00ecea3978834c01@speechrecog
a=cmid:1
m=audio 5006 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=recvonly
a=ptime:20
a=mid:1

2019-10-25 20:30:41:443031 [DEBUG]  Wait for Messages [MRCP Server]
2019-10-25 20:30:41:443356 [INFO]   Receive SIP Event [nua_i_state] Status 200 OK [SIP-Agent-1]
2019-10-25 20:30:41:443375 [NOTICE] SIP Call State 0x7fbd68001b58 [completed]
2019-10-25 20:30:41:443578 [INFO]   Receive SIP Event [nua_i_ack] Status 200 OK [SIP-Agent-1]
2019-10-25 20:30:41:443596 [INFO]   Receive SIP Event [nua_i_state] Status 200 OK [SIP-Agent-1]
2019-10-25 20:30:41:443604 [NOTICE] SIP Call State 0x7fbd68001b58 [ready]
2019-10-25 20:30:41:443611 [INFO]   Receive SIP Event [nua_i_active] Status 200 Call active [SIP-Agent-1]
2019-10-25 20:30:41:443931 [DEBUG]  Process Signalled Descriptor [MRCPv2-Agent-1]
2019-10-25 20:30:41:443965 [NOTICE] Accepted TCP/MRCPv2 Connection 10.70.4.124:1544 <-> 10.70.4.124:50760
2019-10-25 20:30:41:443976 [DEBUG]  Wait for Messages [MRCPv2-Agent-1] timeout [600000]
2019-10-25 20:30:41:451443 [DEBUG]  Process Signalled Descriptor [MRCPv2-Agent-1]
2019-10-25 20:30:41:451465 [INFO]   Receive MRCPv2 Data 10.70.4.124:1544 <-> 10.70.4.124:50760 [203 bytes]
MRCP/2.0 203 RECOGNIZE 1
Channel-Identifier: 00ecea3978834c01@speechrecog
Content-Id: request1@form-level
Content-Type: text/uri-list
Cancel-If-Queue: false
Content-Length: 19

builtin:dtmf/digits
2019-10-25 20:30:41:451492 [INFO]   Assign Control Channel <00ecea3978834c01@speechrecog> to Connection 10.70.4.124:1544 <-> 10.70.4.124:50760 [0] -> [1]
2019-10-25 20:30:41:451501 [DEBUG]  Signal Message to [MRCP Server] [0x7fbd640008c0;2;3]
2019-10-25 20:30:41:451512 [DEBUG]  Wait for Messages [MRCPv2-Agent-1] timeout [600000]
2019-10-25 20:30:41:451520 [DEBUG]  Process Message [MRCP Server] [0x7fbd640008c0;2;3]
2019-10-25 20:30:41:451541 [DEBUG]  Dispatch Signaling Message [1]
2019-10-25 20:30:41:451552 [INFO]   Process RECOGNIZE Request <00ecea3978834c01@speechrecog> [1]
2019-10-25 20:30:41:451573 [DEBUG]  Wait for Messages [MRCP Server]
2019-10-25 20:30:41:451599 [DEBUG]  Add DTMF Grammar [digits] <00ecea3978834c01@azuresr>
2019-10-25 20:30:41:451624 [INFO]   Init DTMF Detector: interdigit-timeout=5000 ms, term-timeout=10000 ms, term-char= , length=0, min-length=0, max-length=0 <00ecea3978834c01>
2019-10-25 20:30:41:451634 [INFO]   Start No-Input Timer [5000 ms] <00ecea3978834c01>
2019-10-25 20:30:41:451646 [INFO]   Open Waveform File for Writing /opt/unimrcp/var/umsazuresr-00ecea3978834c01-1-8-kHz.wav, sampling-rate [8000]
2019-10-25 20:30:41:452035 [DEBUG]  Signal Message to [MRCP Server] [0x7fbd7800b4f0;3;4]
2019-10-25 20:30:41:452069 [DEBUG]  Process Message [MRCP Server] [0x7fbd7800b4f0;3;4]
2019-10-25 20:30:41:452084 [INFO]   Process RECOGNIZE Response <00ecea3978834c01@speechrecog> [1]
2019-10-25 20:30:41:452091 [INFO]   State Transition IDLE -> RECOGNIZING <00ecea3978834c01@speechrecog>
2019-10-25 20:30:41:452099 [DEBUG]  Signal Message to [MRCPv2-Agent-1] [0x7fbd8002e0d0;1;0]
2019-10-25 20:30:41:452118 [DEBUG]  Wait for Messages [MRCP Server]
2019-10-25 20:30:41:452129 [DEBUG]  Process Poller Wakeup [MRCPv2-Agent-1]
2019-10-25 20:30:41:452142 [DEBUG]  Process Message [MRCPv2-Agent-1] [0x7fbd8002e0d0;1;0]
2019-10-25 20:30:41:452154 [INFO]   Send MRCPv2 Data 10.70.4.124:1544 <-> 10.70.4.124:50760 [83 bytes]
MRCP/2.0 83 1 200 IN-PROGRESS
Channel-Identifier: 00ecea3978834c01@speechrecog


2019-10-25 20:30:41:452190 [DEBUG]  Wait for Messages [MRCPv2-Agent-1] timeout [600000]
2019-10-25 20:30:41:512624 [INFO]   DTMF Detector State Transition NO-INPUT -> IN-PROGRESS [0 ms] <00ecea3978834c01>
2019-10-25 20:30:41:512655 [INFO]   Start Input Timer [10000 ms] <00ecea3978834c01>
2019-10-25 20:30:41:512678 [INFO]   Detected Start of Event: id=1, digit=1 <00ecea3978834c01>
2019-10-25 20:30:41:512704 [DEBUG]  DTMF Input Started <00ecea3978834c01@azuresr>
2019-10-25 20:30:41:512741 [DEBUG]  Signal Message to [MRCP Server] [0x7fbd7800b4f0;3;4]
2019-10-25 20:30:41:512777 [DEBUG]  Process Message [MRCP Server] [0x7fbd7800b4f0;3;4]
2019-10-25 20:30:41:512799 [INFO]   Process START-OF-INPUT Event <00ecea3978834c01@speechrecog> [1]
2019-10-25 20:30:41:512809 [DEBUG]  Signal Message to [MRCPv2-Agent-1] [0x7fbd8002e0d0;1;0]
2019-10-25 20:30:41:512831 [DEBUG]  Wait for Messages [MRCP Server]
2019-10-25 20:30:41:512847 [DEBUG]  Process Poller Wakeup [MRCPv2-Agent-1]
2019-10-25 20:30:41:512868 [DEBUG]  Process Message [MRCPv2-Agent-1] [0x7fbd8002e0d0;1;0]
2019-10-25 20:30:41:512884 [INFO]   Send MRCPv2 Data 10.70.4.124:1544 <-> 10.70.4.124:50760 [113 bytes]
MRCP/2.0 113 START-OF-INPUT 1 IN-PROGRESS
Channel-Identifier: 00ecea3978834c01@speechrecog
Input-Type: dtmf


2019-10-25 20:30:41:512954 [DEBUG]  Wait for Messages [MRCPv2-Agent-1] timeout [599940]
2019-10-25 20:30:41:572613 [INFO]   Detected End of Event: id=1 duration=560 ts <00ecea3978834c01>
2019-10-25 20:30:41:572636 [INFO]   Start Inter-Digit Timer [5000 ms] <00ecea3978834c01>
2019-10-25 20:30:41:632628 [INFO]   Detected Start of Event: id=2, digit=2 <00ecea3978834c01>
2019-10-25 20:30:41:692631 [INFO]   Detected End of Event: id=2 duration=560 ts <00ecea3978834c01>
2019-10-25 20:30:41:692688 [INFO]   Start Inter-Digit Timer [5000 ms] <00ecea3978834c01>
2019-10-25 20:30:41:752615 [INFO]   Detected Start of Event: id=3, digit=3 <00ecea3978834c01>
2019-10-25 20:30:41:812621 [INFO]   Detected End of Event: id=3 duration=560 ts <00ecea3978834c01>
2019-10-25 20:30:41:812662 [INFO]   Start Inter-Digit Timer [5000 ms] <00ecea3978834c01>
2019-10-25 20:30:41:872615 [INFO]   Detected Start of Event: id=4, digit=4 <00ecea3978834c01>
2019-10-25 20:30:41:932616 [INFO]   Detected End of Event: id=4 duration=560 ts <00ecea3978834c01>
2019-10-25 20:30:41:932656 [INFO]   Start Inter-Digit Timer [5000 ms] <00ecea3978834c01>
2019-10-25 20:30:46:922621 [INFO]   DTMF Detector State Transition IN-PROGRESS -> COMPLETE [0 ms] <00ecea3978834c01>
2019-10-25 20:30:46:922677 [INFO]   Detector Stats: leading-silence=0 ms, input=0 ms, trailing-silence=0 ms <00ecea3978834c01>
2019-10-25 20:30:46:922730 [INFO]   Input Complete [success] size=0 bytes, dur=0 ms <00ecea3978834c01@azuresr>
2019-10-25 20:30:46:922793 [DEBUG]  Close Waveform File umsazuresr-00ecea3978834c01-1-8-kHz.wav, content-length [0]
2019-10-25 20:30:46:923051 [DEBUG]  Signal Message to [MRCP Server] [0x7fbd78011980;3;4]
2019-10-25 20:30:46:923116 [DEBUG]  Process Message [MRCP Server] [0x7fbd78011980;3;4]
2019-10-25 20:30:46:923142 [INFO]   Process RECOGNITION-COMPLETE Event <00ecea3978834c01@speechrecog> [1]
2019-10-25 20:30:46:923152 [INFO]   State Transition RECOGNIZING -> RECOGNIZED <00ecea3978834c01@speechrecog>
2019-10-25 20:30:46:923161 [DEBUG]  Signal Message to [MRCPv2-Agent-1] [0x7fbd8002e0d0;1;0]
2019-10-25 20:30:46:923187 [DEBUG]  Wait for Messages [MRCP Server]
2019-10-25 20:30:46:923206 [DEBUG]  Process Poller Wakeup [MRCPv2-Agent-1]
2019-10-25 20:30:46:923227 [DEBUG]  Process Message [MRCPv2-Agent-1] [0x7fbd8002e0d0;1;0]
2019-10-25 20:30:46:923248 [INFO]   Send MRCPv2 Data 10.70.4.124:1544 <-> 10.70.4.124:50760 [382 bytes]
MRCP/2.0 382 RECOGNITION-COMPLETE 1 COMPLETE
Channel-Identifier: 00ecea3978834c01@speechrecog
Completion-Cause: 000 success
Content-Type: application/x-nlsml
Content-Length: 197

<?xml version="1.0"?>
<result>
  <interpretation grammar="builtin:dtmf/digits" confidence="1.00">
    <input mode="dtmf">1 2 3 4</input>
    <instance>1234</instance>
  </interpretation>
</result>





To unsubscribe from this group and stop receiving emails from it, send an email to uni...@googlegroups.com.
test6.rar

Arsen Chaloyan

unread,
Oct 26, 2019, 5:06:24 PM10/26/19
to UniMRCP
Antonio, the logs show that the client and server are generally setup properly. The problem is in the communication with Azure Speech services. Please note that the TCP port 443 to the service needs to remain open.

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/a9598e91-ed86-462f-a1a9-697de832067d%40googlegroups.com.


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

Antonio D'andrea

unread,
Oct 28, 2019, 6:20:38 AM10/28/19
to UniMRCP
Thx For the answer Arser.

when you say Please note that the TCP port 443 to the service needs to remain open, do you see this on wireshark trace provided by Me or you just looking at the log event like the one below:

2019-10-25 20:29:50:323632 [WARN]   Request failed: Success (0) for HTTP auth <AzureSR>
2019-10-25 20:29:50:323651 [INFO]   Clear HTTP timer <AzureSR>
2019-10-25 20:29:50:323637 [DEBUG]  Signal Message to [MRCP Server] [0x7fbd5c001790;3;0]
2019-10-25 20:29:50:323660 [INFO]   Close HTTP connection <AzureSR>

I'm asking this because I don't see the closure of TCP port 443 in the wireshark corresponding to the logs event.

furthermore, in the wireshark I see the DNS query towards westeurope.api.cognitive.microsoft.com is replied with a DNS response  Standard query response, No such name. May this also causing the reachability of MS Speech Services?

Thx
Antonio.

Arsen Chaloyan

unread,
Oct 29, 2019, 9:22:20 PM10/29/19
to UniMRCP
Hi Antonio,

Sorry, I did not have the chance to take a look at the network capture. Of course, DNS resolving as well as any other generic networking issues could easily cause such a problem.

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/e52e5744-3e10-410f-b1ad-aadd8d55d544%40googlegroups.com.

Wilmar Pérez

unread,
Oct 30, 2019, 6:13:42 PM10/30/19
to uni...@googlegroups.com
Hi Antonio,

I am not familiar with the Azure integration but what a recurrent error you have is:

[WARN]   Failed to Connect to Service <0faeee5277c546c7@azuresr>

And in your wireshark trace, I can see that your DNS is failing to resolve some basic Microsoft names:

image.png

When in fact they can be resolved:

image.png

Your DNS seems to be 10.10.3.11, a local one. I would try adding a couple of DNS to your 10.70.4.124 box.  Try with OpenDNS:

 OpenDNS server addresses, 208.67.222.222 and 208.67.220.220

 Or Google:  8.8.8.8

Try doing that and see how it works.

Best,

Wilmar




--
--------------------------------------------------------
Wilmar Pérez 

Antonio D'andrea

unread,
Oct 31, 2019, 6:09:55 AM10/31/19
to UniMRCP
Thx Wilmar, Thx Arsen.

meanwhile I made progress...since customer is using an http proxy I previously set at the linux level only in order to run the yum installation....thinking it was enough to contact MS speech services...but I was wrong since I noticed from the Usage Manual of Azure SR and SS plugin that you need to Specifies the URI of HTTP proxy in both  umsazuresr.xml and  umsazuress.xml.

afterward I was able to run the test from the umc client with positive result.

thx again for your support
Antonio.


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

--
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 uni...@googlegroups.com.


--
--------------------------------------------------------
Wilmar Pérez 
Reply all
Reply to author
Forward
0 new messages