Fix deadlock on process termination

[Shulyaka]

Fixes #26
Fixes #27
Fixes #29
Fixes #31
Fixes #55

From the asyncio.subprocess.wait specification:

Note: This method can deadlock when using stdout=PIPE or stderr=PIPE and the child process generates so much output that it blocks waiting for the OS pipe buffer to accept more data. Use the communicate() method when using pipes to avoid this condition.

This is exactly what we are doing.

1. Start the process with stdout=PIPE
2. Example for the mic program: read from the process until ASR is done
3. Signal the process to stop and wait till it finishes

If between 2 and 3 the process outputs more data (as mic continues to record the sound), it creates a deadlock: we wait for the process to finish and the process waits for us to read the data he had already sent us.
This PR fixes that race condition as recommended in the documentation, by using communicate(), which will read all the data and then wait for the process to terminate.

[ethereal-engineer]

I've just been running through the original tutorial again (with this patch in place), and it crashes with error on the step:

script/run bin/mic_record_sample.py sample.wav

Sadly, reverting the patch fixes this crash. So more work is needed somewhere.

[ethereal-engineer]

I've been doing some more testing with and without the patch. I will raise a new issue with more information later on (I have also reduced my config file to bare minimums).

[Shulyaka]

Hi @ethereal-engineer

Please share the debug logs (add --debug flag to your command)

[ethereal-engineer]

Hi @ethereal-engineer

Please share the debug logs (add --debug flag to your command)

At the moment I'm always running with debug on. Just wondering if the debug flag is passed on to the subprograms because there is little output.

[Shulyaka]

Yes, there is little debug output in general, but at least may give some more information on where and what is crushing

[Shulyaka]

Feel free to add your own debug info

[pipsen]

Still have problems....

Docker starts, mic and wakeword detection working, after wakeword recognition, I see this log:

DEBUG:rhasspy3_http_api.pipeline:run: mic=PipelineProgramConfig(name='arecord', template_args=None, after=None),wake=PipelineProgramConfig(name='porcupine1', template_args=None, after=None),vad=PipelineProgramConfig(name='silero', template_args=None, after=None),asr=PipelineProgramConfig(name='faster-whisper.client', template_args=None, after=None),intent=None,handle=PipelineProgramConfig(name='repeat', template_args=None, after=None),tts=PipelineProgramConfig(name='piper.client', template_args=None, after=None),snd=PipelineProgramConfig(name='aplay', template_args=None, after=None),start_after=None stop_after=None DEBUG:rhasspy3.program:mic_adapter_raw.py ['--samples-per-chunk', '1024', '--rate', '16000', '--width', '2', '--channels', '1', 'arecord -q -D "plughw:CARD=USB,DEV=0" -r 16000 -c 1 -f S16_LE -t raw -'] DEBUG:rhasspy3.program:client_unix_socket.py ['var/run/faster-whisper.socket'] DEBUG:rhasspy3.program:.venv/bin/python3 ['bin/porcupine_stream.py', '--model', 'porcupine_linux.ppn'] DEBUG:rhasspy3.wake:detect: processing audio DEBUG:rhasspy3.wake:detect: Detection(name='porcupine_linux', timestamp=5071590488178204) DEBUG:rhasspy3.program:vad_adapter_raw.py ['--rate', '16000', '--width', '2', '--channels', '1', '--samples-per-chunk', '512', 'script/speech_prob "share/silero_vad.onnx"'] DEBUG:rhasspy3.vad:segment: processing audio DEBUG:rhasspy3.vad:segment: speaking started DEBUG:rhasspy3.vad:segment: speaking ended

=> After that, nothing is happening any more, stuck

[Shulyaka]

@pipsen If you restart your faster-whisper server, does it help? Any logs from the faster-whisper server?