After HotWord i get wrong and double responses

Hi Guys!

First, im really really glad and happy that you offer your time for helping me.
Everything works fine with rhasspy, except that i get the most time false responses.
After HotWord (the detects in the log comes from tv) i get the Succeed and Error
WAV played. I dont know why, first i get Finished, Sir, Finished, Sir, Sorry Sir i cant detect
your command.

If it really detects the command, it works, but 9 out of 10 Trys i get
false responses and double responses, Yes, Yes no, no. The most one was 5 Responses.
I hope everything you need for help me is in the Log. If you need more information,
just write me.

MANY THANKS.

LOG:

Jun 21 19:19:47 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:47,754] rhasspywake_porcupine_hermes: -> HotwordDetected(model_id='/usr/lib/rhasspy/usr/local/lib/python3.7/site-packages/pvporcupine/resources/keyword_files/raspberry-pi/jarvis_raspberry-pi.ppn', model_version='', model_type='personal', current_sensitivity=0.0, site_id='default', session_id=None, send_audio_captured=None, lang=None, custom_entities=None)
Jun 21 19:19:47 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:47,756] rhasspywake_porcupine_hermes: Publishing 319 bytes(s) to hermes/hotword/jarvis_raspberry-pi/detected
Jun 21 19:19:47 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:47,762] rhasspyserver_hermes: <- HotwordDetected(model_id='/usr/lib/rhasspy/usr/local/lib/python3.7/site-packages/pvporcupine/resources/keyword_files/raspberry-pi/jarvis_raspberry-pi.ppn', model_version='', model_type='personal', current_sensitivity=0.0, site_id='default', session_id=None, send_audio_captured=None, lang=None, custom_entities=None)
Jun 21 19:19:47 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:47,764] rhasspydialogue_hermes: <- HotwordDetected(model_id='/usr/lib/rhasspy/usr/local/lib/python3.7/site-packages/pvporcupine/resources/keyword_files/raspberry-pi/jarvis_raspberry-pi.ppn', model_version='', model_type='personal', current_sensitivity=0.0, site_id='default', session_id=None, send_audio_captured=None, lang=None, custom_entities=None)
Jun 21 19:19:47 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:47,771] rhasspydialogue_hermes: Playing WAV /usr/lib/rhasspy/etc/wav/jarvis_service.wav
Jun 21 19:19:47 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:47,784] rhasspydialogue_hermes: -> HotwordToggleOff(site_id='default', reason=<HotwordToggleReason.PLAY_AUDIO: 'playAudio'>)
Jun 21 19:19:47 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:47,784] rhasspydialogue_hermes: Publishing 44 bytes(s) to hermes/hotword/toggleOff
Jun 21 19:19:47 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:47,786] rhasspydialogue_hermes: -> AsrToggleOff(site_id='default', reason=<AsrToggleReason.PLAY_AUDIO: 'playAudio'>)
Jun 21 19:19:47 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:47,788] rhasspydialogue_hermes: Publishing 44 bytes(s) to hermes/asr/toggleOff
Jun 21 19:19:47 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:47,789] rhasspydialogue_hermes: -> AudioPlayBytes(262188 byte(s)) to hermes/audioServer/default/playBytes/6dffc421-a8a7-4169-8d48-1e71afb4d352
Jun 21 19:19:47 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:47,791] rhasspydialogue_hermes: Waiting for playFinished (id=6dffc421-a8a7-4169-8d48-1e71afb4d352, timeout=3.222154195011338)
Jun 21 19:19:47 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:47,797] rhasspyspeakers_cli_hermes: <- AudioPlayBytes(262188 byte(s))
Jun 21 19:19:47 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:47,798] rhasspyspeakers_cli_hermes: ['aplay', '-q', '-t', 'wav', '-D', 'sysdefault:CARD=Headphones']
Jun 21 19:19:47 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:47,835] rhasspywake_porcupine_hermes: <- HotwordToggleOff(site_id='default', reason=<HotwordToggleReason.PLAY_AUDIO: 'playAudio'>)
Jun 21 19:19:47 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:47,835] rhasspyasr_pocketsphinx_hermes: <- AsrToggleOff(site_id='default', reason=<AsrToggleReason.PLAY_AUDIO: 'playAudio'>)
Jun 21 19:19:47 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:47,835] rhasspyasr_pocketsphinx_hermes: Disabled
Jun 21 19:19:47 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:47,836] rhasspywake_porcupine_hermes: Disabled
Jun 21 19:19:49 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:49,502] rhasspyspeakers_cli_hermes: -> AudioPlayFinished(id='6dffc421-a8a7-4169-8d48-1e71afb4d352', session_id='6dffc421-a8a7-4169-8d48-1e71afb4d352')
Jun 21 19:19:49 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:49,503] rhasspyspeakers_cli_hermes: Publishing 99 bytes(s) to hermes/audioServer/default/playFinished
Jun 21 19:19:49 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:49,506] rhasspydialogue_hermes: <- AudioPlayFinished(id='6dffc421-a8a7-4169-8d48-1e71afb4d352', session_id='6dffc421-a8a7-4169-8d48-1e71afb4d352')
Jun 21 19:19:49 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:49,508] rhasspydialogue_hermes: -> HotwordToggleOn(site_id='default', reason=<HotwordToggleReason.PLAY_AUDIO: 'playAudio'>)
Jun 21 19:19:49 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:49,508] rhasspydialogue_hermes: Publishing 44 bytes(s) to hermes/hotword/toggleOn
Jun 21 19:19:49 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:49,509] rhasspytts_cli_hermes: <- AudioPlayFinished(id='6dffc421-a8a7-4169-8d48-1e71afb4d352', session_id='6dffc421-a8a7-4169-8d48-1e71afb4d352')
Jun 21 19:19:49 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:49,510] rhasspydialogue_hermes: -> AsrToggleOn(site_id='default', reason=<AsrToggleReason.PLAY_AUDIO: 'playAudio'>)
Jun 21 19:19:49 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:49,511] rhasspydialogue_hermes: Publishing 44 bytes(s) to hermes/asr/toggleOn
Jun 21 19:19:49 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:49,511] rhasspydialogue_hermes: Starting new session (id=default-jarvis_raspberry-pi-21b3dd44-bcbe-404b-bfe5-73e712069ba0)
Jun 21 19:19:49 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:49,513] rhasspydialogue_hermes: -> DialogueSessionStarted(session_id='default-jarvis_raspberry-pi-21b3dd44-bcbe-404b-bfe5-73e712069ba0', site_id='default', custom_data='jarvis_raspberry-pi', lang=None)
Jun 21 19:19:49 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:49,513] rhasspydialogue_hermes: Publishing 153 bytes(s) to hermes/dialogueManager/sessionStarted
Jun 21 19:19:49 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:49,515] rhasspydialogue_hermes: -> HotwordToggleOff(site_id='default', reason=<HotwordToggleReason.DIALOGUE_SESSION: 'dialogueSession'>)
Jun 21 19:19:49 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:49,515] rhasspydialogue_hermes: Publishing 50 bytes(s) to hermes/hotword/toggleOff
Jun 21 19:19:49 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:49,516] rhasspydialogue_hermes: Listening for session default-jarvis_raspberry-pi-21b3dd44-bcbe-404b-bfe5-73e712069ba0
Jun 21 19:19:49 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:49,518] rhasspydialogue_hermes: -> AsrStartListening(site_id='default', session_id='default-jarvis_raspberry-pi-21b3dd44-bcbe-404b-bfe5-73e712069ba0', lang=None, stop_on_silence=True, send_audio_captured=True, wakeword_id='jarvis_raspberry-pi', intent_filter=None)
Jun 21 19:19:49 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:49,518] rhasspydialogue_hermes: Publishing 225 bytes(s) to hermes/asr/startListening
Jun 21 19:19:49 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:49,524] rhasspywake_porcupine_hermes: <- HotwordToggleOn(site_id='default', reason=<HotwordToggleReason.PLAY_AUDIO: 'playAudio'>)
Jun 21 19:19:49 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:49,524] rhasspywake_porcupine_hermes: Enabled
Jun 21 19:19:49 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:49,547] rhasspywake_porcupine_hermes: Receiving audio
Jun 21 19:19:49 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:49,594] rhasspywake_porcupine_hermes: <- HotwordToggleOff(site_id='default', reason=<HotwordToggleReason.DIALOGUE_SESSION: 'dialogueSession'>)
Jun 21 19:19:49 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:49,594] rhasspywake_porcupine_hermes: Disabled
Jun 21 19:19:49 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:49,596] rhasspyasr_pocketsphinx_hermes: <- AsrToggleOn(site_id='default', reason=<AsrToggleReason.PLAY_AUDIO: 'playAudio'>)
Jun 21 19:19:49 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:49,596] rhasspyasr_pocketsphinx_hermes: Enabled
Jun 21 19:19:49 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:49,599] rhasspyasr_pocketsphinx_hermes: <- AsrStartListening(site_id='default', session_id='default-jarvis_raspberry-pi-21b3dd44-bcbe-404b-bfe5-73e712069ba0', lang=None, stop_on_silence=True, send_audio_captured=True, wakeword_id='jarvis_raspberry-pi', intent_filter=None)
Jun 21 19:19:49 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:49,605] rhasspyasr_pocketsphinx_hermes: Starting listening (session_id=default-jarvis_raspberry-pi-21b3dd44-bcbe-404b-bfe5-73e712069ba0)
Jun 21 19:19:49 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:49,613] rhasspyasr_pocketsphinx_hermes: Receiving audio
Jun 21 19:19:52 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:52,357] rhasspyasr_pocketsphinx_hermes: Voice command recorded for session default-jarvis_raspberry-pi-21b3dd44-bcbe-404b-bfe5-73e712069ba0 (86400 byte(s))
Jun 21 19:19:52 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:52,359] rhasspyasr_pocketsphinx_hermes: -> AsrRecordingFinished(site_id='default', session_id='default-jarvis_raspberry-pi-21b3dd44-bcbe-404b-bfe5-73e712069ba0')
Jun 21 19:19:52 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:52,359] rhasspyasr_pocketsphinx_hermes: Publishing 102 bytes(s) to rhasspy/asr/recordingFinished
Jun 21 19:19:52 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:52,361] rhasspyasr_pocketsphinx_hermes: Transcribing 86444 byte(s) of audio data
Jun 21 19:19:52 raspsrv rhasspy[620]: INFO: cmn.c(133): CMN: 37.10  7.39  0.96  4.42 12.66 16.08  4.91  1.40 -10.48 -14.78 -11.20  1.18  0.53
Jun 21 19:19:52 raspsrv rhasspy[620]: INFO: ngram_search_fwdtree.c(1550):     2735 words recognized (10/fr)
Jun 21 19:19:52 raspsrv rhasspy[620]: INFO: ngram_search_fwdtree.c(1552):   129289 senones evaluated (479/fr)
Jun 21 19:19:52 raspsrv rhasspy[620]: INFO: ngram_search_fwdtree.c(1556):    71180 channels searched (263/fr), 5852 1st, 52476 last
Jun 21 19:19:52 raspsrv rhasspy[620]: INFO: ngram_search_fwdtree.c(1559):     3394 words for which last channels evaluated (12/fr)
Jun 21 19:19:52 raspsrv rhasspy[620]: INFO: ngram_search_fwdtree.c(1561):     2839 candidate words for entering last phone (10/fr)
Jun 21 19:19:52 raspsrv rhasspy[620]: INFO: ngram_search_fwdtree.c(1564): fwdtree 0.53 CPU 0.196 xRT
Jun 21 19:19:52 raspsrv rhasspy[620]: INFO: ngram_search_fwdtree.c(1567): fwdtree 0.54 wall 0.199 xRT
Jun 21 19:19:52 raspsrv rhasspy[620]: INFO: ngram_search_fwdflat.c(302): Utterance vocabulary contains 24 words
Jun 21 19:19:53 raspsrv rhasspy[620]: INFO: ngram_search_fwdflat.c(948):     2707 words recognized (10/fr)
Jun 21 19:19:53 raspsrv rhasspy[620]: INFO: ngram_search_fwdflat.c(950):   172795 senones evaluated (640/fr)
Jun 21 19:19:53 raspsrv rhasspy[620]: INFO: ngram_search_fwdflat.c(952):   110926 channels searched (410/fr)
Jun 21 19:19:53 raspsrv rhasspy[620]: INFO: ngram_search_fwdflat.c(954):     5452 words searched (20/fr)
Jun 21 19:19:53 raspsrv rhasspy[620]: INFO: ngram_search_fwdflat.c(957):     3483 word transitions (12/fr)
Jun 21 19:19:53 raspsrv rhasspy[620]: INFO: ngram_search_fwdflat.c(960): fwdflat 0.50 CPU 0.185 xRT
Jun 21 19:19:53 raspsrv rhasspy[620]: INFO: ngram_search_fwdflat.c(963): fwdflat 0.50 wall 0.186 xRT
Jun 21 19:19:53 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:53,421] rhasspyasr_pocketsphinx.transcribe: Decoded audio in 1.0582732259936165 second(s)
Jun 21 19:19:53 raspsrv rhasspy[620]: INFO: ngram_search.c(1250): lattice start node <s>.0 end node </s>.260
Jun 21 19:19:53 raspsrv rhasspy[620]: INFO: ngram_search.c(1276): Eliminated 0 nodes before end node
Jun 21 19:19:53 raspsrv rhasspy[620]: INFO: ngram_search.c(1381): Lattice has 244 nodes, 798 links
Jun 21 19:19:53 raspsrv rhasspy[620]: INFO: ps_lattice.c(1374): Bestpath score: -12749
Jun 21 19:19:53 raspsrv rhasspy[620]: INFO: ps_lattice.c(1378): Normalizer P(O) = alpha(</s>:260:268) = -736830
Jun 21 19:19:53 raspsrv rhasspy[620]: INFO: ps_lattice.c(1435): Joint P(O,S) = -855723 P(S|O) = -118893
Jun 21 19:19:53 raspsrv rhasspy[620]: INFO: ngram_search.c(872): bestpath 0.00 CPU 0.001 xRT
Jun 21 19:19:53 raspsrv rhasspy[620]: INFO: ngram_search.c(875): bestpath 0.00 wall 0.001 xRT
Jun 21 19:19:53 raspsrv rhasspy[620]: INFO: ngram_search.c(1027): bestpath 0.00 CPU 0.000 xRT
Jun 21 19:19:53 raspsrv rhasspy[620]: INFO: ngram_search.c(1030): bestpath 0.00 wall 0.000 xRT
Jun 21 19:19:53 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:53,434] rhasspyasr_pocketsphinx_hermes: Transcription(text='auf offen offen das die sperr und', likelihood=6.8539990039905566e-06, transcribe_seconds=1.0582732259936165, wav_seconds=2.7, tokens=[TranscriptionToken(token='<s>', start_time=0.0, end_time=0.33, likelihood=1.0002000431911853), TranscriptionToken(token='auf', start_time=0.34, end_time=0.79, likelihood=0.011480356949794334), TranscriptionToken(token='offen', start_time=0.8, end_time=1.04, likelihood=0.0031946873089012976), TranscriptionToken(token='offen', start_time=1.05, end_time=1.3, likelihood=0.015216344405378442), TranscriptionToken(token='das', start_time=1.31, end_time=1.48, likelihood=0.22069466455639578), TranscriptionToken(token='<sil>', start_time=1.49, end_time=1.76, likelihood=0.3320307157917459), TranscriptionToken(token='die', start_time=1.77, end_time=2.0, likelihood=0.8014556402008576), TranscriptionToken(token='sperr', start_time=2.01, end_time=2.28, likelihood=0.7213449225331319), TranscriptionToken(token='und', start_time=2.29, end_time=2.59, likelihood=0.1393692461666324), TranscriptionToken(token='</s>', start_time=2.6, end_time=2.68, likelihood=1.0)])
Jun 21 19:19:53 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:53,444] rhasspyasr_pocketsphinx_hermes: -> AsrTextCaptured(text='auf offen offen das die sperr und', likelihood=6.8539990039905566e-06, seconds=1.0582732259936165, site_id='default', session_id='default-jarvis_raspberry-pi-21b3dd44-bcbe-404b-bfe5-73e712069ba0', wakeword_id=None, asr_tokens=[[AsrToken(value='<s>', confidence=1.0002000431911853, range_start=0, range_end=4, time=AsrTokenTime(start=0.0, end=0.33)), AsrToken(value='auf', confidence=0.011480356949794334, range_start=4, range_end=8, time=AsrTokenTime(start=0.34, end=0.79)), AsrToken(value='offen', confidence=0.0031946873089012976, range_start=8, range_end=14, time=AsrTokenTime(start=0.8, end=1.04)), AsrToken(value='offen', confidence=0.015216344405378442, range_start=14, range_end=20, time=AsrTokenTime(start=1.05, end=1.3)), AsrToken(value='das', confidence=0.22069466455639578, range_start=20, range_end=24, time=AsrTokenTime(start=1.31, end=1.48)), AsrToken(value='<sil>', confidence=0.3320307157917459, range_start=24, range_end=30, time=AsrTokenTime(start=1.49, end=1.76)), AsrToken(value='die', confidence=0.8014556402008576, range_start=30, range_end=34, time=AsrTokenTime(start=1.77, end=2.0)), AsrToken(value='sperr', confidence=0.7213449225331319, range_start=34, range_end=40, time=AsrTokenTime(start=2.01, end=2.28)), AsrToken(value='und', confidence=0.1393692461666324, range_start=40, range_end=44, time=AsrTokenTime(start=2.29, end=2.59)), AsrToken(value='</s>', confidence=1.0, range_start=44, range_end=49, time=AsrTokenTime(start=2.6, end=2.68))]], lang=None)
Jun 21 19:19:53 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:53,444] rhasspyasr_pocketsphinx_hermes: Publishing 1499 bytes(s) to hermes/asr/textCaptured
Jun 21 19:19:53 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:53,445] rhasspyasr_pocketsphinx_hermes: -> AsrAudioCaptured(86444 byte(s)) to rhasspy/asr/default/default/audioCaptured
Jun 21 19:19:53 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:53,466] rhasspydialogue_hermes: <- AsrTextCaptured(text='auf offen offen das die sperr und', likelihood=6.8539990039905566e-06, seconds=1.0582732259936165, site_id='default', session_id='default-jarvis_raspberry-pi-21b3dd44-bcbe-404b-bfe5-73e712069ba0', wakeword_id=None, asr_tokens=[[AsrToken(value='<s>', confidence=1.0002000431911853, range_start=0, range_end=4, time=AsrTokenTime(start=0.0, end=0.33)), AsrToken(value='auf', confidence=0.011480356949794334, range_start=4, range_end=8, time=AsrTokenTime(start=0.34, end=0.79)), AsrToken(value='offen', confidence=0.0031946873089012976, range_start=8, range_end=14, time=AsrTokenTime(start=0.8, end=1.04)), AsrToken(value='offen', confidence=0.015216344405378442, range_start=14, range_end=20, time=AsrTokenTime(start=1.05, end=1.3)), AsrToken(value='das', confidence=0.22069466455639578, range_start=20, range_end=24, time=AsrTokenTime(start=1.31, end=1.48)), AsrToken(value='<sil>', confidence=0.3320307157917459, range_start=24, range_end=30, time=AsrTokenTime(start=1.49, end=1.76)), AsrToken(value='die', confidence=0.8014556402008576, range_start=30, range_end=34, time=AsrTokenTime(start=1.77, end=2.0)), AsrToken(value='sperr', confidence=0.7213449225331319, range_start=34, range_end=40, time=AsrTokenTime(start=2.01, end=2.28)), AsrToken(value='und', confidence=0.1393692461666324, range_start=40, range_end=44, time=AsrTokenTime(start=2.29, end=2.59)), AsrToken(value='</s>', confidence=1.0, range_start=44, range_end=49, time=AsrTokenTime(start=2.6, end=2.68))]], lang=None)
Jun 21 19:19:53 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:53,467] rhasspydialogue_hermes: Playing WAV /usr/lib/rhasspy/etc/wav/jarvis_confirmed.wav
Jun 21 19:19:53 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:53,473] rhasspydialogue_hermes: -> HotwordToggleOff(site_id='default', reason=<HotwordToggleReason.PLAY_AUDIO: 'playAudio'>)
Jun 21 19:19:53 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:53,473] rhasspydialogue_hermes: Publishing 44 bytes(s) to hermes/hotword/toggleOff
Jun 21 19:19:53 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:53,475] rhasspydialogue_hermes: -> AsrToggleOff(site_id='default', reason=<AsrToggleReason.PLAY_AUDIO: 'playAudio'>)
Jun 21 19:19:53 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:53,475] rhasspydialogue_hermes: Publishing 44 bytes(s) to hermes/asr/toggleOff
Jun 21 19:19:53 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:53,476] rhasspydialogue_hermes: -> AudioPlayBytes(131116 byte(s)) to hermes/audioServer/default/playBytes/c53c87af-a44a-4dd5-a979-4a9049e8103e
Jun 21 19:19:53 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:53,477] rhasspydialogue_hermes: Waiting for playFinished (id=c53c87af-a44a-4dd5-a979-4a9049e8103e, timeout=1.736077097505669)
Jun 21 19:19:53 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:53,479] rhasspyspeakers_cli_hermes: <- AudioPlayBytes(131116 byte(s))
Jun 21 19:19:53 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:53,480] rhasspyspeakers_cli_hermes: ['aplay', '-q', '-t', 'wav', '-D', 'sysdefault:CARD=Headphones']
Jun 21 19:19:53 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:53,514] rhasspyasr_pocketsphinx_hermes: <- AsrToggleOff(site_id='default', reason=<AsrToggleReason.PLAY_AUDIO: 'playAudio'>)
Jun 21 19:19:53 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:53,514] rhasspyasr_pocketsphinx_hermes: Disabled
Jun 21 19:19:53 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:53,514] rhasspywake_porcupine_hermes: <- HotwordToggleOff(site_id='default', reason=<HotwordToggleReason.PLAY_AUDIO: 'playAudio'>)
Jun 21 19:19:53 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:53,514] rhasspywake_porcupine_hermes: Disabled
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,272] rhasspyspeakers_cli_hermes: -> AudioPlayFinished(id='c53c87af-a44a-4dd5-a979-4a9049e8103e', session_id='c53c87af-a44a-4dd5-a979-4a9049e8103e')
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,272] rhasspyspeakers_cli_hermes: Publishing 99 bytes(s) to hermes/audioServer/default/playFinished
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,275] rhasspydialogue_hermes: <- AudioPlayFinished(id='c53c87af-a44a-4dd5-a979-4a9049e8103e', session_id='c53c87af-a44a-4dd5-a979-4a9049e8103e')
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,275] rhasspytts_cli_hermes: <- AudioPlayFinished(id='c53c87af-a44a-4dd5-a979-4a9049e8103e', session_id='c53c87af-a44a-4dd5-a979-4a9049e8103e')
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,277] rhasspydialogue_hermes: -> HotwordToggleOn(site_id='default', reason=<HotwordToggleReason.PLAY_AUDIO: 'playAudio'>)
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,277] rhasspydialogue_hermes: Publishing 44 bytes(s) to hermes/hotword/toggleOn
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,279] rhasspydialogue_hermes: -> AsrToggleOn(site_id='default', reason=<AsrToggleReason.PLAY_AUDIO: 'playAudio'>)
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,279] rhasspydialogue_hermes: Publishing 44 bytes(s) to hermes/asr/toggleOn
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,280] rhasspydialogue_hermes: Received text: auf offen offen das die sperr und
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,282] rhasspydialogue_hermes: -> AsrStopListening(site_id='default', session_id='default-jarvis_raspberry-pi-21b3dd44-bcbe-404b-bfe5-73e712069ba0')
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,282] rhasspydialogue_hermes: Publishing 102 bytes(s) to hermes/asr/stopListening
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,284] rhasspydialogue_hermes: -> HotwordToggleOn(site_id='default', reason=<HotwordToggleReason.DIALOGUE_SESSION: 'dialogueSession'>)
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,285] rhasspydialogue_hermes: Publishing 50 bytes(s) to hermes/hotword/toggleOn
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,287] rhasspydialogue_hermes: -> NluQuery(input='auf offen offen das die sperr und', site_id='default', id=None, intent_filter=None, session_id='default-jarvis_raspberry-pi-21b3dd44-bcbe-404b-bfe5-73e712069ba0', wakeword_id='jarvis_raspberry-pi', lang=None, custom_data='jarvis_raspberry-pi', asr_confidence=6.8539990039905566e-06, custom_entities=None)
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,287] rhasspydialogue_hermes: Publishing 335 bytes(s) to hermes/nlu/query
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,293] rhasspynlu_hermes: <- NluQuery(input='auf offen offen das die sperr und', site_id='default', id=None, intent_filter=None, session_id='default-jarvis_raspberry-pi-21b3dd44-bcbe-404b-bfe5-73e712069ba0', wakeword_id='jarvis_raspberry-pi', lang=None, custom_data='jarvis_raspberry-pi', asr_confidence=6.8539990039905566e-06, custom_entities=None)
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,295] rhasspywake_porcupine_hermes: <- HotwordToggleOn(site_id='default', reason=<HotwordToggleReason.PLAY_AUDIO: 'playAudio'>)
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,295] rhasspywake_porcupine_hermes: Still disabled: {<HotwordToggleReason.DIALOGUE_SESSION: 'dialogueSession'>}
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,296] rhasspynlu_hermes: -> NluIntentNotRecognized(input='auf offen offen das die sperr und', site_id='default', id=None, custom_data='jarvis_raspberry-pi', session_id='default-jarvis_raspberry-pi-21b3dd44-bcbe-404b-bfe5-73e712069ba0')
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,296] rhasspywake_porcupine_hermes: <- HotwordToggleOn(site_id='default', reason=<HotwordToggleReason.DIALOGUE_SESSION: 'dialogueSession'>)
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,297] rhasspywake_porcupine_hermes: Enabled
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,296] rhasspynlu_hermes: Publishing 197 bytes(s) to hermes/nlu/intentNotRecognized
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,299] rhasspyserver_hermes: <- NluIntentNotRecognized(input='auf offen offen das die sperr und', site_id='default', id=None, custom_data='jarvis_raspberry-pi', session_id='default-jarvis_raspberry-pi-21b3dd44-bcbe-404b-bfe5-73e712069ba0')
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,301] rhasspyasr_pocketsphinx_hermes: <- AsrToggleOn(site_id='default', reason=<AsrToggleReason.PLAY_AUDIO: 'playAudio'>)
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,301] rhasspyasr_pocketsphinx_hermes: Enabled
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,301] rhasspydialogue_hermes: <- NluIntentNotRecognized(input='auf offen offen das die sperr und', site_id='default', id=None, custom_data='jarvis_raspberry-pi', session_id='default-jarvis_raspberry-pi-21b3dd44-bcbe-404b-bfe5-73e712069ba0')
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,303] rhasspyasr_pocketsphinx_hermes: <- AsrStopListening(site_id='default', session_id='default-jarvis_raspberry-pi-21b3dd44-bcbe-404b-bfe5-73e712069ba0')
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,303] rhasspyasr_pocketsphinx_hermes: Received a total of 125520 byte(s) for WAV data for session default-jarvis_raspberry-pi-21b3dd44-bcbe-404b-bfe5-73e712069ba0
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,303] rhasspyasr_pocketsphinx_hermes: Stopping listening (session_id=default-jarvis_raspberry-pi-21b3dd44-bcbe-404b-bfe5-73e712069ba0)
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,303] rhasspydialogue_hermes: Playing WAV /usr/lib/rhasspy/etc/wav/jarvis_error.wav
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,317] rhasspyasr_pocketsphinx_hermes: Receiving audio
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,316] rhasspywake_porcupine_hermes: Receiving audio
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,322] rhasspydialogue_hermes: -> HotwordToggleOff(site_id='default', reason=<HotwordToggleReason.PLAY_AUDIO: 'playAudio'>)
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,323] rhasspydialogue_hermes: Publishing 44 bytes(s) to hermes/hotword/toggleOff
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,325] rhasspydialogue_hermes: -> AsrToggleOff(site_id='default', reason=<AsrToggleReason.PLAY_AUDIO: 'playAudio'>)
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,326] rhasspydialogue_hermes: Publishing 44 bytes(s) to hermes/asr/toggleOff
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,327] rhasspydialogue_hermes: -> AudioPlayBytes(524332 byte(s)) to hermes/audioServer/default/playBytes/80bc1718-7764-4438-8b96-0d959aa7a45b
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,330] rhasspydialogue_hermes: Waiting for playFinished (id=80bc1718-7764-4438-8b96-0d959aa7a45b, timeout=6.194308390022676)
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,341] rhasspyspeakers_cli_hermes: <- AudioPlayBytes(524332 byte(s))
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,342] rhasspyspeakers_cli_hermes: ['aplay', '-q', '-t', 'wav', '-D', 'sysdefault:CARD=Headphones']
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,364] rhasspyasr_pocketsphinx_hermes: <- AsrToggleOff(site_id='default', reason=<AsrToggleReason.PLAY_AUDIO: 'playAudio'>)
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,365] rhasspyasr_pocketsphinx_hermes: Disabled
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,366] rhasspywake_porcupine_hermes: <- HotwordToggleOff(site_id='default', reason=<HotwordToggleReason.PLAY_AUDIO: 'playAudio'>)
Jun 21 19:19:54 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:54,366] rhasspywake_porcupine_hermes: Disabled
Jun 21 19:19:57 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:57,382] rhasspyspeakers_cli_hermes: -> AudioPlayFinished(id='80bc1718-7764-4438-8b96-0d959aa7a45b', session_id='80bc1718-7764-4438-8b96-0d959aa7a45b')
Jun 21 19:19:57 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:57,382] rhasspyspeakers_cli_hermes: Publishing 99 bytes(s) to hermes/audioServer/default/playFinished
Jun 21 19:19:57 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:57,385] rhasspydialogue_hermes: <- AudioPlayFinished(id='80bc1718-7764-4438-8b96-0d959aa7a45b', session_id='80bc1718-7764-4438-8b96-0d959aa7a45b')
Jun 21 19:19:57 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:57,385] rhasspytts_cli_hermes: <- AudioPlayFinished(id='80bc1718-7764-4438-8b96-0d959aa7a45b', session_id='80bc1718-7764-4438-8b96-0d959aa7a45b')
Jun 21 19:19:57 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:57,387] rhasspydialogue_hermes: -> HotwordToggleOn(site_id='default', reason=<HotwordToggleReason.PLAY_AUDIO: 'playAudio'>)
Jun 21 19:19:57 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:57,387] rhasspydialogue_hermes: Publishing 44 bytes(s) to hermes/hotword/toggleOn
Jun 21 19:19:57 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:57,389] rhasspydialogue_hermes: -> AsrToggleOn(site_id='default', reason=<AsrToggleReason.PLAY_AUDIO: 'playAudio'>)
Jun 21 19:19:57 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:57,389] rhasspydialogue_hermes: Publishing 44 bytes(s) to hermes/asr/toggleOn
Jun 21 19:19:57 raspsrv rhasspy[620]: [WARNING:2021-06-21 19:19:57,389] rhasspydialogue_hermes: No intent recognized (site_id=default, session_id=default-jarvis_raspberry-pi-21b3dd44-bcbe-404b-bfe5-73e712069ba0)
Jun 21 19:19:57 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:57,391] rhasspydialogue_hermes: -> AsrStopListening(site_id='default', session_id='default-jarvis_raspberry-pi-21b3dd44-bcbe-404b-bfe5-73e712069ba0')
Jun 21 19:19:57 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:57,391] rhasspydialogue_hermes: Publishing 102 bytes(s) to hermes/asr/stopListening
Jun 21 19:19:57 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:57,393] rhasspywake_porcupine_hermes: <- HotwordToggleOn(site_id='default', reason=<HotwordToggleReason.PLAY_AUDIO: 'playAudio'>)
Jun 21 19:19:57 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:57,393] rhasspywake_porcupine_hermes: Enabled
Jun 21 19:19:57 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:57,393] rhasspydialogue_hermes: -> DialogueSessionEnded(termination=DialogueSessionTermination(reason=<DialogueSessionTerminationReason.INTENT_NOT_RECOGNIZED: 'intentNotRecognized'>), session_id='default-jarvis_raspberry-pi-21b3dd44-bcbe-404b-bfe5-73e712069ba0', site_id='default', custom_data='jarvis_raspberry-pi')
Jun 21 19:19:57 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:57,395] rhasspyasr_pocketsphinx_hermes: <- AsrToggleOn(site_id='default', reason=<AsrToggleReason.PLAY_AUDIO: 'playAudio'>)
Jun 21 19:19:57 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:57,395] rhasspydialogue_hermes: Publishing 189 bytes(s) to hermes/dialogueManager/sessionEnded
Jun 21 19:19:57 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:57,396] rhasspyasr_pocketsphinx_hermes: Enabled
Jun 21 19:19:57 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:57,396] rhasspydialogue_hermes: -> HotwordToggleOn(site_id='default', reason=<HotwordToggleReason.DIALOGUE_SESSION: 'dialogueSession'>)
Jun 21 19:19:57 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:57,397] rhasspydialogue_hermes: Publishing 50 bytes(s) to hermes/hotword/toggleOn
Jun 21 19:19:57 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:57,399] rhasspyasr_pocketsphinx_hermes: <- AsrStopListening(site_id='default', session_id='default-jarvis_raspberry-pi-21b3dd44-bcbe-404b-bfe5-73e712069ba0')
Jun 21 19:19:57 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:57,399] rhasspyasr_pocketsphinx_hermes: Stopping listening (session_id=default-jarvis_raspberry-pi-21b3dd44-bcbe-404b-bfe5-73e712069ba0)
Jun 21 19:19:57 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:57,399] rhasspywake_porcupine_hermes: <- HotwordToggleOn(site_id='default', reason=<HotwordToggleReason.DIALOGUE_SESSION: 'dialogueSession'>)
Jun 21 19:19:57 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:57,399] rhasspywake_porcupine_hermes: Enabled
Jun 21 19:19:57 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:57,409] rhasspyasr_pocketsphinx_hermes: Receiving audio
Jun 21 19:19:57 raspsrv rhasspy[620]: [DEBUG:2021-06-21 19:19:57,409] rhasspywake_porcupine_hermes: Receiving audio

