sonus stops sending events after overnight idle

[sdetweil]

index.js.txt
timeStamp.js.txt

using sonus in the smart mirror project, with latest code (0.1.9), after mirror runs overnight (in sleep mode)
on wakeup, there are no reco events being posted from sonus to smart mirror..
the sonus node process is still running

I am adding debug to see the flow, and will post on wed 12/22 after capture.
attached is the index.js with the trace entries so u can see where they happen
also the timestamp file used by the logging.. (goes in the smart-mirror folder)

sample

11/21/2017 7:55:05 AM module detector trigger hotword
11/21/2017 7:55:05 AM cloudSpeechRecognizer setup to listen
11/21/2017 7:55:05 AM module detector trigger streaming ready
11/21/2017 7:55:05 AM module detector ready for more
11/21/2017 7:55:05 AM module detector silence
11/21/2017 7:55:05 AM module detector silence
11/21/2017 7:55:05 AM module detector silence
11/21/2017 7:55:05 AM module detector silence
11/21/2017 7:55:05 AM module detector silence
11/21/2017 7:55:05 AM module detector silence
11/21/2017 7:55:06 AM module detector silence
11/21/2017 7:55:06 AM module detector silence
11/21/2017 7:55:06 AM module detector silence
11/21/2017 7:55:06 AM module detector silence
11/21/2017 7:55:06 AM module detector sound
11/21/2017 7:55:06 AM module detector sound
11/21/2017 7:55:06 AM module detector sound
11/21/2017 7:55:06 AM module detector sound
11/21/2017 7:55:07 AM module detector sound
11/21/2017 7:55:07 AM module detector sound
11/21/2017 7:55:07 AM module detector sound
11/21/2017 7:55:07 AM module detector sound
11/21/2017 7:55:07 AM module detector silence
11/21/2017 7:55:07 AM module detector silence
11/21/2017 7:55:07 AM module detector silence
11/21/2017 7:55:07 AM module detector silence
11/21/2017 7:55:08 AM module detector silence
11/21/2017 7:55:08 AM module detector silence
11/21/2017 7:55:08 AM module detector silence
11/21/2017 7:55:08 AM module detector silence
11/21/2017 7:55:08 AM module detector silence
11/21/2017 7:55:08 AM module detector silence
11/21/2017 7:55:08 AM module detector silence
11/21/2017 7:55:08 AM module detector silence
11/21/2017 7:55:09 AM module detector silence
11/21/2017 7:55:09 AM module detector silence
11/21/2017 7:55:09 AM module detector silence
11/21/2017 7:55:09 AM module detector silence
11/21/2017 7:55:09 AM module detector silence
11/21/2017 7:55:09 AM module detector silence
11/21/2017 7:55:09 AM module detector silence
11/21/2017 7:55:09 AM module detector silence
11/21/2017 7:55:10 AM module detector silence
11/21/2017 7:55:10 AM module detector silence
11/21/2017 7:55:10 AM module detector silence
11/21/2017 7:55:11 AM module detector silence
11/21/2017 7:55:11 AM module detector silence
11/21/2017 7:55:11 AM module detector silence
11/21/2017 7:55:11 AM module detector sound
11/21/2017 7:55:12 AM module detector sound
11/21/2017 7:55:12 AM module detector sound
11/21/2017 7:55:12 AM module detector sound
11/21/2017 7:55:12 AM module detector sound
11/21/2017 7:55:12 AM module detector sound
11/21/2017 7:55:12 AM module detector sound
11/21/2017 7:55:12 AM module detector sound
11/21/2017 7:55:12 AM module detector sound
11/21/2017 7:55:13 AM module detector silence
11/21/2017 7:55:13 AM module detector silence
11/21/2017 7:55:13 AM module detector sound
11/21/2017 7:55:13 AM module detector sound
11/21/2017 7:55:13 AM module detector sound
11/21/2017 7:55:13 AM module detector sound
11/21/2017 7:55:13 AM module detector silence
11/21/2017 7:55:13 AM module detector silence
11/21/2017 7:55:14 AM module detector silence
11/21/2017 7:55:14 AM module detector silence
11/21/2017 7:55:14 AM module detector silence
11/21/2017 7:55:14 AM module detector silence
11/21/2017 7:55:14 AM module detector silence
11/21/2017 7:55:14 AM module detector silence
11/21/2017 7:55:14 AM module detector silence
11/21/2017 7:55:14 AM module detector silence
11/21/2017 7:55:15 AM module detector silence
11/21/2017 7:55:15 AM module detector silence
11/21/2017 7:55:15 AM module detector silence
11/21/2017 7:55:15 AM module detector silence
11/21/2017 7:55:15 AM module detector silence
11/21/2017 7:55:15 AM module detector silence
11/21/2017 7:55:15 AM module detector silence
11/21/2017 7:55:15 AM module detector silence
11/21/2017 7:55:16 AM module detector silence
11/21/2017 7:55:16 AM module detector silence
11/21/2017 7:55:16 AM module detector silence
11/21/2017 7:55:16 AM module detector silence
11/21/2017 7:55:16 AM module detector silence
11/21/2017 7:55:16 AM module detector silence
11/21/2017 7:55:16 AM module detector silence
11/21/2017 7:55:16 AM module detector silence
11/21/2017 7:55:17 AM module detector silence
11/21/2017 7:55:17 AM module detector silence
11/21/2017 7:55:17 AM module detector silence
11/21/2017 7:55:17 AM module detector silence
11/21/2017 7:55:17 AM cloudSpeechRecognizer data
11/21/2017 7:55:17 AM cloudSpeechRecognizer data something else
11/21/2017 7:55:17 AM cloudSpeechRecognizer data something else no prior results
11/21/2017 7:55:17 AM module detector csr final result
11/21/2017 7:55:17 AM module detector csr no longer listening
11/21/2017 7:55:17 AM cloudSpeechRecognizer data <-------- this seems bad if not listening.
11/21/2017 7:55:17 AM cloudSpeechRecognizer some data
11/21/2017 7:55:17 AM module detector csr partial show
11/21/2017 7:55:17 AM cloudSpeechRecognizer data partial=show
11/21/2017 7:55:17 AM module detector silence
11/21/2017 7:55:17 AM cloudSpeechRecognizer data
11/21/2017 7:55:17 AM cloudSpeechRecognizer some data
11/21/2017 7:55:17 AM module detector csr partial show me
11/21/2017 7:55:17 AM cloudSpeechRecognizer data partial=show me
11/21/2017 7:55:17 AM cloudSpeechRecognizer data
11/21/2017 7:55:17 AM cloudSpeechRecognizer some data
11/21/2017 7:55:17 AM module detector csr partial show map
11/21/2017 7:55:17 AM cloudSpeechRecognizer data partial=show map
11/21/2017 7:55:17 AM cloudSpeechRecognizer data
11/21/2017 7:55:17 AM cloudSpeechRecognizer some data
11/21/2017 7:55:17 AM module detector csr partial show
11/21/2017 7:55:17 AM cloudSpeechRecognizer data partial=show
11/21/2017 7:55:17 AM cloudSpeechRecognizer data
11/21/2017 7:55:17 AM cloudSpeechRecognizer some data
11/21/2017 7:55:17 AM module detector csr partial show map
11/21/2017 7:55:17 AM cloudSpeechRecognizer data partial=show map
11/21/2017 7:55:17 AM module detector silence
11/21/2017 7:55:17 AM cloudSpeechRecognizer data
11/21/2017 7:55:17 AM cloudSpeechRecognizer some data
11/21/2017 7:55:17 AM module detector csr final result show map
11/21/2017 7:55:17 AM cloudSpeechRecognizer data final
11/21/2017 7:55:17 AM module detector csr no longer listening

