Skip to content
This repository has been archived by the owner on Sep 2, 2024. It is now read-only.

Service get "stuck" and doesn't listen anymore #12

Closed
goldyfruit opened this issue Apr 17, 2023 · 8 comments
Closed

Service get "stuck" and doesn't listen anymore #12

goldyfruit opened this issue Apr 17, 2023 · 8 comments

Comments

@goldyfruit
Copy link
Member

goldyfruit commented Apr 17, 2023 •
edited
Loading

Very randomly, the listener service get stuck, consuming CPU resources. I was not able to really pinpoint the issue but it seems that the service is looping waiting for something.

Here are the logs when it started to not been responsive anymore.

2023-04-17 08:17:02.984 - voice - ovos_bus_client.session:reset_default_session:171 - INFO - New Default Session Start: 163bd72c-3261-4dd0-b5cc-dce57b92cbd0
2023-04-17 08:17:02.989 - voice - ovos_listener.service:handle_wakeword:98 - INFO - Wakeword Detected: hey_mycroft
2023-04-17 08:17:03.007 - voice - ovos_listener.mic:_listen_phrase:950 - DEBUG - Recording...
2023-04-17 08:17:03.009 - voice - ovos_listener.service:handle_record_begin:72 - INFO - Begin Recording...
2023-04-17 08:17:05.369 - voice - ovos_listener.mic:_listen_phrase:956 - INFO - Saving Utterance Recording
2023-04-17 08:17:05.373 - voice - ovos_listener.service:handle_record_end:79 - INFO - End Recording...
2023-04-17 08:17:05.375 - voice - ovos_listener.mic:listen:944 - DEBUG - Thinking...
2023-04-17 08:17:05.399 - voice - ovos_utils.sound:play_end_listening_sound:77 - DEBUG - Could not find 'end_listening' audio file!
2023-04-17 08:17:05.618 - voice - ovos_listener.mic:adjust_for_ambient_noise:976 - INFO - Silence threshold adjusted to 24.0
2023-04-17 08:17:05.620 - voice - ovos_listener.mic:listen:899 - DEBUG - Waiting for wake word...
2023-04-17 08:17:07.692 - voice - ovos_listener:transcribe:211 - DEBUG - STT: what time is it
2023-04-17 08:17:07.695 - voice - ovos_listener.service:handle_utterance:119 - INFO - Utterance: ['what time is it']

And here is a strace Python ovos_listener service.