Maybe its useful, 3 minutes after i got this lines also in syslog:

Jun 21 19:22:05 raspsrv rngd[948]: stats: bits received from HRNG source: 740064
Jun 21 19:22:05 raspsrv rngd[948]: stats: bits sent to kernel pool: 692800
Jun 21 19:22:05 raspsrv rngd[948]: stats: entropy added to kernel pool: 692800
Jun 21 19:22:05 raspsrv rngd[948]: stats: FIPS 140-2 successes: 37
Jun 21 19:22:05 raspsrv rngd[948]: stats: FIPS 140-2 failures: 0
Jun 21 19:22:05 raspsrv rngd[948]: stats: FIPS 140-2(2001-10-10) Monobit: 0
Jun 21 19:22:05 raspsrv rngd[948]: stats: FIPS 140-2(2001-10-10) Poker: 0
Jun 21 19:22:05 raspsrv rngd[948]: stats: FIPS 140-2(2001-10-10) Runs: 0
Jun 21 19:22:05 raspsrv rngd[948]: stats: FIPS 140-2(2001-10-10) Long run: 0
Jun 21 19:22:05 raspsrv rngd[948]: stats: FIPS 140-2(2001-10-10) Continuous run: 0
Jun 21 19:22:05 raspsrv rngd[948]: stats: HRNG source speed: (min=76.015; avg=494.733; max=723.246)Kibits/s
Jun 21 19:22:05 raspsrv rngd[948]: stats: FIPS tests speed: (min=12.329; avg=34.752; max=41.828)Mibits/s
Jun 21 19:22:05 raspsrv rngd[948]: stats: Lowest ready-buffers level: 2
Jun 21 19:22:05 raspsrv rngd[948]: stats: Entropy starvations: 0
Jun 21 19:22:05 raspsrv rngd[948]: stats: Time spent starving for entropy: (min=0; avg=0.000; max=0)us


Nobody has Ideas for me?

Only thing I can think off: you have more than 1 Rhasspy connected somehow

Workaround:

Just use the Docker Image, its all there and you
dont have to struggle through every step yourself

Thanks regardless,
Topic can be closed.

Advise for all others:
USE DOCKER, there is no recognizable
overhead and it works as expected.

Ps: Maybe add in the Tutorial:
If homeassistant is on the same machine,
use external IP because localhost is the
docker machine itself.

Greets
Ricardo

1 Like