[ Respeaker Core V2.0 ] Snips unresponsive once an intent has not been recognized

[GiovanniBalestrieri]

I am facing a problem with Snips. The Chain works well until an intent is not recognized or the ASR captures an empty string.

The hotword is not triggered anymore and not even a sudo systemctl restart snips-hotword.service solved the problem. I have to restart the 'snips-audio-server.service' to get back on track.

I am using a Respeaker Core v2.0

Here are the logs when an empty string is detected and the audio service is restarted

Sep 13 14:32:45 glutamate snips-audio-server[2667]: ALSA lib pcm_dmix.c:1052:(snd_pcm_dmix_open) unable to open slave
Sep 13 14:32:45 glutamate snips-audio-server[2667]: Failed to create secure directory (/var/empty/.config/pulse): No such file or directory
Sep 13 14:32:45 glutamate snips-audio-server[2667]: Failed to load cookie file from cookie: No such file or directory
Sep 13 14:32:45 glutamate snips-audio-server[2667]: ALSA lib pulse.c:243:(pulse_connect) PulseAudio: Unable to connect: Access denied
Sep 13 14:32:45 glutamate snips-audio-server[2667]: Failed to create secure directory (/var/empty/.config/pulse): No such file or directory
Sep 13 14:32:45 glutamate snips-audio-server[2667]: Failed to load cookie file from cookie: No such file or directory
Sep 13 14:32:45 glutamate snips-audio-server[2667]: ALSA lib pulse.c:243:(pulse_connect) PulseAudio: Unable to connect: Access denied
Sep 13 14:32:45 glutamate snips-audio-server[2667]: INFO:snips_audio_portaudio: Use input device: "seeed-8mic-voicecard: - (hw:0,0)"
Sep 13 14:32:45 glutamate pulseaudio[489]: W: [pulseaudio] protocol-native.c: Denied access to client with invalid authentication data.
Sep 13 14:32:45 glutamate pulseaudio[489]: W: [pulseaudio] protocol-native.c: Denied access to client with invalid authentication data.
Sep 13 14:32:55 glutamate snips-hotword[2520]: INFO:snips_hotword_hermes        : Hotword detected: site_id:default model:default
Sep 13 14:32:55 glutamate snips-dialogue[2508]: INFO:snips_dialogue_lib::coordinator::coordinator: Site [default]: reset site -> turn off ASR and turn off Hotword
Sep 13 14:32:55 glutamate snips-dialogue[2508]: INFO:snips_dialogue_lib::coordinator::coordinator: Session [f6189b54-10d1-4f64-883d-9b7eab7a213b]: The session has been created because the site "default" is free
Sep 13 14:32:55 glutamate snips-hotword[2520]: INFO:snips_hotword_lib::features : Audio thread for site default idle.
Sep 13 14:32:55 glutamate snips-audio-server[2667]: INFO:snips_audio_portaudio: Playing "776edf59-31d7-4483-8934-288a72988d29" using output "seeed-8mic-voicecard: - (hw:0,1)", wav spec: WavSpec { channels: 2, sample_rate: 22050, bits_per_sample: 16, sample_format: Int }
Sep 13 14:32:56 glutamate snips-audio-server[2667]: INFO:snips_audio_portaudio: Playing of "776edf59-31d7-4483-8934-288a72988d29" finished
Sep 13 14:32:56 glutamate snips-tts[2519]: WARN:snips_tts_hermes: Did received a "play finished" message from audio server with an unknown id '776edf59-31d7-4483-8934-288a72988d29'. It could be normal if you have more than one audio server.
Sep 13 14:32:56 glutamate snips-asr[2518]: INFO:snips_asr_hermes  : Listening
Sep 13 14:32:56 glutamate snips-asr[2518]: INFO:snips_asr_lib::asr: T0       entered AsrRunner::run
Sep 13 14:32:56 glutamate snips-asr[2518]: INFO:snips_asr_lib::asr: T0+0.000 capture started
Sep 13 14:33:00 glutamate snips-asr[2518]: INFO:snips_asr_lib::asr: T0+4.540 endpoint detected (rule:1) frame:274 samples:70144 signal_time:4.384 rtf:0.661
Sep 13 14:33:00 glutamate snips-asr[2518]: INFO:snips_asr_lib::asr: T0+4.550 capture ended
Sep 13 14:33:01 glutamate snips-asr[2518]: INFO:snips_asr_lib::asr: T0+4.694 decoder finalized
Sep 13 14:33:01 glutamate snips-asr[2518]: INFO:snips_asr_lib::asr: T0+4.695 lookup and post-processing done
Sep 13 14:33:01 glutamate snips-asr[2518]: INFO:snips_asr_hermes  : Cleanup
Sep 13 14:33:01 glutamate snips-asr[2518]: INFO:snips_asr_hermes  : Preparing decoder
Sep 13 14:33:01 glutamate snips-audio-server[2667]: INFO:snips_audio_portaudio: Playing "a948a70f-dbb2-4797-a1e6-1d5e6715fab3" using output "seeed-8mic-voicecard: - (hw:0,1)", wav spec: WavSpec { channels: 2, sample_rate: 22050, bits_per_sample: 16, sample_format: Int }
Sep 13 14:33:01 glutamate snips-asr[2518]: INFO:snips_asr_hermes  : Idle
Sep 13 14:33:02 glutamate snips-audio-server[2667]: INFO:snips_audio_portaudio: Playing of "a948a70f-dbb2-4797-a1e6-1d5e6715fab3" finished
Sep 13 14:33:02 glutamate snips-tts[2519]: WARN:snips_tts_hermes: Did received a "play finished" message from audio server with an unknown id 'a948a70f-dbb2-4797-a1e6-1d5e6715fab3'. It could be normal if you have more than one audio server.
Sep 13 14:33:02 glutamate snips-audio-server[2667]: INFO:snips_audio_portaudio: Playing "2193ea28-d169-4f17-8818-494d91de6b30" using output "seeed-8mic-voicecard: - (hw:0,1)", wav spec: WavSpec { channels: 2, sample_rate: 44100, bits_per_sample: 16, sample_format: Int }
Sep 13 14:33:03 glutamate snips-audio-server[2667]: INFO:snips_audio_portaudio: Playing of "2193ea28-d169-4f17-8818-494d91de6b30" finished
Sep 13 14:33:03 glutamate snips-tts[2519]: WARN:snips_tts_hermes: Did received a "play finished" message from audio server with an unknown id '2193ea28-d169-4f17-8818-494d91de6b30'. It could be normal if you have more than one audio server.
Sep 13 14:33:03 glutamate snips-dialogue[2508]: INFO:snips_dialogue_lib::coordinator::coordinator: Session [f6189b54-10d1-4f64-883d-9b7eab7a213b]: closing session which was active: IntentNotRecognized
Sep 13 14:33:03 glutamate snips-dialogue[2508]: INFO:snips_dialogue_lib::coordinator::coordinator: Site [default]: reset site -> turn off ASR and turn on Hotword
Sep 13 14:33:03 glutamate snips-hotword[2520]: INFO:snips_hotword_lib::features : Audio thread for site default running
Sep 13 14:33:09 glutamate systemd[1]: Stopping Snips Audio Server...
Sep 13 14:33:09 glutamate systemd[1]: Stopped Snips Audio Server.
Sep 13 14:33:09 glutamate systemd[1]: Started Snips Audio Server.
Sep 13 14:33:09 glutamate snips-audio-server[2704]: Failed to create secure directory (/var/empty/.config/pulse): No such file or directory
Sep 13 14:33:09 glutamate snips-audio-server[2704]: Failed to load cookie file from cookie: No such file or directory
Sep 13 14:33:10 glutamate snips-audio-server[2704]: ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.front
Sep 13 14:33:10 glutamate snips-audio-server[2704]: ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.rear
Sep 13 14:33:10 glutamate snips-audio-server[2704]: ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.center_lfe
Sep 13 14:33:10 glutamate snips-audio-server[2704]: ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.side
Sep 13 14:33:10 glutamate snips-audio-server[2704]: ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.surround21
Sep 13 14:33:10 glutamate snips-audio-server[2704]: ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.surround21
Sep 13 14:33:10 glutamate snips-audio-server[2704]: ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.surround40
Sep 13 14:33:10 glutamate snips-audio-server[2704]: ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.surround41
Sep 13 14:33:10 glutamate snips-audio-server[2704]: ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.surround50
Sep 13 14:33:10 glutamate snips-audio-server[2704]: ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.surround51
Sep 13 14:33:10 glutamate snips-audio-server[2704]: ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.surround71
Sep 13 14:33:10 glutamate snips-audio-server[2704]: ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.iec958
Sep 13 14:33:10 glutamate snips-audio-server[2704]: ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.iec958
Sep 13 14:33:10 glutamate snips-audio-server[2704]: ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.iec958
Sep 13 14:33:10 glutamate snips-audio-server[2704]: ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.hdmi
Sep 13 14:33:10 glutamate snips-audio-server[2704]: ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.hdmi
Sep 13 14:33:10 glutamate snips-audio-server[2704]: ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.modem
Sep 13 14:33:10 glutamate snips-audio-server[2704]: ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.modem
Sep 13 14:33:10 glutamate snips-audio-server[2704]: ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.phoneline
Sep 13 14:33:10 glutamate snips-audio-server[2704]: ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.phoneline
Sep 13 14:33:10 glutamate snips-audio-server[2704]: ALSA lib pcm_dmix.c:1052:(snd_pcm_dmix_open) unable to open slave
Sep 13 14:33:10 glutamate snips-audio-server[2704]: Failed to create secure directory (/var/empty/.config/pulse): No such file or directory
Sep 13 14:33:10 glutamate snips-audio-server[2704]: Failed to load cookie file from cookie: No such file or directory
Sep 13 14:33:10 glutamate snips-audio-server[2704]: ALSA lib pulse.c:243:(pulse_connect) PulseAudio: Unable to connect: Access denied
Sep 13 14:33:10 glutamate snips-audio-server[2704]: Failed to create secure directory (/var/empty/.config/pulse): No such file or directory
Sep 13 14:33:10 glutamate snips-audio-server[2704]: Failed to load cookie file from cookie: No such file or directory
Sep 13 14:33:10 glutamate snips-audio-server[2704]: ALSA lib pulse.c:243:(pulse_connect) PulseAudio: Unable to connect: Access denied
Sep 13 14:33:10 glutamate pulseaudio[489]: W: [pulseaudio] protocol-native.c: Denied access to client with invalid authentication data.
Sep 13 14:33:10 glutamate pulseaudio[489]: W: [pulseaudio] protocol-native.c: Denied access to client with invalid authentication data.
Sep 13 14:33:10 glutamate snips-audio-server[2704]: INFO:snips_audio_portaudio: Use input device: "seeed-8mic-voicecard: - (hw:0,0)"
Sep 13 14:33:15 glutamate snips-hotword[2520]: INFO:snips_hotword_hermes        : Hotword detected: site_id:default model:default
Sep 13 14:33:15 glutamate snips-dialogue[2508]: INFO:snips_dialogue_lib::coordinator::coordinator: Site [default]: reset site -> turn off ASR and turn off Hotword
Sep 13 14:33:15 glutamate snips-dialogue[2508]: INFO:snips_dialogue_lib::coordinator::coordinator: Session [d65ced77-8699-4976-9d8b-87642398cd94]: The session has been created because the site "default" is free
Sep 13 14:33:15 glutamate snips-audio-server[2704]: INFO:snips_audio_portaudio: Playing "e225b822-291c-4686-97e4-6b3af467cf97" using output "seeed-8mic-voicecard: - (hw:0,1)", wav spec: WavSpec { channels: 2, sample_rate: 22050, bits_per_sample: 16, sample_format: Int }
Sep 13 14:33:15 glutamate snips-hotword[2520]: INFO:snips_hotword_lib::features : Audio thread for site default idle.
Sep 13 14:33:16 glutamate snips-audio-server[2704]: INFO:snips_audio_portaudio: Playing of "e225b822-291c-4686-97e4-6b3af467cf97" finished
Sep 13 14:33:16 glutamate snips-tts[2519]: WARN:snips_tts_hermes: Did received a "play finished" message from audio server with an unknown id 'e225b822-291c-4686-97e4-6b3af467cf97'. It could be normal if you have more than one audio server.
Sep 13 14:33:16 glutamate snips-asr[2518]: INFO:snips_asr_hermes  : Listening
Sep 13 14:33:16 glutamate snips-asr[2518]: INFO:snips_asr_lib::asr: T0       entered AsrRunner::run
Sep 13 14:33:16 glutamate snips-asr[2518]: INFO:snips_asr_lib::asr: T0+0.000 capture started
Sep 13 14:33:18 glutamate snips-asr[2518]: INFO:snips_asr_lib::asr: T0+2.408 endpoint detected (rule:2) frame:143 samples:36608 signal_time:2.288 rtf:0.638
Sep 13 14:33:18 glutamate snips-asr[2518]: INFO:snips_asr_lib::asr: T0+2.414 capture ended
Sep 13 14:33:18 glutamate snips-asr[2518]: INFO:snips_asr_lib::asr: T0+2.557 decoder finalized
Sep 13 14:33:18 glutamate snips-asr[2518]: INFO:snips_asr_lib::asr: T0+2.557 lookup and post-processing done
Sep 13 14:33:18 glutamate snips-asr[2518]: INFO:snips_asr_hermes  : Cleanup
Sep 13 14:33:18 glutamate snips-asr[2518]: INFO:snips_asr_hermes  : Preparing decoder
Sep 13 14:33:18 glutamate snips-audio-server[2704]: INFO:snips_audio_portaudio: Playing "9c500074-bee9-4ee3-a17c-27a819a685f9" using output "seeed-8mic-voicecard: - (hw:0,1)", wav spec: WavSpec { channels: 2, sample_rate: 22050, bits_per_sample: 16, sample_format: Int }
Sep 13 14:33:19 glutamate snips-asr[2518]: INFO:snips_asr_hermes  : Idle
Sep 13 14:33:20 glutamate snips-audio-server[2704]: INFO:snips_audio_portaudio: Playing of "9c500074-bee9-4ee3-a17c-27a819a685f9" finished
Sep 13 14:33:20 glutamate snips-tts[2519]: WARN:snips_tts_hermes: Did received a "play finished" message from audio server with an unknown id '9c500074-bee9-4ee3-a17c-27a819a685f9'. It could be normal if you have more than one audio server.
Sep 13 14:33:25 glutamate snips-dialogue[2508]: INFO:snips_dialogue_lib::coordinator::coordinator: Session [d65ced77-8699-4976-9d8b-87642398cd94]: closing session which was active: Timeout
Sep 13 14:33:25 glutamate snips-dialogue[2508]: INFO:snips_dialogue_lib::coordinator::coordinator: Site [default]: reset site -> turn off ASR and turn on Hotword
Sep 13 14:33:25 glutamate snips-hotword[2520]: INFO:snips_hotword_lib::features : Audio thread for site default running

