Recognition is suspended 15 seconds after the start of work

[rybushkindmitry]

Recognition is suspended 15 seconds after the start of work.

same => n,SpeechBackground(Speech,10)

The timeout option does not affect performance. I've tried setting to 5, 10, 40 and no value.

After the end of the conversation on the phone, the channel on the asterisk remains in a frozen state.

localhost*CLI> core show channels verbose Channel Context Extension Prio State Application Data CallerID Duration Accountcode PeerAccount BridgeID
PJSIP/102-00000000 internal 1 10 Up SpeechBackgr Speech-2 102 00:12:58
PJSIP/102-00000001 internal 1 10 Up SpeechBackgr Speech-2,10 102 00:10:37
PJSIP/102-00000002 internal 1 10 Up SpeechBackgr Speech-2,10 102 00:04:41
3 active channels 3 active calls 3 calls processed

[nshmyrev]

Most likely you don't have latest asterisk patches with ping/pong handling

https://github.com/asterisk/asterisk/commit/7163efd934b75a39c766313ec2eec05c1439dbf0

[rybushkindmitry]

I have updated the asterisk to the latest version. I checked that this patch is in the source code. The problem was not solved.

[laar789]

Hi, it is true, I have the same problem. After 15 seconds sometimes is like 30 seconds, rtp stops flowing, and the channel get stuck in asterisk ( you can validate it with core show channels verbose). Something I verify is that when I hang the channel in the softphone I'm using, the sip messages flow normally, asterisk receive the BYE and send the ACK, but the channel is up and stuck. I'm using pjsip by the way...Can someone solve this issue... btw. If using speechbackground during the first 15 seconds the app works very well.

[nshmyrev]

@laar789 what is your asterisk version

[laar789]

I tried 16.13.0 and 17.7.0. With both versions the result is the same....

[nshmyrev]

Ok, what is dumped on console log when channel hangs?

[laar789]

Well, actually nothing special. Using the default app, it just suddenly stops showing some info. It starts like this:

Executing [123@profile-6:1] NoOp("PJSIP/user1-00000003", "") in new stack -- Executing [123@profile-6:2] Answer("PJSIP/user1-00000003", "") in new stack -- Executing [123@profile-6:3] SpeechCreate("PJSIP/user1-00000003", "") in new stack [Oct 13 08:48:44] NOTICE[28196][C-00000004]: res_speech_vosk.c:83 vosk_recog_create: (vosk) Create speech resource ws://127.0.0.1:2700 [Oct 13 08:48:44] NOTICE[28196][C-00000004]: res_speech_vosk.c:91 vosk_recog_create: (vosk) Created speech resource result 0 -- Executing [123@profile-6:4] TryExec("PJSIP/user1-00000003", "SpeechBackground(demo-congrats)") in new stack [Oct 13 08:48:44] NOTICE[28196][C-00000004]: res_speech_vosk.c:201 vosk_recog_start: (vosk) Start recognition [Oct 13 08:48:44] NOTICE[28196][C-00000004]: res_speech_vosk.c:166 vosk_recog_write: (vosk) Got result: '{ "partial" : "" }' [Oct 13 08:48:44] NOTICE[28196][C-00000004]: res_speech_vosk.c:166 vosk_recog_write: (vosk) Got result: '{ "partial" : "" }' [Oct 13 08:48:44] NOTICE[28196][C-00000004]: res_speech_vosk.c:166 vosk_recog_write: (vosk) Got result: '{ "partial" : "" }' [Oct 13 08:48:45] NOTICE[28196][C-00000004]: res_speech_vosk.c:166 vosk_recog_write: (vosk) Got result: '{ "partial" : "" }' [Oct 13 08:48:45] NOTICE[28196][C-00000004]: res_speech_vosk.c:166 vosk_recog_write: (vosk) Got result: '{ "partial" : "" }'

And after many lines of the same notice, it simply stops showing no more info, nor a different notice or warning or error, it justs stops, and in the phone the call continue, when I hang up the phone in asterisk the channel stay:

asterisk*CLI> core show channels verbose Channel Context Extension Prio State Application Data CallerID Duration Accountcode PeerAccount BridgeID
PJSIP/user1-00000001 profile-6 123 4 Up SpeechBackgr demo-congrats 1000 16:31:01
PJSIP/user1-00000002 profile-6 123 4 Up SpeechBackgr demo-congrats 1000 16:19:48
PJSIP/user1-00000003 profile-6 123 4 Up SpeechBackgr demo-congrats 1000 00:02:26
3 active channels 3 active call

Sometimes the channel hangs automatically with the message of no RTP activity... but some channels just stays in ther, like the ones you see, until I restart asterisk.

Enabling the DEBUG, the last message it show the console is:

