Hi all. It’s me again =)
I have cheked logs right from docker container… Below is the line showing starting of playing beep_hi sound
[DEBUG:2020-11-23 13:41:42,602] rhasspydialogue_hermes: -> AudioPlayBytes(83948 byte(s)) to hermes/audioServer/default/playBytes/5b2cec16-f76e-4bc8-beaa-382a646d3081
But it has been finished after ~5 secs. Even after rhasspyasr_kaldi_hermes: -> AsrRecordingFinished
[DEBUG:2020-11-23 13:41:48,150] rhasspyspeakers_cli_hermes: -> AudioPlayFinished(id='5b2cec16-f76e-4bc8-beaa-382a646d3081', session_id='5b2cec16-f76e-4bc8-beaa-382a646d3081')
Below is the full log showing all details. @fastjack, @synesthesiam do you have any ideas? I still can’t solve this issue
[DEBUG:2020-11-23 13:41:41,948] rhasspywake_snowboy_hermes: Wake word detected: snowboy (site_id=default)
[DEBUG:2020-11-23 13:41:42,643] rhasspyasr_kaldi_hermes: <- AsrToggleOff(site_id='default', reason=<AsrToggleReason.PLAY_AUDIO: 'playAudio'>)
[DEBUG:2020-11-23 13:41:42,644] rhasspyasr_kaldi_hermes: Disabled (AsrToggleReason.PLAY_AUDIO)
[DEBUG:2020-11-23 13:41:42,374] rhasspydialogue_hermes: <- HotwordDetected(model_id='snowboy', model_version='', model_type='personal', current_sensitivity=0.5, site_id='default', session_id=None, send_audio_captured=None, lang=None)
[DEBUG:2020-11-23 13:41:42,504] rhasspydialogue_hermes: Playing WAV /usr/lib/rhasspy/etc/wav/beep_hi.wav
[DEBUG:2020-11-23 13:41:42,597] rhasspydialogue_hermes: -> HotwordToggleOff(site_id='default', reason=<HotwordToggleReason.PLAY_AUDIO: 'playAudio'>)
[DEBUG:2020-11-23 13:41:42,598] rhasspydialogue_hermes: Publishing 44 bytes(s) to hermes/hotword/toggleOff
[DEBUG:2020-11-23 13:41:42,601] rhasspydialogue_hermes: -> AsrToggleOff(site_id='default', reason=<AsrToggleReason.PLAY_AUDIO: 'playAudio'>)
[DEBUG:2020-11-23 13:41:42,601] rhasspydialogue_hermes: Publishing 44 bytes(s) to hermes/asr/toggleOff
[DEBUG:2020-11-23 13:41:42,602] rhasspydialogue_hermes: -> AudioPlayBytes(83948 byte(s)) to hermes/audioServer/default/playBytes/5b2cec16-f76e-4bc8-beaa-382a646d3081
[DEBUG:2020-11-23 13:41:42,605] rhasspydialogue_hermes: Waiting for playFinished (id=5b2cec16-f76e-4bc8-beaa-382a646d3081, timeout=1.2012925170068027)
[DEBUG:2020-11-23 13:41:42,262] rhasspywake_snowboy_hermes: -> HotwordDetected(model_id='snowboy', model_version='', model_type='personal', current_sensitivity=0.5, site_id='default', session_id=None, send_audio_captured=None, lang=None)
[DEBUG:2020-11-23 13:41:42,262] rhasspywake_snowboy_hermes: Publishing 175 bytes(s) to hermes/hotword/snowboy/detected
[DEBUG:2020-11-23 13:41:42,643] rhasspywake_snowboy_hermes: <- HotwordToggleOff(site_id='default', reason=<HotwordToggleReason.PLAY_AUDIO: 'playAudio'>)
[DEBUG:2020-11-23 13:41:42,644] rhasspywake_snowboy_hermes: Disabled
[DEBUG:2020-11-23 13:41:42,611] rhasspyspeakers_cli_hermes: <- AudioPlayBytes(83948 byte(s))
[DEBUG:2020-11-23 13:41:42,612] rhasspyspeakers_cli_hermes: ['aplay', '-q', '-t', 'wav', '-D', 'hw:CARD=Headphones,DEV=0']
[WARNING:2020-11-23 13:41:43,809] rhasspydialogue_hermes: Did not receive sayFinished before timeout
[DEBUG:2020-11-23 13:41:43,811] rhasspydialogue_hermes: -> HotwordToggleOn(site_id='default', reason=<HotwordToggleReason.PLAY_AUDIO: 'playAudio'>)
[DEBUG:2020-11-23 13:41:43,812] rhasspydialogue_hermes: Publishing 44 bytes(s) to hermes/hotword/toggleOn
[DEBUG:2020-11-23 13:41:43,815] rhasspydialogue_hermes: -> AsrToggleOn(site_id='default', reason=<AsrToggleReason.PLAY_AUDIO: 'playAudio'>)
[DEBUG:2020-11-23 13:41:43,815] rhasspydialogue_hermes: Publishing 44 bytes(s) to hermes/asr/toggleOn
[DEBUG:2020-11-23 13:41:43,817] rhasspywake_snowboy_hermes: <- HotwordToggleOn(site_id='default', reason=<HotwordToggleReason.PLAY_AUDIO: 'playAudio'>)
[DEBUG:2020-11-23 13:41:43,817] rhasspywake_snowboy_hermes: Enabled
[WARNING:2020-11-23 13:41:43,819] rhasspydialogue_hermes: No session for id default-snowboy-1bc4b514-d5b9-487e-8999-0f104a58f0c8
[DEBUG:2020-11-23 13:41:43,819] rhasspydialogue_hermes: Handling queued session
[DEBUG:2020-11-23 13:41:43,820] rhasspydialogue_hermes: Session aborted: default-snowboy-1bc4b514-d5b9-487e-8999-0f104a58f0c8
[WARNING:2020-11-23 13:41:43,820] rhasspydialogue_hermes: No session for id default-snowboy-1bc4b514-d5b9-487e-8999-0f104a58f0c8
[DEBUG:2020-11-23 13:41:43,824] rhasspyasr_kaldi_hermes: <- AsrToggleOn(site_id='default', reason=<AsrToggleReason.PLAY_AUDIO: 'playAudio'>)
[DEBUG:2020-11-23 13:41:43,822] rhasspydialogue_hermes: -> HotwordToggleOn(site_id='default', reason=<HotwordToggleReason.DIALOGUE_SESSION: 'dialogueSession'>)
[DEBUG:2020-11-23 13:41:43,823] rhasspydialogue_hermes: Publishing 50 bytes(s) to hermes/hotword/toggleOn
[DEBUG:2020-11-23 13:41:43,824] rhasspydialogue_hermes: Starting new session (id=default-snowboy-b39e3665-c879-4ed5-bf4c-d2b62a4cbe66)
[DEBUG:2020-11-23 13:41:43,825] rhasspyasr_kaldi_hermes: Enabled
[DEBUG:2020-11-23 13:41:43,826] rhasspydialogue_hermes: -> DialogueSessionStarted(session_id='default-snowboy-b39e3665-c879-4ed5-bf4c-d2b62a4cbe66', site_id='default', custom_data='snowboy', lang=None)
[DEBUG:2020-11-23 13:41:43,827] rhasspydialogue_hermes: Publishing 129 bytes(s) to hermes/dialogueManager/sessionStarted
[DEBUG:2020-11-23 13:41:43,841] rhasspyasr_kaldi_hermes: <- AsrStartListening(site_id='default', session_id='default-snowboy-b39e3665-c879-4ed5-bf4c-d2b62a4cbe66', lang=None, stop_on_silence=True, send_audio_captured=True, wakeword_id='snowboy', intent_filter=None)
[DEBUG:2020-11-23 13:41:43,842] rhasspyasr_kaldi_hermes: Creating new transcriber session default-snowboy-b39e3665-c879-4ed5-bf4c-d2b62a4cbe66
[DEBUG:2020-11-23 13:41:43,843] rhasspyasr_kaldi.transcribe: Using kaldi at /usr/lib/rhasspy/.venv/lib/kaldi
[DEBUG:2020-11-23 13:41:43,830] rhasspydialogue_hermes: -> HotwordToggleOff(site_id='default', reason=<HotwordToggleReason.DIALOGUE_SESSION: 'dialogueSession'>)
[DEBUG:2020-11-23 13:41:43,832] rhasspydialogue_hermes: Publishing 50 bytes(s) to hermes/hotword/toggleOff
[DEBUG:2020-11-23 13:41:43,833] rhasspydialogue_hermes: Listening for session default-snowboy-b39e3665-c879-4ed5-bf4c-d2b62a4cbe66
[DEBUG:2020-11-23 13:41:43,835] rhasspydialogue_hermes: -> AsrStartListening(site_id='default', session_id='default-snowboy-b39e3665-c879-4ed5-bf4c-d2b62a4cbe66', lang=None, stop_on_silence=True, send_audio_captured=True, wakeword_id='snowboy', intent_filter=None)
[DEBUG:2020-11-23 13:41:43,835] rhasspydialogue_hermes: Publishing 201 bytes(s) to hermes/asr/startListening
[DEBUG:2020-11-23 13:41:43,831] rhasspywake_snowboy_hermes: <- HotwordToggleOn(site_id='default', reason=<HotwordToggleReason.DIALOGUE_SESSION: 'dialogueSession'>)
[DEBUG:2020-11-23 13:41:43,831] rhasspywake_snowboy_hermes: Enabled
[DEBUG:2020-11-23 13:41:43,835] rhasspywake_snowboy_hermes: <- HotwordToggleOff(site_id='default', reason=<HotwordToggleReason.DIALOGUE_SESSION: 'dialogueSession'>)
[DEBUG:2020-11-23 13:41:43,836] rhasspywake_snowboy_hermes: Disabled
[DEBUG:2020-11-23 13:41:43,880] rhasspyasr_kaldi.transcribe: ['/usr/lib/rhasspy/.venv/lib/kaldi/online2-tcp-nnet3-decode-faster', '--port-num=52684', '--config=/profiles/en/kaldi/model/online/conf/online.conf', '--frame-subsampling-factor=3', '--max-active=7000', '--lattice-beam=8.0', '--acoustic-scale=1.0', '--beam=24.0', '/profiles/en/kaldi/model/model/final.mdl', '/profiles/en/kaldi/model/graph/HCLG.fst', '/profiles/en/kaldi/model/graph/words.txt']
[DEBUG:2020-11-23 13:41:43,881] rhasspyasr_kaldi_hermes: Starting listening (session_id=default-snowboy-b39e3665-c879-4ed5-bf4c-d2b62a4cbe66)
[DEBUG:2020-11-23 13:41:43,961] rhasspyasr_kaldi_hermes: Receiving audio
[DEBUG:2020-11-23 13:41:45,264] rhasspyasr_kaldi_hermes: -> AsrRecordingFinished(site_id='default', session_id='default-snowboy-b39e3665-c879-4ed5-bf4c-d2b62a4cbe66')
[DEBUG:2020-11-23 13:41:45,264] rhasspyasr_kaldi_hermes: Publishing 90 bytes(s) to rhasspy/asr/recordingFinished
[DEBUG:2020-11-23 13:41:48,150] rhasspyspeakers_cli_hermes: -> AudioPlayFinished(id='5b2cec16-f76e-4bc8-beaa-382a646d3081', session_id='5b2cec16-f76e-4bc8-beaa-382a646d3081')
[DEBUG:2020-11-23 13:41:48,151] rhasspyspeakers_cli_hermes: Publishing 99 bytes(s) to hermes/audioServer/default/playFinished
[DEBUG:2020-11-23 13:41:48,159] rhasspydialogue_hermes: <- AudioPlayFinished(id='5b2cec16-f76e-4bc8-beaa-382a646d3081', session_id='5b2cec16-f76e-4bc8-beaa-382a646d3081')
[DEBUG:2020-11-23 13:41:48,191] rhasspytts_cli_hermes: <- AudioPlayFinished(id='5b2cec16-f76e-4bc8-beaa-382a646d3081', session_id='5b2cec16-f76e-4bc8-beaa-382a646d3081')
[DEBUG:2020-11-23 13:41:48,302] rhasspyasr_kaldi.transcribe: /usr/lib/rhasspy/.venv/lib/kaldi/online2-tcp-nnet3-decode-faster --port-num=52684 --config=/profiles/en/kaldi/model/online/conf/online.conf --frame-subsampling-factor=3 --max-active=7000 --lattice-beam=8.0 --acoustic-scale=1.0 --beam=24.0 /profiles/en/kaldi/model/model/final.mdl /profiles/en/kaldi/model/graph/hclg.fst /profiles/en/kaldi/model/graph/words.txt
[DEBUG:2020-11-23 13:41:49,594] rhasspyasr_kaldi.transcribe: log (online2-tcp-nnet3-decode-faster[5.5]:computederivedvars():ivector-extractor.cc:183) computing derived variables for ivector extractor
[DEBUG:2020-11-23 13:41:50,395] rhasspyasr_kaldi.transcribe: log (online2-tcp-nnet3-decode-faster[5.5]:computederivedvars():ivector-extractor.cc:204) done.
[DEBUG:2020-11-23 13:41:51,088] rhasspyasr_kaldi.transcribe: log (online2-tcp-nnet3-decode-faster[5.5]:removeorphannodes():nnet-nnet.cc:948) removed 1 orphan nodes.
[DEBUG:2020-11-23 13:41:51,088] rhasspyasr_kaldi.transcribe: log (online2-tcp-nnet3-decode-faster[5.5]:removeorphancomponents():nnet-nnet.cc:847) removing 2 orphan components.
[DEBUG:2020-11-23 13:41:51,089] rhasspyasr_kaldi.transcribe: log (online2-tcp-nnet3-decode-faster[5.5]:collapse():nnet-utils.cc:1472) added 1 components, removed 2
[DEBUG:2020-11-23 13:41:51,224] rhasspyasr_kaldi.transcribe: log (online2-tcp-nnet3-decode-faster[5.5]:compilelooped():nnet-compile-looped.cc:345) spent 0.0997529 seconds in looped compilation.
[DEBUG:2020-11-23 13:41:51,322] rhasspyasr_kaldi.transcribe: log (online2-tcp-nnet3-decode-faster[5.5]:listen():online2-tcp-nnet3-decode-faster.cc:379) tcpserver: listening on port: 52684
[DEBUG:2020-11-23 13:41:51,322] rhasspyasr_kaldi.transcribe: log (online2-tcp-nnet3-decode-faster[5.5]:accept():online2-tcp-nnet3-decode-faster.cc:393) waiting for client...
[DEBUG:2020-11-23 13:41:51,322] rhasspyasr_kaldi.transcribe: Decoder started
[DEBUG:2020-11-23 13:41:51,364] rhasspyasr_kaldi.transcribe: Finished stream. Getting transcription.
[DEBUG:2020-11-23 13:41:52,810] rhasspyasr_kaldi.transcribe: ['kodi service ', 'kodi service off ']
[DEBUG:2020-11-23 13:41:52,812] rhasspyasr_kaldi_hermes: Transcription result: Transcription(text='kodi service off', likelihood=1, transcribe_seconds=1.447506689990405, wav_seconds=1.472, tokens=None)
[DEBUG:2020-11-23 13:41:52,816] rhasspyasr_kaldi_hermes: -> AsrTextCaptured(text='kodi service off', likelihood=1, seconds=1.447506689990405, site_id='default', session_id='default-snowboy-b39e3665-c879-4ed5-bf4c-d2b62a4cbe66', wakeword_id=None, asr_tokens=None, lang=None)
[DEBUG:2020-11-23 13:41:52,816] rhasspyasr_kaldi_hermes: Publishing 218 bytes(s) to hermes/asr/textCaptured
[DEBUG:2020-11-23 13:41:52,818] rhasspyasr_kaldi_hermes: -> AsrAudioCaptured(43244 byte(s)) to rhasspy/asr/default/default/audioCaptured
[DEBUG:2020-11-23 13:41:52,855] rhasspydialogue_hermes: <- AsrTextCaptured(text='kodi service off', likelihood=1, seconds=1.447506689990405, site_id='default', session_id='default-snowboy-b39e3665-c879-4ed5-bf4c-d2b62a4cbe66', wakeword_id=None, asr_tokens=None, lang=None)
[DEBUG:2020-11-23 13:41:52,857] rhasspydialogue_hermes: Playing WAV /usr/lib/rhasspy/etc/wav/beep_lo.wav
[DEBUG:2020-11-23 13:41:52,875] rhasspydialogue_hermes: -> HotwordToggleOff(site_id='default', reason=<HotwordToggleReason.PLAY_AUDIO: 'playAudio'>)
[DEBUG:2020-11-23 13:41:52,876] rhasspydialogue_hermes: Publishing 44 bytes(s) to hermes/hotword/toggleOff
[DEBUG:2020-11-23 13:41:52,879] rhasspydialogue_hermes: -> AsrToggleOff(site_id='default', reason=<AsrToggleReason.PLAY_AUDIO: 'playAudio'>)
[DEBUG:2020-11-23 13:41:52,879] rhasspydialogue_hermes: Publishing 44 bytes(s) to hermes/asr/toggleOff
[DEBUG:2020-11-23 13:41:52,881] rhasspydialogue_hermes: -> AudioPlayBytes(119908 byte(s)) to hermes/audioServer/default/playBytes/fbdd153a-55d0-46ca-af0b-4ba54208a52a
[DEBUG:2020-11-23 13:41:52,883] rhasspydialogue_hermes: Waiting for playFinished (id=fbdd153a-55d0-46ca-af0b-4ba54208a52a, timeout=1.6090022675736961)
[DEBUG:2020-11-23 13:41:52,890] rhasspyspeakers_cli_hermes: <- AudioPlayBytes(119908 byte(s))
[DEBUG:2020-11-23 13:41:52,891] rhasspyspeakers_cli_hermes: ['aplay', '-q', '-t', 'wav', '-D', 'hw:CARD=Headphones,DEV=0']
[DEBUG:2020-11-23 13:41:52,894] rhasspywake_snowboy_hermes: <- HotwordToggleOff(site_id='default', reason=<HotwordToggleReason.PLAY_AUDIO: 'playAudio'>)
[DEBUG:2020-11-23 13:41:52,895] rhasspywake_snowboy_hermes: Disabled
[DEBUG:2020-11-23 13:41:52,946] rhasspyasr_kaldi_hermes: <- AsrToggleOff(site_id='default', reason=<AsrToggleReason.PLAY_AUDIO: 'playAudio'>)
[DEBUG:2020-11-23 13:41:52,946] rhasspyasr_kaldi_hermes: Disabled (AsrToggleReason.PLAY_AUDIO)
[DEBUG:2020-11-23 13:41:53,778] rhasspyspeakers_cli_hermes: -> AudioPlayFinished(id='fbdd153a-55d0-46ca-af0b-4ba54208a52a', session_id='fbdd153a-55d0-46ca-af0b-4ba54208a52a')
[DEBUG:2020-11-23 13:41:53,792] rhasspyspeakers_cli_hermes: Publishing 99 bytes(s) to hermes/audioServer/default/playFinished
[DEBUG:2020-11-23 13:41:53,804] rhasspydialogue_hermes: <- AudioPlayFinished(id='fbdd153a-55d0-46ca-af0b-4ba54208a52a', session_id='fbdd153a-55d0-46ca-af0b-4ba54208a52a')
[DEBUG:2020-11-23 13:41:53,809] rhasspydialogue_hermes: -> HotwordToggleOn(site_id='default', reason=<HotwordToggleReason.PLAY_AUDIO: 'playAudio'>)
[DEBUG:2020-11-23 13:41:53,809] rhasspytts_cli_hermes: <- AudioPlayFinished(id='fbdd153a-55d0-46ca-af0b-4ba54208a52a', session_id='fbdd153a-55d0-46ca-af0b-4ba54208a52a')
[DEBUG:2020-11-23 13:41:53,810] rhasspydialogue_hermes: Publishing 44 bytes(s) to hermes/hotword/toggleOn
[DEBUG:2020-11-23 13:41:53,815] rhasspydialogue_hermes: -> AsrToggleOn(site_id='default', reason=<AsrToggleReason.PLAY_AUDIO: 'playAudio'>)
[DEBUG:2020-11-23 13:41:53,815] rhasspydialogue_hermes: Publishing 44 bytes(s) to hermes/asr/toggleOn
[DEBUG:2020-11-23 13:41:53,817] rhasspydialogue_hermes: Received text: kodi service off
[DEBUG:2020-11-23 13:41:53,820] rhasspydialogue_hermes: -> AsrStopListening(site_id='default', session_id='default-snowboy-b39e3665-c879-4ed5-bf4c-d2b62a4cbe66')
[DEBUG:2020-11-23 13:41:53,821] rhasspydialogue_hermes: Publishing 90 bytes(s) to hermes/asr/stopListening
[DEBUG:2020-11-23 13:41:53,824] rhasspydialogue_hermes: -> HotwordToggleOn(site_id='default', reason=<HotwordToggleReason.DIALOGUE_SESSION: 'dialogueSession'>)
[DEBUG:2020-11-23 13:41:53,825] rhasspydialogue_hermes: Publishing 50 bytes(s) to hermes/hotword/toggleOn
[DEBUG:2020-11-23 13:41:53,828] rhasspywake_snowboy_hermes: <- HotwordToggleOn(site_id='default', reason=<HotwordToggleReason.PLAY_AUDIO: 'playAudio'>)
[DEBUG:2020-11-23 13:41:53,831] rhasspydialogue_hermes: -> NluQuery(input='kodi service off', site_id='default', id=None, intent_filter=None, session_id='default-snowboy-b39e3665-c879-4ed5-bf4c-d2b62a4cbe66', wakeword_id='snowboy', lang=None)
[DEBUG:2020-11-23 13:41:53,832] rhasspydialogue_hermes: Publishing 192 bytes(s) to hermes/nlu/query
[DEBUG:2020-11-23 13:41:53,835] rhasspyasr_kaldi_hermes: <- AsrToggleOn(site_id='default', reason=<AsrToggleReason.PLAY_AUDIO: 'playAudio'>)
[DEBUG:2020-11-23 13:41:53,837] rhasspyasr_kaldi_hermes: Enabled
[DEBUG:2020-11-23 13:41:53,829] rhasspywake_snowboy_hermes: Still disabled: {<HotwordToggleReason.DIALOGUE_SESSION: 'dialogueSession'>}
[DEBUG:2020-11-23 13:41:53,841] rhasspywake_snowboy_hermes: <- HotwordToggleOn(site_id='default', reason=<HotwordToggleReason.DIALOGUE_SESSION: 'dialogueSession'>)
[DEBUG:2020-11-23 13:41:53,842] rhasspywake_snowboy_hermes: Enabled
[DEBUG:2020-11-23 13:41:53,848] rhasspyasr_kaldi_hermes: <- AsrStopListening(site_id='default', session_id='default-snowboy-b39e3665-c879-4ed5-bf4c-d2b62a4cbe66')
[DEBUG:2020-11-23 13:41:53,850] rhasspyasr_kaldi_hermes: Stopping listening (session_id=default-snowboy-b39e3665-c879-4ed5-bf4c-d2b62a4cbe66)
[DEBUG:2020-11-23 13:41:53,853] rhasspyasr_kaldi_hermes: Receiving audio
[DEBUG:2020-11-23 13:41:53,872] rhasspynlu_hermes: <- NluQuery(input='kodi service off', site_id='default', id=None, intent_filter=None, session_id='default-snowboy-b39e3665-c879-4ed5-bf4c-d2b62a4cbe66', wakeword_id='snowboy', lang=None)
[DEBUG:2020-11-23 13:41:53,918] rhasspynlu_hermes: -> NluIntentParsed(input='switch.kodi off', intent=Intent(intent_name='TurnOnOff', confidence_score=1.0), site_id='default', id=None, slots=[Slot(entity='device', value={'kind': 'Unknown', 'value': 'switch.kodi'}, slot_name='device', raw_value='kodi service', confidence=1.0, range=SlotRange(start=0, end=11, raw_start=0, raw_end=12)), Slot(entity='state', value={'kind': 'Unknown', 'value': 'off'}, slot_name='state', raw_value='off', confidence=1.0, range=SlotRange(start=12, end=15, raw_start=13, raw_end=16))], session_id='default-snowboy-b39e3665-c879-4ed5-bf4c-d2b62a4cbe66')
[DEBUG:2020-11-23 13:41:53,932] rhasspynlu_hermes: Publishing 603 bytes(s) to hermes/nlu/intentParsed
[DEBUG:2020-11-23 13:41:53,961] rhasspynlu_hermes: -> NluIntent(input='switch.kodi off', intent=Intent(intent_name='TurnOnOff', confidence_score=1.0), site_id='default', id=None, slots=[Slot(entity='device', value={'kind': 'Unknown', 'value': 'switch.kodi'}, slot_name='device', raw_value='kodi service', confidence=1.0, range=SlotRange(start=0, end=11, raw_start=0, raw_end=12)), Slot(entity='state', value={'kind': 'Unknown', 'value': 'off'}, slot_name='state', raw_value='off', confidence=1.0, range=SlotRange(start=12, end=15, raw_start=13, raw_end=16))], session_id='default-snowboy-b39e3665-c879-4ed5-bf4c-d2b62a4cbe66', custom_data=None, asr_tokens=[[AsrToken(value='switch.kodi', confidence=1.0, range_start=0, range_end=11, time=None), AsrToken(value='off', confidence=1.0, range_start=12, range_end=15, time=None)]], asr_confidence=None, raw_input='kodi service off', wakeword_id='snowboy', lang=None)
[DEBUG:2020-11-23 13:41:53,962] rhasspynlu_hermes: Publishing 911 bytes(s) to hermes/intent/TurnOnOff
[DEBUG:2020-11-23 13:41:54,026] rhasspyhomeassistant_hermes: <- NluIntent(input='switch.kodi off', intent=Intent(intent_name='TurnOnOff', confidence_score=1.0), site_id='default', id=None, slots=[Slot(entity='device', value={'kind': 'Unknown', 'value': 'switch.kodi'}, slot_name='device', raw_value='kodi service', confidence=1.0, range=SlotRange(start=0, end=11, raw_start=0, raw_end=12)), Slot(entity='state', value={'kind': 'Unknown', 'value': 'off'}, slot_name='state', raw_value='off', confidence=1.0, range=SlotRange(start=12, end=15, raw_start=13, raw_end=16))], session_id='default-snowboy-b39e3665-c879-4ed5-bf4c-d2b62a4cbe66', custom_data=None, asr_tokens=[[AsrToken(value='switch.kodi', confidence=1.0, range_start=0, range_end=11, time=None), AsrToken(value='off', confidence=1.0, range_start=12, range_end=15, time=None)]], asr_confidence=None, raw_input='kodi service off', wakeword_id='snowboy', lang=None)
[DEBUG:2020-11-23 13:41:54,021] rhasspydialogue_hermes: <- NluIntent(input='switch.kodi off', intent=Intent(intent_name='TurnOnOff', confidence_score=1.0), site_id='default', id=None, slots=[Slot(entity='device', value={'kind': 'Unknown', 'value': 'switch.kodi'}, slot_name='device', raw_value='kodi service', confidence=1.0, range=SlotRange(start=0, end=11, raw_start=0, raw_end=12)), Slot(entity='state', value={'kind': 'Unknown', 'value': 'off'}, slot_name='state', raw_value='off', confidence=1.0, range=SlotRange(start=12, end=15, raw_start=13, raw_end=16))], session_id='default-snowboy-b39e3665-c879-4ed5-bf4c-d2b62a4cbe66', custom_data=None, asr_tokens=[[AsrToken(value='switch.kodi', confidence=1.0, range_start=0, range_end=11, time=None), AsrToken(value='off', confidence=1.0, range_start=12, range_end=15, time=None)]], asr_confidence=None, raw_input='kodi service off', wakeword_id='snowboy', lang=None)
[DEBUG:2020-11-23 13:41:54,029] rhasspydialogue_hermes: Recognized NluIntent(input='switch.kodi off', intent=Intent(intent_name='TurnOnOff', confidence_score=1.0), site_id='default', id=None, slots=[Slot(entity='device', value={'kind': 'Unknown', 'value': 'switch.kodi'}, slot_name='device', raw_value='kodi service', confidence=1.0, range=SlotRange(start=0, end=11, raw_start=0, raw_end=12)), Slot(entity='state', value={'kind': 'Unknown', 'value': 'off'}, slot_name='state', raw_value='off', confidence=1.0, range=SlotRange(start=12, end=15, raw_start=13, raw_end=16))], session_id='default-snowboy-b39e3665-c879-4ed5-bf4c-d2b62a4cbe66', custom_data=None, asr_tokens=[[AsrToken(value='switch.kodi', confidence=1.0, range_start=0, range_end=11, time=None), AsrToken(value='off', confidence=1.0, range_start=12, range_end=15, time=None)]], asr_confidence=None, raw_input='kodi service off', wakeword_id='snowboy', lang=None)
[DEBUG:2020-11-23 13:41:54,065] rhasspyhomeassistant_hermes: http://XX.XX.XX.XX:8123/api/events/rhasspy_TurnOnOff
[ERROR:2020-11-23 13:42:13,850] rhasspydialogue_hermes: Session timed out for site default: default-snowboy-b39e3665-c879-4ed5-bf4c-d2b62a4cbe66
[DEBUG:2020-11-23 13:42:13,853] rhasspydialogue_hermes: -> AsrStopListening(site_id='default', session_id='default-snowboy-b39e3665-c879-4ed5-bf4c-d2b62a4cbe66')
[DEBUG:2020-11-23 13:42:13,854] rhasspydialogue_hermes: Publishing 90 bytes(s) to hermes/asr/stopListening
[DEBUG:2020-11-23 13:42:13,859] rhasspydialogue_hermes: -> DialogueSessionEnded(termination=DialogueSessionTermination(reason=<DialogueSessionTerminationReason.TIMEOUT: 'timeout'>), session_id='default-snowboy-b39e3665-c879-4ed5-bf4c-d2b62a4cbe66', site_id='default', custom_data='snowboy')
[DEBUG:2020-11-23 13:42:13,860] rhasspydialogue_hermes: Publishing 153 bytes(s) to hermes/dialogueManager/sessionEnded
[DEBUG:2020-11-23 13:42:13,863] rhasspydialogue_hermes: -> HotwordToggleOn(site_id='default', reason=<HotwordToggleReason.DIALOGUE_SESSION: 'dialogueSession'>)
[DEBUG:2020-11-23 13:42:13,864] rhasspydialogue_hermes: Publishing 50 bytes(s) to hermes/hotword/toggleOn
[DEBUG:2020-11-23 13:42:13,894] rhasspywake_snowboy_hermes: <- HotwordToggleOn(site_id='default', reason=<HotwordToggleReason.DIALOGUE_SESSION: 'dialogueSession'>)
[DEBUG:2020-11-23 13:42:13,894] rhasspyasr_kaldi_hermes: <- AsrStopListening(site_id='default', session_id='default-snowboy-b39e3665-c879-4ed5-bf4c-d2b62a4cbe66')
[DEBUG:2020-11-23 13:42:13,895] rhasspyasr_kaldi_hermes: Stopping listening (session_id=default-snowboy-b39e3665-c879-4ed5-bf4c-d2b62a4cbe66)
[DEBUG:2020-11-23 13:42:13,895] rhasspywake_snowboy_hermes: Enabled