[WedHumpDay]

I've confirmed this as well on Respeaker Core v2. Was able to reproduce under 60.8, Once an unknown intent, responses are no longer recognized. In my case, I have to restart all services to have recognition back.

respeaker@Livingroom:~$ sam status

Connected to device livingroom

OS version ................... Debian GNU/Linux 9 (stretch)
Installed assistant .......... Snips
Language ..................... en
Hotword ...................... jarvis
ASR engine ................... snips
Status ....................... Live

Service status:

snips-analytics .............. 0.60.8 (not running)
snips-asr .................... 0.60.8 (running)
snips-audio-server ........... 0.60.8 (running)
snips-dialogue ............... 0.60.8 (running)
snips-hotword ................ 0.60.8 (running)
snips-nlu .................... 0.60.8 (running)
snips-skill-server ........... 0.60.8 (running)
snips-tts .................... 0.60.8 (running)

respeaker@Livingroom:~$

respeaker@Livingroom:~$ sam watch
[17:23:07] Watching on ha:1883 (MQTT)
[17:23:10] [Hotword] detected on site livingroom, for model default
[17:23:10] [Asr] was asked to stop listening on site livingroom
[17:23:10] [Hotword] was asked to toggle itself 'off' on site livingroom
[17:23:10] [Dialogue] session with id 'ff7c9d05-ca93-4b8c-a07f-0298a781511b' was started on site livingroom
[17:23:10] [AudioServer] was asked to play a wav of 41.1 kB with id '384f0f0f-b7e7-43a2-b454-282b534564de' on site livingroom
[17:23:11] [AudioServer] finished playing wav with id '384f0f0f-b7e7-43a2-b454-282b534564de'
[17:23:11] [Asr] was asked to listen on site livingroom
[17:23:13] [Asr] captured text "could" in 1.0s
[17:23:13] [Asr] was asked to stop listening on site livingroom
[17:23:13] [AudioServer] was asked to play a wav of 93.1 kB with id 'e08ed8c5-54c2-432d-aeff-21ebbe2415d0' on site livingroom
[17:23:14] [AudioServer] finished playing wav with id 'e08ed8c5-54c2-432d-aeff-21ebbe2415d0'
[17:23:14] [Nlu] was asked to parse input "could"
[17:23:14] [Nlu] intent not recognized for "could"
[17:23:14] [AudioServer] was asked to play a wav of 61.1 kB with id '711d5828-64be-4cac-9a1e-70e52a464abe' on site livingroom
[17:23:15] [AudioServer] finished playing wav with id '711d5828-64be-4cac-9a1e-70e52a464abe'
[17:23:15] [Dialogue] session with id 'ff7c9d05-ca93-4b8c-a07f-0298a781511b' was ended on site livingroom. The session was ended because the platform didn't understand the user
[17:23:15] [Asr] was asked to stop listening on site livingroom
[17:23:15] [Hotword] was asked to toggle itself 'on' on site livingroom

[cpoisson]

Hey guys,

I cannot reproduce your issue on version 0.61.1 using the weather demo assistant.

If it occurs again on your side, please re-ping us on the forum.