[sdetweil]

the new debug shows the background snowboy seems to be hung sending 'sound' events.

I have more log than this, but this is all that happens after this point

11/22/2017 2:41:33 AM module detector silence
11/22/2017 2:41:33 AM module detector silence
11/22/2017 2:41:33 AM module detector silence
11/22/2017 2:41:33 AM module detector silence
11/22/2017 2:41:33 AM module detector silence
11/22/2017 2:41:33 AM module detector silence
11/22/2017 2:41:33 AM module detector silence
11/22/2017 2:41:33 AM module detector sound <---- starting here, this is all that sonus receives.
I am asleep at this time
11/22/2017 2:41:34 AM module detector sound
11/22/2017 2:41:34 AM module detector sound
11/22/2017 2:41:34 AM module detector sound
11/22/2017 2:41:34 AM module detector sound
11/22/2017 2:41:34 AM module detector sound
11/22/2017 2:41:34 AM module detector sound
11/22/2017 2:41:34 AM module detector sound
11/22/2017 2:41:35 AM module detector sound
11/22/2017 2:41:35 AM module detector sound
11/22/2017 2:41:35 AM module detector sound
11/22/2017 2:41:35 AM module detector sound
11/22/2017 2:41:35 AM module detector sound
11/22/2017 2:41:35 AM module detector sound
11/22/2017 2:41:35 AM module detector sound
11/22/2017 2:41:35 AM module detector sound

