search

snipsco / snips-issues

Feel free to share your bugs with us.
14 stars 5 forks source link

[Platform][Wakeword] Memory leak in hotword #126

Open jenskastensson opened 5 years ago

jenskastensson commented 5 years ago

What's the issue? The hotword module seems to leak memory,

Use Cases Impacted Stand-by

How to reproduce Leave the mike with background noise (music/radio/talk) for 1h

Expected behavior No memory leak

Version and Environment 0.61.1 Raspberry ReSpeaker

Logs This is application log every 3 min, it does "ps -C snips-hotword -o %mem=" the last parameter "hw" [Mon Apr 29 2019 11:37:05 ] currentMem: 16 memUsageSnips: 0 nlu:8 asr:5 hw:3 [Mon Apr 29 2019 11:40:05 ] currentMem: 17 memUsageSnips: 16 nlu:8 asr:5 hw:4 [Mon Apr 29 2019 11:43:05 ] currentMem: 17 memUsageSnips: 17 nlu:8 asr:5 hw:4 [Mon Apr 29 2019 11:46:05 ] currentMem: 18 memUsageSnips: 17 nlu:8 asr:5 hw:5 [Mon Apr 29 2019 11:49:05 ] currentMem: 19 memUsageSnips: 18 nlu:8 asr:5 hw:6 [Mon Apr 29 2019 11:52:05 ] currentMem: 19 memUsageSnips: 19 nlu:8 asr:5 hw:6 [Mon Apr 29 2019 11:55:05 ] currentMem: 20 memUsageSnips: 19 nlu:8 asr:5 hw:7 [Mon Apr 29 2019 11:58:05 ] currentMem: 21 memUsageSnips: 20 nlu:8 asr:5 hw:8 [Mon Apr 29 2019 12:01:05 ] currentMem: 21 memUsageSnips: 21 nlu:8 asr:5 hw:8 [Mon Apr 29 2019 12:04:05 ] currentMem: 22 memUsageSnips: 21 nlu:8 asr:5 hw:9 [Mon Apr 29 2019 12:07:05 ] currentMem: 22 memUsageSnips: 22 nlu:8 asr:5 hw:9 [Mon Apr 29 2019 12:10:05 ] currentMem: 23 memUsageSnips: 22 nlu:8 asr:5 hw:10 [Mon Apr 29 2019 12:13:05 ] currentMem: 24 memUsageSnips: 23 nlu:8 asr:5 hw:11 [Mon Apr 29 2019 12:16:05 ] currentMem: 24 memUsageSnips: 24 nlu:8 asr:5 hw:11 [Mon Apr 29 2019 12:19:05 ] currentMem: 25 memUsageSnips: 24 nlu:8 asr:5 hw:12 [Mon Apr 29 2019 12:22:05 ] currentMem: 26 memUsageSnips: 25 nlu:8 asr:5 hw:13 [Mon Apr 29 2019 12:25:05 ] currentMem: 26 memUsageSnips: 26 nlu:8 asr:5 hw:13 [Mon Apr 29 2019 12:28:05 ] currentMem: 27 memUsageSnips: 26 nlu:8 asr:5 hw:14 [Mon Apr 29 2019 12:31:05 ] currentMem: 27 memUsageSnips: 27 nlu:8 asr:5 hw:14 [Mon Apr 29 2019 12:34:05 ] currentMem: 28 memUsageSnips: 27 nlu:8 asr:5 hw:15 [Mon Apr 29 2019 12:37:05 ] currentMem: 29 memUsageSnips: 28 nlu:8 asr:5 hw:16 [Mon Apr 29 2019 12:40:05 ] currentMem: 29 memUsageSnips: 29 nlu:8 asr:5 hw:16 [Mon Apr 29 2019 12:43:05 ] currentMem: 30 memUsageSnips: 29 nlu:8 asr:5 hw:17 [Mon Apr 29 2019 12:46:05 ] currentMem: 31 memUsageSnips: 30 nlu:8 asr:5 hw:18 [Mon Apr 29 2019 12:49:05 ] currentMem: 31 memUsageSnips: 31 nlu:8 asr:5 hw:18 ->restart snips modules

Additional information This problem was reported in the forum some time ago https://forum.snips.ai/t/out-of-memory-kill-process-snips-hotword/1637

Workaround Restart all snips modules when memory usage exceeds a certain limit

kali commented 5 years ago

Hi, thanks for reporting.... again.

Can you remind me which wake word model (or models) you are using on the device ?

jenskastensson commented 5 years ago

Hi, I use "Hey Snips" only. And no worries! The test environment: the ReSpeaker sits 10cm in front of a Sonos speaker, TuneIn with SomaFM: Covers triggers the leak :-)

kali commented 5 years ago

OK, I have to ask... Is the Wake word triggered by the input ? Do you observe the leak if there is no noise in front of the micro ?

Can you give me the logs of snips-hotword ? One way is to run "journalctl -u snips-hotword > log.txt", and copy log.txt. Without the redirection you may get truncated lines, and I need them in full.

jenskastensson commented 5 years ago

The wakeword is triggered from time to time, but typically it is not triggered as it is so close to the speaker. Here's the log BTW Is this normal: Hotword detected: site_id:bedroom model:hey_snips (1556540520229ms ago)