futex(0x7f7400de40, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0xa3676c, FUTEX_WAKE_PRIVATE, 1)  = 1
openat(AT_FDCWD, "/tmp/mycroft/ipc/mic_level", O_WRONLY|O_CREAT|O_TRUNC|O_CLOEXEC, 0666) = 13
futex(0xa36768, FUTEX_WAIT_BITSET_PRIVATE, 0, {tv_sec=211159, tv_nsec=204258892}, FUTEX_BITSET_MATCH_ANY) = -1 EAGAIN (Resource temporarily unavailable)
futex(0xa36770, FUTEX_WAKE_PRIVATE, 1)  = 0
futex(0xa36770, FUTEX_WAIT_PRIVATE, 2, NULL) = 0
futex(0xa36770, FUTEX_WAKE_PRIVATE, 1)  = 0
newfstatat(13, "", {st_mode=S_IFREG|0644, st_size=0, ...}, AT_EMPTY_PATH) = 0
futex(0xa36768, FUTEX_WAKE_PRIVATE, 1)  = 0
ioctl(13, TCGETS, 0x7eca7ce450)         = -1 ENOTTY (Inappropriate ioctl for device)
futex(0xa3676c, FUTEX_WAIT_BITSET_PRIVATE, 0, {tv_sec=211159, tv_nsec=205143627}, FUTEX_BITSET_MATCH_ANY) = -1 EAGAIN (Resource temporarily unavailable)
futex(0xa36770, FUTEX_WAIT_PRIVATE, 2, NULL) = 0
futex(0xa36770, FUTEX_WAKE_PRIVATE, 1)  = 0
futex(0xa36768, FUTEX_WAIT_BITSET_PRIVATE, 0, {tv_sec=211159, tv_nsec=205437200}, FUTEX_BITSET_MATCH_ANY) = -1 EAGAIN (Resource temporarily unavailable)
futex(0xa36770, FUTEX_WAIT_PRIVATE, 2, NULL) = -1 EAGAIN (Resource temporarily unavailable)
futex(0xa36770, FUTEX_WAKE_PRIVATE, 1)  = 0
futex(0xa3676c, FUTEX_WAKE_PRIVATE, 1)  = 0
futex(0xa36770, FUTEX_WAKE_PRIVATE, 1)  = 0
lseek(13, 0, SEEK_CUR)                  = 0
futex(0xa36768, FUTEX_WAIT_BITSET_PRIVATE, 0, {tv_sec=211159, tv_nsec=206127325}, FUTEX_BITSET_MATCH_ANY) = 0
futex(0xa36770, FUTEX_WAKE_PRIVATE, 1)  = 0
futex(0xa3676c, FUTEX_WAIT_BITSET_PRIVATE, 0, {tv_sec=211159, tv_nsec=206449545}, FUTEX_BITSET_MATCH_ANY) = 0
futex(0xa36770, FUTEX_WAIT_PRIVATE, 2, NULL) = -1 EAGAIN (Resource temporarily unavailable)
futex(0xa36770, FUTEX_WAKE_PRIVATE, 1)  = 0
futex(0xa36768, FUTEX_WAKE_PRIVATE, 1)  = 1
lseek(13, 0, SEEK_CUR)                  = 0
futex(0xa3676c, FUTEX_WAIT_BITSET_PRIVATE, 0, {tv_sec=211159, tv_nsec=207118800}, FUTEX_BITSET_MATCH_ANY) = 0
futex(0xa36770, FUTEX_WAIT_PRIVATE, 2, NULL) = -1 EAGAIN (Resource temporarily unavailable)
futex(0xa36770, FUTEX_WAKE_PRIVATE, 1)  = 0
futex(0xa36768, FUTEX_WAKE_PRIVATE, 1)  = 1
write(13, "Energy:  cur=82 thresh=300.000 m"..., 38) = 38
futex(0xa3676c, FUTEX_WAIT_BITSET_PRIVATE, 0, {tv_sec=211159, tv_nsec=207764981}, FUTEX_BITSET_MATCH_ANY) = -1 EAGAIN (Resource temporarily unavailable)
futex(0xa36770, FUTEX_WAIT_PRIVATE, 2, NULL) = -1 EAGAIN (Resource temporarily unavailable)
futex(0xa36770, FUTEX_WAKE_PRIVATE, 1)  = 0
futex(0xa36768, FUTEX_WAKE_PRIVATE, 1)  = 1
close(13)                               = 0
futex(0x7eb4083f50, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 0, NULL, FUTEX_BITSET_MATCH_ANY) = 0
futex(0xa3676c, FUTEX_WAIT_BITSET_PRIVATE, 0, {tv_sec=211159, tv_nsec=236187850}, FUTEX_BITSET_MATCH_ANY) = 0
futex(0xa36770, FUTEX_WAKE_PRIVATE, 1)  = 0
newfstatat(AT_FDCWD, "/home/ovos/.mycroft/mycroft.conf", 0x7eca7ce360, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/ovos/.mycroft/mycroft.conf", 0x7eca7ce300, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/ovos/.mycroft/mycroft.conf", 0x7eca7ce320, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/ovos/.mycroft/mycroft.conf", 0x7eca7ce320, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/ovos/.mycroft/mycroft.conf", 0x7eca7ce320, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/ovos/.mycroft/mycroft.conf", 0x7eca7ce320, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/ovos/.mycroft/mycroft.conf", 0x7eca7ce320, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/ovos/.mycroft/mycroft.conf", 0x7eca7ce320, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/ovos/.mycroft/mycroft.conf", 0x7eca7ce320, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/ovos/.mycroft/mycroft.conf", 0x7eca7ce320, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/ovos/.mycroft/mycroft.conf", 0x7eca7ce320, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/ovos/.mycroft/mycroft.conf", 0x7eca7ce320, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/ovos/.mycroft/mycroft.conf", 0x7eca7ce320, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/ovos/.mycroft/mycroft.conf", 0x7eca7ce320, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/ovos/.mycroft/mycroft.conf", 0x7eca7ce320, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/ovos/.mycroft/mycroft.conf", 0x7eca7ce320, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/ovos/.mycroft/mycroft.conf", 0x7eca7ce320, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/ovos/.mycroft/mycroft.conf", 0x7eca7ce320, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/ovos/.mycroft/mycroft.conf", 0x7eca7ce320, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/ovos/.mycroft/mycroft.conf", 0x7eca7ce320, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/ovos/.mycroft/mycroft.conf", 0x7eca7ce320, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/ovos/.mycroft/mycroft.conf", 0x7eca7ce320, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/ovos/.mycroft/mycroft.conf", 0x7eca7ce320, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/ovos/.mycroft/mycroft.conf", 0x7eca7ce320, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/ovos/.mycroft/mycroft.conf", 0x7eca7ce320, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/ovos/.mycroft/mycroft.conf", 0x7eca7ce320, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/ovos/.mycroft/mycroft.conf", 0x7eca7ce320, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/ovos/.mycroft/mycroft.conf", 0x7eca7ce320, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/ovos/.mycroft/mycroft.conf", 0x7eca7ce320, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/ovos/.mycroft/mycroft.conf", 0x7eca7ce320, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/ovos/.mycroft/mycroft.conf", 0x7eca7ce320, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/ovos/.mycroft/mycroft.conf", 0x7eca7ce320, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/ovos/.mycroft/mycroft.conf", 0x7eca7ce320, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/ovos/.mycroft/mycroft.conf", 0x7eca7ce320, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/ovos/.mycroft/mycroft.conf", 0x7eca7ce320, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/tmp/mycroft/ipc", {st_mode=S_IFDIR|0777, st_size=4096, ...}, 0) = 0
newfstatat(AT_FDCWD, "/tmp/mycroft/ipc/signal/buttonPress", 0x7eca7ce640, 0) = -1 ENOENT (No such file or directory)
futex(0x7f7400de40, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x7eb4083f50, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 0, NULL, FUTEX_BITSET_MATCH_ANY) = 0
futex(0xa36768, FUTEX_WAIT_BITSET_PRIVATE, 0, {tv_sec=211159, tv_nsec=321670439}, FUTEX_BITSET_MATCH_ANY) = 0
futex(0xa36770, FUTEX_WAKE_PRIVATE, 1)  = 0

I got this forever in strace log.

For some reason, the service seems to look for this /home/ovos/.mycroft/mycroft.conf file which doesn't not exist but I don't think this is the issue.
@JarbasAl
Copy link
Member

do you have a VAD plugin enabled? might be the same as #17 (undiagnosed)

@goldyfruit
Copy link
Member Author

goldyfruit commented Apr 17, 2023 •
edited
Loading

do you have a VAD plugin enabled? might be the same as OpenVoiceOS/ovos-listener#17 (undiagnosed)

Yes I do, the webrtcvad plugin but the plugin is correctly loaded.

@JarbasAl
Copy link
Member

JarbasAl commented May 1, 2023

did you have wakeword/utterance upload enabled?

could this be coming from OpenVoiceOS/ovos-backend-client#36

@goldyfruit
Copy link
Member Author 

│ listener                                                     │                                                                                                                                                                             │
│     sample_rate                                              │ 16000                                                                                                                                                                       │
│     mic_meter_ipc                                            │ False                                                                                                                                                                       │
│     record_wake_words                                        │ True                                                                                                                                                                        │
│     save_utterances                                          │ True                                                                                                                                                                        │
│     wake_word_upload                                         │                                                                                                                                                                             │
│         disable                                              │ True                                                                                                                                                                        │
│         url                                                  │                                                                                                                                                                             │
│     VAD                                                      │                                                                                                                                                                             │
│         silence_method                                       │ vad_and_ratio                                                                                                                                                               │
│         speech_seconds                                       │ 0.1                                                                                                                                                                         │
│         silence_seconds                                      │ 0.5                                                                                                                                                                         │
│         before_seconds                                       │ 0.5                                                                                                                                                                         │
│         min_seconds                                          │ 1                                                                                                                                                                           │
│         max_current_ratio_threshold                          │ 2                                                                                                                                                                           │
│         initial_energy_threshold                             │ 1000.0                                                                                                                                                                      │
│         module                                               │ ovos-vad-plugin-silero                                                                                                                                                      │
│         ovos-vad-plugin-silero                               │                                                                                                                                                                             │
│             threshold                                        │ 0.2                                                                                                                                                                         │
│         ovos-vad-plugin-webrtcvad                            │                                                                                                                                                                             │
│             vad_mode                                         │ 3                                                                                                                                                                           │
│         ovos-vad-plugin-precise                              │                                                                                                                                                                             │
│             debug                                            │ True                                                                                                                                                                        │
│     retry_mic_init                                           │ True                                                                                                                                                                        │
│     mute_during_output                                       │ False                                                                                                                                                                       │
│     duck_while_listening                                     │ 0.3                                                                                                                                                                         │
│     phoneme_duration                                         │ 120                                                                                                                                                                         │
│     multiplier                                               │ 1.0                                                                                                                                                                         │
│     energy_ratio                                             │ 1.5                                                                                                                                                                         │
│     wake_word                                                │ hey_mycroft                                                                                                                                                                 │
│     stand_up_word                                            │ wake_up                                                                                                                                                                     │
│     recording_timeout                                        │ 10.0                                                                                                                                                                        │
│     recording_timeout_with_silence                           │ 0.8                                                                                                                                                                         │
│     instant_listen                                           │ True                                                                                                                                                                        │
│     continuous_listen                                        │ False                                                                                                                                                                       │
│     hybrid_listen                                            │ False                                                                                                                                                                       │
│     listen_timeout                                           │ 45

@j1nx
Copy link
Member

j1nx commented May 1, 2023

Can you reproduce the issue with a restart of PulseAudio?

@goldyfruit
Copy link
Member Author

goldyfruit commented May 1, 2023 •
edited
Loading

Can you reproduce the issue with a restart of PulseAudio?

Yes, this is the same behaviour as when PulseAudio or PipeWire are restarted except that when it happens, I got a specific message in the logs:

Expression 'alsa_snd_pcm_poll_descriptors_revents( self->pcm, pfds, self->nfds, &revents )' failed in 'src/hostapi/alsa/pa_linux_alsa.c', line: 3665
Expression 'PaAlsaStreamComponent_EndPolling( &self->capture, capturePfds, &pollCapture, &xrun )' failed in 'src/hostapi/alsa/pa_linux_alsa.c', line: 3887
Expression 'PaAlsaStream_WaitForFrames( stream, &framesAvail, &xrun )' failed in 'src/hostapi/alsa/pa_linux_alsa.c', line: 4285

@j1nx
Copy link
Member

j1nx commented May 4, 2023

So basically, an error occurs within the audio system making the voice service not reconnecting anymore.

In this case, the sound system most likely quickly recovers itself and just carry on, however when the voice service looses connection, it never re-connect again.

It is an old problem that surfaces.

This can be solved by some sort of microphone watchdog that quickly reconnects and/or restarts when it looses connection to the microphone. This does not solve the underlying reason of the sound system error, but sound issues/errors can happen often for different reasons without any clear cause. However the voice service should be able to identify that it lost microphone connection and recover from it.

@goldyfruit
Copy link
Member Author

It is an old problem that surfaces.

I guess it would be valuable as well for the audio service.

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@goldyfruit @j1nx @JarbasAl