[Oct 13 08:55:53] DEBUG[28569][C-00000006]: res_http_websocket.c:382 __ast_websocket_write: Writing websocket binary frame, length 3200 [Oct 13 08:55:53] NOTICE[28569][C-00000006]: res_speech_vosk.c:166 vosk_recog_write: (vosk) Got result: '{ "partial" : "" }' [Oct 13 08:55:53] DEBUG[28569][C-00000006]: res_http_websocket.c:382 __ast_websocket_write: Writing websocket binary frame, length 3200 [Oct 13 08:55:53] NOTICE[28569][C-00000006]: res_speech_vosk.c:166 vosk_recog_write: (vosk) Got result: '{ "partial" : "" }' [Oct 13 08:55:53] DEBUG[28569][C-00000006]: res_http_websocket.c:382 __ast_websocket_write: Writing websocket pong frame, length 4

Always the last message is the "Writing websocket pong frame, length 4" and then it stops. Although It show like 4 or 5 pong messages before.

[nshmyrev]

Ok, this is helpful. You can probably run the asr server from terminal too and get the log there. To enable logging you can uncomment this part in asr_server.py:

# Enable loging if needed
#
# logger = logging.getLogger('websockets')
# logger.setLevel(logging.INFO)
# logger.addHandler(logging.StreamHandler())

[laar789]

Hi I try enabling loging en asr_server.py (within docker), but besides this:

LOG (VoskAPI:ReadDataFiles():vosk/model.cc:192) Decoding params beam=13 max-active=7000 lattice-beam=6 LOG (VoskAPI:ReadDataFiles():vosk/model.cc:195) Silence phones 1:2:3:4:5:6:7:8:9:10 LOG (VoskAPI:RemoveOrphanNodes():nnet-nnet.cc:948) Removed 1 orphan nodes. LOG (VoskAPI:RemoveOrphanComponents():nnet-nnet.cc:847) Removing 2 orphan components. LOG (VoskAPI:Collapse():nnet-utils.cc:1472) Added 1 components, removed 2 LOG (VoskAPI:CompileLooped():nnet-compile-looped.cc:345) Spent 0.07177 seconds in looped compilation. LOG (VoskAPI:ReadDataFiles():vosk/model.cc:219) Loading i-vector extractor from /opt/vosk-model-es/model/ivector/final.ie LOG (VoskAPI:ComputeDerivedVars():ivector-extractor.cc:183) Computing derived variables for iVector extractor LOG (VoskAPI:ComputeDerivedVars():ivector-extractor.cc:204) Done. LOG (VoskAPI:ReadDataFiles():vosk/model.cc:240) Loading HCL and G from /opt/vosk-model-es/model/HCLr.fst /opt/vosk-model-es/model/Gr.fst LOG (VoskAPI:ReadDataFiles():vosk/model.cc:262) Loading winfo /opt/vosk-model-es/model/word_boundary.int_

After initializing the asr_server, no message is shown when asterisk channel connects or freezes....or maybe I'm doing something wrong?

[laar789]

Hi.

I want to share something else I realize. When I execute the SpeechCreate app, and vosk server isn't available, the channel get stuck, like 2 minutes, untill some "Connection timed out" occur in module tcptls.c. But the case is that when the SpeechCreate is executing, no sip event affect the channel, I mean, I hangup but the channel keeps searching for vosk server. I think maybe this is for other issue or even for an asterisk bug report, but the behavior is the same when no audio to recognize is sent to SpeechBackground app.

I will keep looking more because this is the best way to integrate asterisk with the amazing Vosk project for an IVR application. I hope @nshmyrev could find more.

[nshmyrev]

@laar789 thank you, this is useful information. I wish I can have a time to look on this issue closer, I'll try.

[BaderEddineB]

Any news on this subject ? i have the same probleme !

[laar789]

Hi. It seems like there is no solution right now. I use a workaround, that has work for me. Basically I split the long audio into 2 or more short audios (like 10 seconds) and then repeat the SpeechBackground as many times as audios I have, something like this:

exten => 1,1,Answer same => n,Wait(1) same => n,SpeechCreate same => n,SpeechBackground(hello_1) same => n,Verbose(0,Result was ${SPEECH_TEXT(0)}) same => n,SpeechDestroy()

same => n,SpeechCreate same => n,SpeechBackground(hello_2) same => n,Verbose(0,Result was ${SPEECH_TEXT(0)}) same => n,SpeechDestroy()

same => n,SpeechCreate same => n,SpeechBackground(hello_2) same => n,Verbose(0,Result was ${SPEECH_TEXT(0)}) same => n,SpeechDestroy()

With this works, but it has its down side, because when something is about to be recognized just in between the destroy, and the next create, it just get lost. But it mostly works.

So, a complete fix is still desirable and needed, because it sometimes will fail, and split a minute audio into 6 can make the dialplan very long and that's not desirable.

The software is really good and I like it very much. I will try to find a fix, and learn more C to try to collaborate with the project, but right now I am in other projects and C is not my strong

[Goddard]

Also running into this issue.

Just curious @nshmyrev what version of Asterisk did you test on that didn't have this issue?

Thanks

UPDATE : I tested on asterisk 16 and git master as of today. Same issue on both.