[evancohen]

I'm assuming your running this on the Pi. I get back to Seattle on Monday, so I can run this overnight and see if I get similar results on Tuesday.

[sdetweil]

yes on pi

happens every overnight

latest sonus index.js here, I looked at the snowboy samples and they had a callback for error, which u didn't use.. I added it and added a debug entry to that.. sadly they don't pass back the error info

  detector.on('silence', () => {writelog('module detector silence');sonus.emit('silence')})
  detector.on('sound', () => {writelog('module detector sound');sonus.emit('sound')})
  detector.on('error', () => {writelog('module detector error');sonus.emit('error','')})

tonight will have another report with that info added.
index.js.txt

[sdetweil]

same results no errors, interesting that the failure is near the same time. (2:30 vs 2:41 central)

1/23/2017 2:30:29 AM module detector silence
11/23/2017 2:30:29 AM module detector silence
11/23/2017 2:30:29 AM module detector silence
11/23/2017 2:30:29 AM module detector silence
11/23/2017 2:30:29 AM module detector silence
11/23/2017 2:30:29 AM module detector sound <---- starting here, this is all that sonus receives.
11/23/2017 2:30:29 AM module detector sound
11/23/2017 2:30:29 AM module detector sound
11/23/2017 2:30:30 AM module detector sound
11/23/2017 2:30:30 AM module detector sound
11/23/2017 2:30:30 AM module detector sound
11/23/2017 2:30:30 AM module detector sound

[evancohen]

Awesome, the more data the better. Can you include the full log in a Pastebin?

[sdetweil]

two links to log files here
https://pastebin.com/TvUz8YRx

[sdetweil]

next update, I started the mirror code after midnight, told it to go to sleep, and it worked at 7am.

[sdetweil]

failed again, this time during the day.. its 18 hours 43 minutes after start.. I will check the prior runs to see the elapsed time.

prior runs started getting continuous 'sound' events at 18:49 and 18:43 minutes elapsed. all have had a date change.. 7:47am-02:30am, 7:52am-2:41am, 11:26pm-6:09pm

seems unlikely this is coincidence...

[sdetweil]

I created issue 315 in snowboy Kitt-AI/snowboy#315

[sdetweil]

this is an alsa arecord bug/design issue.. the code is not intended to run 24x7. i am testing a set of fixes to work around this. I will create a pull request with the changes

[sdetweil]

posted pull request which will help fix this problem.

[evancohen]

Closing because this is now fixed!