-- Logs begin at Sun 2019-04-28 09:46:50 CEST, end at Mon 2019-04-29 15:42:07 CEST. -- Apr 28 10:33:04 v2 systemd[1]: Stopping Snips Hotword... Apr 28 10:33:04 v2 systemd[1]: Stopped Snips Hotword. Apr 28 10:33:04 v2 systemd[1]: Started Snips Hotword. Apr 28 10:33:04 v2 snips-hotword[18821]: INFO:snips_hotword::server: Using model from /usr/share/snips/assistant/custom_hotword Apr 28 10:33:04 v2 snips-hotword[18821]: INFO:snips_hotword_lib::universal: Loading model "/usr/share/snips/assistant/custom_hotword", hotword_key: Some("hey_snips"), model_id: Some("workflow-hey_snips_subww_feedback_10seeds-2018_12_04T12_13_05_evaluated_model_0002") Apr 28 10:33:08 v2 snips-hotword[18821]: INFO:snips_hotword::server : Discovered audio_server bedroom/mqtt, starting hotword listener Apr 28 10:33:08 v2 snips-hotword[18821]: INFO:snips_hotword::server : Connecting using MQTT site-id bedroom Apr 28 10:33:08 v2 snips-hotword[18821]: INFO:snips_hotword_lib::audio : Audio thread for bedroom started Apr 28 10:33:08 v2 snips-hotword[18821]: INFO:snips_hotword_lib::audio : Net and VAD thread for site bedroom started (vad inhibitor: true, vad messages: false Apr 28 10:33:08 v2 snips-hotword[18821]: INFO:snips_hotword_lib : Detector "detector.hey_snips.bedroom", sensitivity: 0.5, threshold 0.787 Apr 28 10:33:08 v2 snips-hotword[18821]: INFO:snips_hotword_lib : detector.hey_snips.bedroom thread started Apr 28 10:33:11 v2 snips-hotword[18821]: INFO:snips_hotword::server : Discovered audio_server home_cinema/mqtt, starting hotword listener Apr 28 10:33:11 v2 snips-hotword[18821]: INFO:snips_hotword::server : Connecting using MQTT site-id home_cinema Apr 28 10:33:11 v2 snips-hotword[18821]: INFO:snips_hotword_lib::audio : Audio thread for home_cinema started Apr 28 10:33:11 v2 snips-hotword[18821]: INFO:snips_hotword_lib::audio : Net and VAD thread for site home_cinema started (vad inhibitor: true, vad messages: false Apr 28 10:33:11 v2 snips-hotword[18821]: INFO:snips_hotword_lib : Detector "detector.hey_snips.home_cinema", sensitivity: 0.5, threshold 0.787 Apr 28 10:33:11 v2 snips-hotword[18821]: INFO:snips_hotword_lib : detector.hey_snips.home_cinema thread started Apr 28 13:33:04 v2 systemd[1]: Stopping Snips Hotword... Apr 28 13:33:04 v2 systemd[1]: Stopped Snips Hotword. Apr 28 13:33:04 v2 systemd[1]: Started Snips Hotword. Apr 28 13:33:05 v2 snips-hotword[11000]: INFO:snips_hotword::server: Using model from /usr/share/snips/assistant/custom_hotword Apr 28 13:33:05 v2 snips-hotword[11000]: INFO:snips_hotword_lib::universal: Loading model "/usr/share/snips/assistant/custom_hotword", hotword_key: Some("hey_snips"), model_id: Some("workflow-hey_snips_subww_feedback_10seeds-2018_12_04T12_13_05_evaluated_model_0002") Apr 28 13:33:08 v2 snips-hotword[11000]: INFO:snips_hotword::server : Discovered audio_server bedroom/mqtt, starting hotword listener Apr 28 13:33:08 v2 snips-hotword[11000]: INFO:snips_hotword::server : Connecting using MQTT site-id bedroom Apr 28 13:33:08 v2 snips-hotword[11000]: INFO:snips_hotword_lib::audio : Audio thread for bedroom started Apr 28 13:33:08 v2 snips-hotword[11000]: INFO:snips_hotword_lib::audio : Net and VAD thread for site bedroom started (vad inhibitor: true, vad messages: false Apr 28 13:33:08 v2 snips-hotword[11000]: INFO:snips_hotword_lib : Detector "detector.hey_snips.bedroom", sensitivity: 0.5, threshold 0.787 Apr 28 13:33:08 v2 snips-hotword[11000]: INFO:snips_hotword_lib : detector.hey_snips.bedroom thread started Apr 28 13:33:11 v2 snips-hotword[11000]: INFO:snips_hotword::server : Discovered audio_server home_cinema/mqtt, starting hotword listener Apr 28 13:33:11 v2 snips-hotword[11000]: INFO:snips_hotword::server : Connecting using MQTT site-id home_cinema Apr 28 13:33:11 v2 snips-hotword[11000]: INFO:snips_hotword_lib::audio : Audio thread for home_cinema started Apr 28 13:33:11 v2 snips-hotword[11000]: INFO:snips_hotword_lib::audio : Net and VAD thread for site home_cinema started (vad inhibitor: true, vad messages: false Apr 28 13:33:11 v2 snips-hotword[11000]: INFO:snips_hotword_lib : Detector "detector.hey_snips.home_cinema", sensitivity: 0.5, threshold 0.787 Apr 28 13:33:11 v2 snips-hotword[11000]: INFO:snips_hotword_lib : detector.hey_snips.home_cinema thread started Apr 28 16:33:04 v2 systemd[1]: Stopping Snips Hotword... Apr 28 16:33:04 v2 systemd[1]: Stopped Snips Hotword. Apr 28 16:33:05 v2 systemd[1]: Started Snips Hotword. Apr 28 16:33:05 v2 snips-hotword[2857]: INFO:snips_hotword::server: Using model from /usr/share/snips/assistant/custom_hotword Apr 28 16:33:05 v2 snips-hotword[2857]: INFO:snips_hotword_lib::universal: Loading model "/usr/share/snips/assistant/custom_hotword", hotword_key: Some("hey_snips"), model_id: Some("workflow-hey_snips_subww_feedback_10seeds-2018_12_04T12_13_05_evaluated_model_0002") Apr 28 16:33:08 v2 snips-hotword[2857]: INFO:snips_hotword::server : Discovered audio_server bedroom/mqtt, starting hotword listener Apr 28 16:33:08 v2 snips-hotword[2857]: INFO:snips_hotword::server : Connecting using MQTT site-id bedroom Apr 28 16:33:08 v2 snips-hotword[2857]: INFO:snips_hotword_lib::audio : Audio thread for bedroom started Apr 28 16:33:08 v2 snips-hotword[2857]: INFO:snips_hotword_lib::audio : Net and VAD thread for site bedroom started (vad inhibitor: true, vad messages: false Apr 28 16:33:08 v2 snips-hotword[2857]: INFO:snips_hotword_lib : Detector "detector.hey_snips.bedroom", sensitivity: 0.5, threshold 0.787 Apr 28 16:33:08 v2 snips-hotword[2857]: INFO:snips_hotword_lib : detector.hey_snips.bedroom thread started Apr 28 16:33:12 v2 snips-hotword[2857]: INFO:snips_hotword::server : Discovered audio_server home_cinema/mqtt, starting hotword listener Apr 28 16:33:12 v2 snips-hotword[2857]: INFO:snips_hotword::server : Connecting using MQTT site-id home_cinema Apr 28 16:33:12 v2 snips-hotword[2857]: INFO:snips_hotword_lib::audio : Audio thread for home_cinema started Apr 28 16:33:12 v2 snips-hotword[2857]: INFO:snips_hotword_lib::audio : Net and VAD thread for site home_cinema started (vad inhibitor: true, vad messages: false Apr 28 16:33:12 v2 snips-hotword[2857]: INFO:snips_hotword_lib : Detector "detector.hey_snips.home_cinema", sensitivity: 0.5, threshold 0.787 Apr 28 16:33:12 v2 snips-hotword[2857]: INFO:snips_hotword_lib : detector.hey_snips.home_cinema thread started Apr 28 19:33:04 v2 systemd[1]: Stopping Snips Hotword... Apr 28 19:33:04 v2 systemd[1]: Stopped Snips Hotword. Apr 28 19:33:07 v2 systemd[1]: Started Snips Hotword. Apr 28 19:33:07 v2 snips-hotword[27347]: INFO:snips_hotword::server: Using model from /usr/share/snips/assistant/custom_hotword Apr 28 19:33:07 v2 snips-hotword[27347]: INFO:snips_hotword_lib::universal: Loading model "/usr/share/snips/assistant/custom_hotword", hotword_key: Some("hey_snips"), model_id: Some("workflow-hey_snips_subww_feedback_10seeds-2018_12_04T12_13_05_evaluated_model_0002") Apr 28 19:33:11 v2 snips-hotword[27347]: INFO:snips_hotword::server : Discovered audio_server bedroom/mqtt, starting hotword listener Apr 28 19:33:11 v2 snips-hotword[27347]: INFO:snips_hotword::server : Connecting using MQTT site-id bedroom Apr 28 19:33:11 v2 snips-hotword[27347]: INFO:snips_hotword_lib::audio : Audio thread for bedroom started Apr 28 19:33:11 v2 snips-hotword[27347]: INFO:snips_hotword_lib::audio : Net and VAD thread for site bedroom started (vad inhibitor: true, vad messages: false Apr 28 19:33:11 v2 snips-hotword[27347]: INFO:snips_hotword_lib : Detector "detector.hey_snips.bedroom", sensitivity: 0.5, threshold 0.787 Apr 28 19:33:11 v2 snips-hotword[27347]: INFO:snips_hotword_lib : detector.hey_snips.bedroom thread started Apr 28 19:33:14 v2 snips-hotword[27347]: INFO:snips_hotword::server : Discovered audio_server home_cinema/mqtt, starting hotword listener Apr 28 19:33:14 v2 snips-hotword[27347]: INFO:snips_hotword::server : Connecting using MQTT site-id home_cinema Apr 28 19:33:14 v2 snips-hotword[27347]: INFO:snips_hotword_lib::audio : Audio thread for home_cinema started Apr 28 19:33:14 v2 snips-hotword[27347]: INFO:snips_hotword_lib : Detector "detector.hey_snips.home_cinema", sensitivity: 0.5, threshold 0.787 Apr 28 19:33:14 v2 snips-hotword[27347]: INFO:snips_hotword_lib::audio : Net and VAD thread for site home_cinema started (vad inhibitor: true, vad messages: false Apr 28 19:33:14 v2 snips-hotword[27347]: INFO:snips_hotword_lib : detector.hey_snips.home_cinema thread started Apr 28 22:33:04 v2 systemd[1]: Stopping Snips Hotword... Apr 28 22:33:04 v2 systemd[1]: Stopped Snips Hotword. Apr 28 22:33:05 v2 systemd[1]: Started Snips Hotword. Apr 28 22:33:05 v2 snips-hotword[19117]: INFO:snips_hotword::server: Using model from /usr/share/snips/assistant/custom_hotword Apr 28 22:33:05 v2 snips-hotword[19117]: INFO:snips_hotword_lib::universal: Loading model "/usr/share/snips/assistant/custom_hotword", hotword_key: Some("hey_snips"), model_id: Some("workflow-hey_snips_subww_feedback_10seeds-2018_12_04T12_13_05_evaluated_model_0002") Apr 28 22:33:09 v2 snips-hotword[19117]: INFO:snips_hotword::server : Discovered audio_server bedroom/mqtt, starting hotword listener Apr 28 22:33:09 v2 snips-hotword[19117]: INFO:snips_hotword::server : Connecting using MQTT site-id bedroom Apr 28 22:33:09 v2 snips-hotword[19117]: INFO:snips_hotword_lib::audio : Audio thread for bedroom started Apr 28 22:33:09 v2 snips-hotword[19117]: INFO:snips_hotword_lib::audio : Net and VAD thread for site bedroom started (vad inhibitor: true, vad messages: false Apr 28 22:33:09 v2 snips-hotword[19117]: INFO:snips_hotword_lib : Detector "detector.hey_snips.bedroom", sensitivity: 0.5, threshold 0.787 Apr 28 22:33:09 v2 snips-hotword[19117]: INFO:snips_hotword_lib : detector.hey_snips.bedroom thread started Apr 28 22:33:12 v2 snips-hotword[19117]: INFO:snips_hotword::server : Discovered audio_server home_cinema/mqtt, starting hotword listener Apr 28 22:33:12 v2 snips-hotword[19117]: INFO:snips_hotword::server : Connecting using MQTT site-id home_cinema Apr 28 22:33:12 v2 snips-hotword[19117]: INFO:snips_hotword_lib::audio : Audio thread for home_cinema started Apr 28 22:33:12 v2 snips-hotword[19117]: INFO:snips_hotword_lib::audio : Net and VAD thread for site home_cinema started (vad inhibitor: true, vad messages: false Apr 28 22:33:12 v2 snips-hotword[19117]: INFO:snips_hotword_lib : Detector "detector.hey_snips.home_cinema", sensitivity: 0.5, threshold 0.787 Apr 28 22:33:12 v2 snips-hotword[19117]: INFO:snips_hotword_lib : detector.hey_snips.home_cinema thread started Apr 29 01:33:04 v2 systemd[1]: Stopping Snips Hotword... Apr 29 01:33:05 v2 systemd[1]: Stopped Snips Hotword. Apr 29 01:33:05 v2 systemd[1]: Started Snips Hotword. Apr 29 01:33:05 v2 snips-hotword[11365]: INFO:snips_hotword::server: Using model from /usr/share/snips/assistant/custom_hotword Apr 29 01:33:05 v2 snips-hotword[11365]: INFO:snips_hotword_lib::universal: Loading model "/usr/share/snips/assistant/custom_hotword", hotword_key: Some("hey_snips"), model_id: Some("workflow-hey_snips_subww_feedback_10seeds-2018_12_04T12_13_05_evaluated_model_0002") Apr 29 01:33:09 v2 snips-hotword[11365]: INFO:snips_hotword::server : Discovered audio_server bedroom/mqtt, starting hotword listener Apr 29 01:33:09 v2 snips-hotword[11365]: INFO:snips_hotword::server : Connecting using MQTT site-id bedroom Apr 29 01:33:09 v2 snips-hotword[11365]: INFO:snips_hotword_lib::audio : Audio thread for bedroom started Apr 29 01:33:09 v2 snips-hotword[11365]: INFO:snips_hotword_lib::audio : Net and VAD thread for site bedroom started (vad inhibitor: true, vad messages: false Apr 29 01:33:09 v2 snips-hotword[11365]: INFO:snips_hotword_lib : Detector "detector.hey_snips.bedroom", sensitivity: 0.5, threshold 0.787 Apr 29 01:33:09 v2 snips-hotword[11365]: INFO:snips_hotword_lib : detector.hey_snips.bedroom thread started Apr 29 01:33:12 v2 snips-hotword[11365]: INFO:snips_hotword::server : Discovered audio_server home_cinema/mqtt, starting hotword listener Apr 29 01:33:12 v2 snips-hotword[11365]: INFO:snips_hotword::server : Connecting using MQTT site-id home_cinema Apr 29 01:33:12 v2 snips-hotword[11365]: INFO:snips_hotword_lib::audio : Audio thread for home_cinema started Apr 29 01:33:12 v2 snips-hotword[11365]: INFO:snips_hotword_lib : Detector "detector.hey_snips.home_cinema", sensitivity: 0.5, threshold 0.787 Apr 29 01:33:12 v2 snips-hotword[11365]: INFO:snips_hotword_lib::audio : Net and VAD thread for site home_cinema started (vad inhibitor: true, vad messages: false Apr 29 01:33:12 v2 snips-hotword[11365]: INFO:snips_hotword_lib : detector.hey_snips.home_cinema thread started Apr 29 04:01:44 v2 systemd[1]: Stopping Snips Hotword... Apr 29 04:01:44 v2 systemd[1]: Stopped Snips Hotword. Apr 29 04:02:15 v2 systemd[1]: Started Snips Hotword. Apr 29 04:02:15 v2 snips-hotword[32043]: INFO:snips_hotword::server: Using model from /usr/share/snips/assistant/custom_hotword Apr 29 04:02:15 v2 snips-hotword[32043]: INFO:snips_hotword_lib::universal: Loading model "/usr/share/snips/assistant/custom_hotword", hotword_key: Some("hey_snips"), model_id: Some("workflow-hey_snips_subww_feedback_10seeds-2018_12_04T12_13_05_evaluated_model_0002") Apr 29 04:02:19 v2 snips-hotword[32043]: INFO:snips_hotword::server : Discovered audio_server bedroom/mqtt, starting hotword listener Apr 29 04:02:19 v2 snips-hotword[32043]: INFO:snips_hotword::server : Connecting using MQTT site-id bedroom Apr 29 04:02:19 v2 snips-hotword[32043]: INFO:snips_hotword_lib::audio : Audio thread for bedroom started Apr 29 04:02:19 v2 snips-hotword[32043]: INFO:snips_hotword_lib::audio : Net and VAD thread for site bedroom started (vad inhibitor: true, vad messages: false Apr 29 04:02:19 v2 snips-hotword[32043]: INFO:snips_hotword_lib : Detector "detector.hey_snips.bedroom", sensitivity: 0.5, threshold 0.787 Apr 29 04:02:19 v2 snips-hotword[32043]: INFO:snips_hotword_lib : detector.hey_snips.bedroom thread started Apr 29 04:02:22 v2 snips-hotword[32043]: INFO:snips_hotword::server : Discovered audio_server home_cinema/mqtt, starting hotword listener Apr 29 04:02:22 v2 snips-hotword[32043]: INFO:snips_hotword::server : Connecting using MQTT site-id home_cinema Apr 29 04:02:22 v2 snips-hotword[32043]: INFO:snips_hotword_lib::audio : Audio thread for home_cinema started Apr 29 04:02:22 v2 snips-hotword[32043]: INFO:snips_hotword_lib : Detector "detector.hey_snips.home_cinema", sensitivity: 0.5, threshold 0.787 Apr 29 04:02:22 v2 snips-hotword[32043]: INFO:snips_hotword_lib : detector.hey_snips.home_cinema thread started Apr 29 04:02:22 v2 snips-hotword[32043]: INFO:snips_hotword_lib::audio : Net and VAD thread for site home_cinema started (vad inhibitor: true, vad messages: false Apr 29 07:02:14 v2 systemd[1]: Stopping Snips Hotword... Apr 29 07:02:14 v2 systemd[1]: Stopped Snips Hotword. Apr 29 07:02:15 v2 systemd[1]: Started Snips Hotword. Apr 29 07:02:15 v2 snips-hotword[24390]: INFO:snips_hotword::server: Using model from /usr/share/snips/assistant/custom_hotword Apr 29 07:02:15 v2 snips-hotword[24390]: INFO:snips_hotword_lib::universal: Loading model "/usr/share/snips/assistant/custom_hotword", hotword_key: Some("hey_snips"), model_id: Some("workflow-hey_snips_subww_feedback_10seeds-2018_12_04T12_13_05_evaluated_model_0002") Apr 29 07:02:19 v2 snips-hotword[24390]: INFO:snips_hotword::server : Discovered audio_server bedroom/mqtt, starting hotword listener Apr 29 07:02:19 v2 snips-hotword[24390]: INFO:snips_hotword::server : Connecting using MQTT site-id bedroom Apr 29 07:02:19 v2 snips-hotword[24390]: INFO:snips_hotword_lib::audio : Audio thread for bedroom started Apr 29 07:02:19 v2 snips-hotword[24390]: INFO:snips_hotword_lib::audio : Net and VAD thread for site bedroom started (vad inhibitor: true, vad messages: false Apr 29 07:02:19 v2 snips-hotword[24390]: INFO:snips_hotword_lib : Detector "detector.hey_snips.bedroom", sensitivity: 0.5, threshold 0.787 Apr 29 07:02:19 v2 snips-hotword[24390]: INFO:snips_hotword_lib : detector.hey_snips.bedroom thread started Apr 29 07:02:22 v2 snips-hotword[24390]: INFO:snips_hotword::server : Discovered audio_server home_cinema/mqtt, starting hotword listener Apr 29 07:02:22 v2 snips-hotword[24390]: INFO:snips_hotword::server : Connecting using MQTT site-id home_cinema Apr 29 07:02:22 v2 snips-hotword[24390]: INFO:snips_hotword_lib::audio : Audio thread for home_cinema started Apr 29 07:02:22 v2 snips-hotword[24390]: INFO:snips_hotword_lib : Detector "detector.hey_snips.home_cinema", sensitivity: 0.5, threshold 0.787 Apr 29 07:02:22 v2 snips-hotword[24390]: INFO:snips_hotword_lib::audio : Net and VAD thread for site home_cinema started (vad inhibitor: true, vad messages: false Apr 29 07:02:22 v2 snips-hotword[24390]: INFO:snips_hotword_lib : detector.hey_snips.home_cinema thread started Apr 29 10:02:14 v2 systemd[1]: Stopping Snips Hotword... Apr 29 10:02:14 v2 systemd[1]: Stopped Snips Hotword. Apr 29 10:02:15 v2 systemd[1]: Started Snips Hotword. Apr 29 10:02:15 v2 snips-hotword[16806]: INFO:snips_hotword::server: Using model from /usr/share/snips/assistant/custom_hotword Apr 29 10:02:15 v2 snips-hotword[16806]: INFO:snips_hotword_lib::universal: Loading model "/usr/share/snips/assistant/custom_hotword", hotword_key: Some("hey_snips"), model_id: Some("workflow-hey_snips_subww_feedback_10seeds-2018_12_04T12_13_05_evaluated_model_0002") Apr 29 10:02:19 v2 snips-hotword[16806]: INFO:snips_hotword::server : Discovered audio_server bedroom/mqtt, starting hotword listener Apr 29 10:02:19 v2 snips-hotword[16806]: INFO:snips_hotword::server : Connecting using MQTT site-id bedroom Apr 29 10:02:19 v2 snips-hotword[16806]: INFO:snips_hotword_lib::audio : Audio thread for bedroom started Apr 29 10:02:19 v2 snips-hotword[16806]: INFO:snips_hotword_lib::audio : Net and VAD thread for site bedroom started (vad inhibitor: true, vad messages: false Apr 29 10:02:19 v2 snips-hotword[16806]: INFO:snips_hotword_lib : Detector "detector.hey_snips.bedroom", sensitivity: 0.5, threshold 0.787 Apr 29 10:02:19 v2 snips-hotword[16806]: INFO:snips_hotword_lib : detector.hey_snips.bedroom thread started Apr 29 10:02:22 v2 snips-hotword[16806]: INFO:snips_hotword::server : Discovered audio_server home_cinema/mqtt, starting hotword listener Apr 29 10:02:22 v2 snips-hotword[16806]: INFO:snips_hotword::server : Connecting using MQTT site-id home_cinema Apr 29 10:02:22 v2 snips-hotword[16806]: INFO:snips_hotword_lib::audio : Audio thread for home_cinema started Apr 29 10:02:22 v2 snips-hotword[16806]: INFO:snips_hotword_lib::audio : Net and VAD thread for site home_cinema started (vad inhibitor: true, vad messages: false Apr 29 10:02:22 v2 snips-hotword[16806]: INFO:snips_hotword_lib : Detector "detector.hey_snips.home_cinema", sensitivity: 0.5, threshold 0.787 Apr 29 10:02:22 v2 snips-hotword[16806]: INFO:snips_hotword_lib : detector.hey_snips.home_cinema thread started Apr 29 10:04:56 v2 snips-hotword[16806]: INFO:snips_hotword_hermes : Hotword detected: site_id:home_cinema model:hey_snips (74ms ago) Apr 29 10:04:56 v2 snips-hotword[16806]: INFO:snips_hotword_lib::audio : Audio thread for site home_cinema stopped. Apr 29 10:05:02 v2 snips-hotword[16806]: INFO:snips_hotword_lib::audio : Audio thread for site home_cinema started. Apr 29 10:35:50 v2 snips-hotword[16806]: INFO:snips_hotword_hermes : Hotword detected: site_id:home_cinema model:hey_snips (147ms ago) Apr 29 10:35:50 v2 snips-hotword[16806]: INFO:snips_hotword_lib::audio : Audio thread for site home_cinema stopped. Apr 29 10:35:55 v2 snips-hotword[16806]: INFO:snips_hotword_lib::audio : Audio thread for site home_cinema started. Apr 29 10:36:00 v2 snips-hotword[16806]: INFO:snips_hotword_hermes : Hotword detected: site_id:home_cinema model:hey_snips (138ms ago) Apr 29 10:36:00 v2 snips-hotword[16806]: INFO:snips_hotword_lib::audio : Audio thread for site home_cinema stopped. Apr 29 10:36:06 v2 snips-hotword[16806]: INFO:snips_hotword_lib::audio : Audio thread for site home_cinema started. Apr 29 10:36:16 v2 snips-hotword[16806]: INFO:snips_hotword_hermes : Hotword detected: site_id:home_cinema model:hey_snips (148ms ago) Apr 29 10:36:16 v2 snips-hotword[16806]: INFO:snips_hotword_lib::audio : Audio thread for site home_cinema stopped. Apr 29 10:36:20 v2 snips-hotword[16806]: INFO:snips_hotword_lib::audio : Audio thread for site home_cinema started. Apr 29 10:36:25 v2 snips-hotword[16806]: INFO:snips_hotword_hermes : Hotword detected: site_id:home_cinema model:hey_snips (131ms ago) Apr 29 10:36:25 v2 snips-hotword[16806]: INFO:snips_hotword_lib::audio : Audio thread for site home_cinema stopped. Apr 29 10:36:31 v2 snips-hotword[16806]: INFO:snips_hotword_lib::audio : Audio thread for site home_cinema started. Apr 29 10:37:30 v2 snips-hotword[16806]: INFO:snips_hotword_hermes : Hotword detected: site_id:home_cinema model:hey_snips (120ms ago) Apr 29 10:37:30 v2 snips-hotword[16806]: INFO:snips_hotword_lib::audio : Audio thread for site home_cinema stopped. Apr 29 10:37:36 v2 snips-hotword[16806]: INFO:snips_hotword_lib::audio : Audio thread for site home_cinema started. Apr 29 10:38:15 v2 snips-hotword[16806]: INFO:snips_hotword_hermes : Hotword detected: site_id:home_cinema model:hey_snips (53ms ago) Apr 29 10:38:15 v2 snips-hotword[16806]: INFO:snips_hotword_lib::audio : Audio thread for site home_cinema stopped. Apr 29 10:38:24 v2 snips-hotword[16806]: INFO:snips_hotword_lib::audio : Audio thread for site home_cinema started. Apr 29 10:39:57 v2 snips-hotword[16806]: INFO:snips_hotword_hermes : Hotword detected: site_id:home_cinema model:hey_snips (31ms ago) Apr 29 10:39:57 v2 snips-hotword[16806]: INFO:snips_hotword_lib::audio : Audio thread for site home_cinema stopped. Apr 29 10:40:06 v2 snips-hotword[16806]: INFO:snips_hotword_lib::audio : Audio thread for site home_cinema started. Apr 29 10:40:23 v2 snips-hotword[16806]: INFO:snips_hotword_hermes : Hotword detected: site_id:home_cinema model:hey_snips (88ms ago) Apr 29 10:40:23 v2 snips-hotword[16806]: INFO:snips_hotword_lib::audio : Audio thread for site home_cinema stopped. Apr 29 10:40:28 v2 snips-hotword[16806]: INFO:snips_hotword_lib::audio : Audio thread for site home_cinema started. Apr 29 11:34:05 v2 systemd[1]: Stopping Snips Hotword... Apr 29 11:34:05 v2 systemd[1]: Stopped Snips Hotword. Apr 29 11:34:08 v2 systemd[1]: Started Snips Hotword. Apr 29 11:34:09 v2 snips-hotword[6724]: INFO:snips_hotword::server: Using model from /usr/share/snips/assistant/custom_hotword Apr 29 11:34:09 v2 snips-hotword[6724]: INFO:snips_hotword_lib::universal: Loading model "/usr/share/snips/assistant/custom_hotword", hotword_key: Some("hey_snips"), model_id: Some("workflow-hey_snips_subww_feedback_10seeds-2018_12_04T12_13_05_evaluated_model_0002") Apr 29 11:34:13 v2 snips-hotword[6724]: INFO:snips_hotword::server : Discovered audio_server bedroom/mqtt, starting hotword listener Apr 29 11:34:13 v2 snips-hotword[6724]: INFO:snips_hotword::server : Connecting using MQTT site-id bedroom Apr 29 11:34:13 v2 snips-hotword[6724]: INFO:snips_hotword_lib::audio : Audio thread for bedroom started Apr 29 11:34:13 v2 snips-hotword[6724]: INFO:snips_hotword_lib::audio : Net and VAD thread for site bedroom started (vad inhibitor: true, vad messages: false Apr 29 11:34:13 v2 snips-hotword[6724]: INFO:snips_hotword_lib : Detector "detector.hey_snips.bedroom", sensitivity: 0.5, threshold 0.787 Apr 29 11:34:13 v2 snips-hotword[6724]: INFO:snips_hotword_lib : detector.hey_snips.bedroom thread started Apr 29 11:34:15 v2 snips-hotword[6724]: INFO:snips_hotword::server : Discovered audio_server home_cinema/mqtt, starting hotword listener Apr 29 11:34:15 v2 snips-hotword[6724]: INFO:snips_hotword::server : Connecting using MQTT site-id home_cinema Apr 29 11:34:15 v2 snips-hotword[6724]: INFO:snips_hotword_lib::audio : Audio thread for home_cinema started Apr 29 11:34:15 v2 snips-hotword[6724]: INFO:snips_hotword_lib : Detector "detector.hey_snips.home_cinema", sensitivity: 0.5, threshold 0.787 Apr 29 11:34:15 v2 snips-hotword[6724]: INFO:snips_hotword_lib : detector.hey_snips.home_cinema thread started Apr 29 11:34:15 v2 snips-hotword[6724]: INFO:snips_hotword_lib::audio : Net and VAD thread for site home_cinema started (vad inhibitor: true, vad messages: false Apr 29 12:49:05 v2 systemd[1]: Stopping Snips Hotword... Apr 29 12:49:05 v2 systemd[1]: Stopped Snips Hotword. Apr 29 12:49:06 v2 systemd[1]: Started Snips Hotword. Apr 29 12:49:06 v2 snips-hotword[17098]: INFO:snips_hotword::server: Using model from /usr/share/snips/assistant/custom_hotword Apr 29 12:49:06 v2 snips-hotword[17098]: INFO:snips_hotword_lib::universal: Loading model "/usr/share/snips/assistant/custom_hotword", hotword_key: Some("hey_snips"), model_id: Some("workflow-hey_snips_subww_feedback_10seeds-2018_12_04T12_13_05_evaluated_model_0002") Apr 29 12:49:10 v2 snips-hotword[17098]: INFO:snips_hotword::server : Discovered audio_server bedroom/mqtt, starting hotword listener Apr 29 12:49:10 v2 snips-hotword[17098]: INFO:snips_hotword::server : Connecting using MQTT site-id bedroom Apr 29 12:49:10 v2 snips-hotword[17098]: INFO:snips_hotword_lib::audio : Audio thread for bedroom started Apr 29 12:49:10 v2 snips-hotword[17098]: INFO:snips_hotword_lib::audio : Net and VAD thread for site bedroom started (vad inhibitor: true, vad messages: false Apr 29 12:49:10 v2 snips-hotword[17098]: INFO:snips_hotword_lib : Detector "detector.hey_snips.bedroom", sensitivity: 0.5, threshold 0.787 Apr 29 12:49:10 v2 snips-hotword[17098]: INFO:snips_hotword_lib : detector.hey_snips.bedroom thread started Apr 29 12:49:13 v2 snips-hotword[17098]: INFO:snips_hotword::server : Discovered audio_server home_cinema/mqtt, starting hotword listener Apr 29 12:49:13 v2 snips-hotword[17098]: INFO:snips_hotword::server : Connecting using MQTT site-id home_cinema Apr 29 12:49:13 v2 snips-hotword[17098]: INFO:snips_hotword_lib::audio : Audio thread for home_cinema started Apr 29 12:49:13 v2 snips-hotword[17098]: INFO:snips_hotword_lib::audio : Net and VAD thread for site home_cinema started (vad inhibitor: true, vad messages: false Apr 29 12:49:13 v2 snips-hotword[17098]: INFO:snips_hotword_lib : Detector "detector.hey_snips.home_cinema", sensitivity: 0.5, threshold 0.787 Apr 29 12:49:13 v2 snips-hotword[17098]: INFO:snips_hotword_lib : detector.hey_snips.home_cinema thread started Apr 29 13:02:15 v2 systemd[1]: Stopping Snips Hotword... Apr 29 13:02:15 v2 systemd[1]: Stopped Snips Hotword. Apr 29 13:02:15 v2 systemd[1]: Started Snips Hotword. Apr 29 13:02:16 v2 snips-hotword[19076]: INFO:snips_hotword::server: Using model from /usr/share/snips/assistant/custom_hotword Apr 29 13:02:16 v2 snips-hotword[19076]: INFO:snips_hotword_lib::universal: Loading model "/usr/share/snips/assistant/custom_hotword", hotword_key: Some("hey_snips"), model_id: Some("workflow-hey_snips_subww_feedback_10seeds-2018_12_04T12_13_05_evaluated_model_0002") Apr 29 13:02:19 v2 snips-hotword[19076]: INFO:snips_hotword::server : Discovered audio_server bedroom/mqtt, starting hotword listener Apr 29 13:02:19 v2 snips-hotword[19076]: INFO:snips_hotword::server : Connecting using MQTT site-id bedroom Apr 29 13:02:19 v2 snips-hotword[19076]: INFO:snips_hotword_lib::audio : Audio thread for bedroom started Apr 29 13:02:19 v2 snips-hotword[19076]: INFO:snips_hotword_lib::audio : Net and VAD thread for site bedroom started (vad inhibitor: true, vad messages: false Apr 29 13:02:19 v2 snips-hotword[19076]: INFO:snips_hotword_lib : Detector "detector.hey_snips.bedroom", sensitivity: 0.5, threshold 0.787 Apr 29 13:02:19 v2 snips-hotword[19076]: INFO:snips_hotword_lib : detector.hey_snips.bedroom thread started Apr 29 13:02:22 v2 snips-hotword[19076]: INFO:snips_hotword::server : Discovered audio_server home_cinema/mqtt, starting hotword listener Apr 29 13:02:22 v2 snips-hotword[19076]: INFO:snips_hotword::server : Connecting using MQTT site-id home_cinema Apr 29 13:02:22 v2 snips-hotword[19076]: INFO:snips_hotword_lib::audio : Audio thread for home_cinema started Apr 29 13:02:22 v2 snips-hotword[19076]: INFO:snips_hotword_lib : Detector "detector.hey_snips.home_cinema", sensitivity: 0.5, threshold 0.787 Apr 29 13:02:22 v2 snips-hotword[19076]: INFO:snips_hotword_lib : detector.hey_snips.home_cinema thread started Apr 29 13:02:22 v2 snips-hotword[19076]: INFO:snips_hotword_lib::audio : Net and VAD thread for site home_cinema started (vad inhibitor: true, vad messages: false Apr 29 13:19:11 v2 systemd[1]: Stopping Snips Hotword... Apr 29 13:19:11 v2 systemd[1]: Stopped Snips Hotword. Apr 29 13:19:12 v2 systemd[1]: Started Snips Hotword. Apr 29 13:19:12 v2 snips-hotword[21666]: INFO:snips_hotword::server: Using model from /usr/share/snips/assistant/custom_hotword Apr 29 13:19:12 v2 snips-hotword[21666]: INFO:snips_hotword_lib::universal: Loading model "/usr/share/snips/assistant/custom_hotword", hotword_key: Some("hey_snips"), model_id: Some("workflow-hey_snips_subww_feedback_10seeds-2018_12_04T12_13_05_evaluated_model_0002") Apr 29 13:19:16 v2 snips-hotword[21666]: INFO:snips_hotword::server : Discovered audio_server bedroom/mqtt, starting hotword listener Apr 29 13:19:16 v2 snips-hotword[21666]: INFO:snips_hotword::server : Connecting using MQTT site-id bedroom Apr 29 13:19:16 v2 snips-hotword[21666]: INFO:snips_hotword_lib::audio : Audio thread for bedroom started Apr 29 13:19:16 v2 snips-hotword[21666]: INFO:snips_hotword_lib::audio : Net and VAD thread for site bedroom started (vad inhibitor: true, vad messages: false Apr 29 13:19:16 v2 snips-hotword[21666]: INFO:snips_hotword_lib : Detector "detector.hey_snips.bedroom", sensitivity: 0.5, threshold 0.787 Apr 29 13:19:16 v2 snips-hotword[21666]: INFO:snips_hotword_lib : detector.hey_snips.bedroom thread started Apr 29 13:19:19 v2 snips-hotword[21666]: INFO:snips_hotword::server : Discovered audio_server home_cinema/mqtt, starting hotword listener Apr 29 13:19:19 v2 snips-hotword[21666]: INFO:snips_hotword::server : Connecting using MQTT site-id home_cinema Apr 29 13:19:19 v2 snips-hotword[21666]: INFO:snips_hotword_lib::audio : Audio thread for home_cinema started Apr 29 13:19:19 v2 snips-hotword[21666]: INFO:snips_hotword_lib::audio : Net and VAD thread for site home_cinema started (vad inhibitor: true, vad messages: false Apr 29 13:19:19 v2 snips-hotword[21666]: INFO:snips_hotword_lib : Detector "detector.hey_snips.home_cinema", sensitivity: 0.5, threshold 0.787 Apr 29 13:19:19 v2 snips-hotword[21666]: INFO:snips_hotword_lib : detector.hey_snips.home_cinema thread started Apr 29 14:14:13 v2 systemd[1]: Stopping Snips Hotword... Apr 29 14:14:13 v2 systemd[1]: Stopped Snips Hotword. Apr 29 14:14:14 v2 systemd[1]: Started Snips Hotword. Apr 29 14:14:15 v2 snips-hotword[30748]: INFO:snips_hotword::server: Using model from /usr/share/snips/assistant/custom_hotword Apr 29 14:14:15 v2 snips-hotword[30748]: INFO:snips_hotword_lib::universal: Loading model "/usr/share/snips/assistant/custom_hotword", hotword_key: Some("hey_snips"), model_id: Some("workflow-hey_snips_subww_feedback_10seeds-2018_12_04T12_13_05_evaluated_model_0002") Apr 29 14:14:19 v2 snips-hotword[30748]: INFO:snips_hotword::server : Discovered audio_server bedroom/mqtt, starting hotword listener Apr 29 14:14:19 v2 snips-hotword[30748]: INFO:snips_hotword::server : Connecting using MQTT site-id bedroom Apr 29 14:14:19 v2 snips-hotword[30748]: INFO:snips_hotword_lib::audio : Audio thread for bedroom started Apr 29 14:14:19 v2 snips-hotword[30748]: INFO:snips_hotword_lib::audio : Net and VAD thread for site bedroom started (vad inhibitor: true, vad messages: false Apr 29 14:14:19 v2 snips-hotword[30748]: INFO:snips_hotword_lib : Detector "detector.hey_snips.bedroom", sensitivity: 0.5, threshold 0.787 Apr 29 14:14:19 v2 snips-hotword[30748]: INFO:snips_hotword_lib : detector.hey_snips.bedroom thread started Apr 29 14:14:21 v2 snips-hotword[30748]: INFO:snips_hotword::server : Discovered audio_server home_cinema/mqtt, starting hotword listener Apr 29 14:14:21 v2 snips-hotword[30748]: INFO:snips_hotword::server : Connecting using MQTT site-id home_cinema Apr 29 14:14:21 v2 snips-hotword[30748]: INFO:snips_hotword_lib::audio : Audio thread for home_cinema started Apr 29 14:14:21 v2 snips-hotword[30748]: INFO:snips_hotword_lib : Detector "detector.hey_snips.home_cinema", sensitivity: 0.5, threshold 0.787 Apr 29 14:14:21 v2 snips-hotword[30748]: INFO:snips_hotword_lib : detector.hey_snips.home_cinema thread started Apr 29 14:14:21 v2 snips-hotword[30748]: INFO:snips_hotword_lib::audio : Net and VAD thread for site home_cinema started (vad inhibitor: true, vad messages: false Apr 29 14:22:00 v2 snips-hotword[30748]: INFO:snips_hotword_hermes : Hotword detected: site_id:bedroom model:hey_snips (1556540520229ms ago) Apr 29 14:22:00 v2 snips-hotword[30748]: INFO:snips_hotword_lib::audio : Audio thread for site bedroom stopped. Apr 29 14:22:08 v2 snips-hotword[30748]: INFO:snips_hotword_lib::audio : Audio thread for site bedroom started. Apr 29 14:23:10 v2 snips-hotword[30748]: INFO:snips_hotword_hermes : Hotword detected: site_id:home_cinema model:hey_snips (73ms ago) Apr 29 14:23:10 v2 snips-hotword[30748]: INFO:snips_hotword_lib::audio : Audio thread for site home_cinema stopped. Apr 29 14:23:18 v2 snips-hotword[30748]: INFO:snips_hotword_lib::audio : Audio thread for site home_cinema started. Apr 29 14:25:02 v2 snips-hotword[30748]: INFO:snips_hotword_hermes : Hotword detected: site_id:bedroom model:hey_snips (1556540702754ms ago) Apr 29 14:25:02 v2 snips-hotword[30748]: INFO:snips_hotword_lib::audio : Audio thread for site bedroom stopped. Apr 29 14:25:11 v2 snips-hotword[30748]: INFO:snips_hotword_lib::audio : Audio thread for site bedroom started. Apr 29 15:40:40 v2 snips-hotword[30748]: INFO:snips_hotword_hermes : Hotword detected: site_id:bedroom model:hey_snips (1556545240231ms ago) Apr 29 15:40:40 v2 snips-hotword[30748]: INFO:snips_hotword_lib::audio : Audio thread for site bedroom stopped. Apr 29 15:40:46 v2 snips-hotword[30748]: INFO:snips_hotword_lib::audio : Audio thread for site bedroom started.

kali commented 5 years ago

Thanks. Hopefully this will be help us narrow it a bit.

The absurd timestamp are not normal, but the consequences should be benign. Are your "bedroom" device clocks synchronized (like with ntp ?) ? This should not be an issue, displaying the message is the only place where we actually compare the times.

jenskastensson commented 5 years ago

It is the home_cinema which in the ReSpeaker and central unit (and having the memory problems). I think the problem is related to the ReSpeaker, and not to the Bedroom Satellite but I cannot be certain. I'll try verify this but it might take some time

jenskastensson commented 5 years ago

I'm running two Snips core in parallel, one is the mentioned ReSpeaker and the other is a Raspberry. The Raspberry doesn't have onboard mike, satellites only. What's quite confusing is that the Raspberry unit seems to have less problem with the hotword module, however the NLU and ASR sometimes uses a lot of memory . If the three units (asr, nlu and hw) together uses more than 30% of the 950Mb memory , I don't have the distribution but this morning ASR and NLU uses grand majority of the quota. So it seems not to be hotword only problem. This night I had this series of restart on the Raspberry [Mon Apr 29 2019 21:17:53 ] getSnipsMemUsage two consecutive -> 30% restart [Mon Apr 29 2019 22:20:53 ] getSnipsMemUsage two consecutive -> 30% restart [Mon Apr 29 2019 23:11:53 ] getSnipsMemUsage two consecutive -> 30% restart [Tue Apr 30 2019 00:14:53 ] getSnipsMemUsage two consecutive -> 30% restart

Hopefully you will be able to reproduce the problem!

jenskastensson commented 5 years ago

Additional information: There's a mistake in the Snips core versions in my first post: the ReSpeaker was running v0.61.1 The Raspberry Pi in the previous post is running v0.62.3. Sorry for the mistake! I have now upgraded both systems, the RaspBerry Pi restarted twice the last hour: [Tue Apr 30 2019 10:38:25 ] getSnipsMemUsage two consecutive -> 30% restart. nlu:13 asr:8 hw:10 [Tue Apr 30 2019 11:05:25 ] getSnipsMemUsage two consecutive -> 30% restart. nlu:14 asr:9 hw:9