pyaudio causes "snd_bcm2835..Interrupted..waiting for lock"

[lowflyerUK]

Initially posted here. Raised here at Dom's request.

I have just upgraded my server to a nice new B2 :) and pyaudio started freezing when something else uses the sound system.

It is (relatively) easy to replicate the issue. The symptoms are exactly the same in the following 3 cases:

1. a completely fresh 2015-02-16-raspbian-wheezy.img
2. a fresh 2015-02-16-raspbian-wheezy.img with sudo apt-get update && sudo apt-get upgrade (on 16/4/2015)
3. a fresh 2015-02-16-raspbian-wheezy.img with sudo apt-get update && sudo apt-get upgrade and sudo rpi-update (3.18.11-v7+ external USB drive: blk_update_request: I/O error and the USB drive gets another /dev/sd node #777)

The B2 has a USB keyboard, hdmi monitor and Broadcom USB Wi-Fi adapter with 2 USB ports (0a5c:bd1e).

What I did:

Flash SDcard with 2015-02-16-raspbian-wheezy.img.
Expand the ext4 filesystem to 5GBytes using gparted on my linux box.
Mount the ext4 filesystem in linux and add my Wi-Fi network to /etc/wpa_supplicant/wpa_supplicant.conf.
Put the SDcard in the B2, boot it and ssh into it.
Check the hdmi speakers work with

speaker-test -c2 -D hw:0,0

then kill speaker-test with CTRL-C
Install pyaudio with

sudo apt-get update
sudo apt-get install python-pyaudio

Check that pyaudio is working by running

import pyaudio

def list_devices():
    # List all audio input devices
    p = pyaudio.PyAudio()
    i = 0
    n = p.get_device_count()
    while i < n:
        print p.get_device_info_by_index(i)
        print '\r\r'
        dev = p.get_device_info_by_index(i)
        if dev['maxInputChannels'] > 0:
            print str(i)+'. '+dev['name']
        i += 1

if __name__ == '__main__':
    list_devices()

After the normal ALSA lib warnings, this gives a list of the sound devices found.

So far this is normal behaviour. Now for the error:
Launch the speaker-test again as above and leave it running. Open a second ssh terminal and in that run the python code above while the speaker-test is still running in the first terminal. Python hangs immediately and needs a few CTRL-Cs before it comes back fully to bash. Go back to the speaker-test which is still running. Kill it with CTRL-C and relaunch it. It fails. In /var/log/kern.log you see a few of these

Apr 16 13:21:29 raspberrypi kernel: [ 1694.022420] snd_bcm2835_playback_open_generic:124 Interrupted whilst waiting for lock
Apr 16 13:21:30 raspberrypi kernel: [ 1694.946695] snd_bcm2835_playback_open_generic:124 Interrupted whilst waiting for lock
Apr 16 13:21:31 raspberrypi kernel: [ 1695.508283] snd_bcm2835_playback_open_generic:124 Interrupted whilst waiting for lock
Apr 16 13:21:34 raspberrypi kernel: [ 1699.245895] snd_bcm2835_playback_close:226 Interrupted whilst waiting for loc

It seems that the sound system is now locked up until the module is removed and reloaded

sudo modprobe -r snd_bcm2835
sudo modprobe snd_bcm2835

after which it is the same as freshly booted.

As ever many thanks for everything!!!!!!

[popcornmix]

I can confirm this sequence is not happy. I see this in dmesg log:

[ 4538.397958] bcm2835_audio_close:767 bcm2835_audio_close: failed on waiting for event (status=0)
[ 4538.398144] vc_vchi_audio_deinit:348 vc_vchi_audio_deinit: failed to close VCHI service connection (status=1)

[popcornmix]

Fix here: bb6b4b6
Will be next firmware update.

[popcornmix]

Okay, firmware updated. Please run sudo rpi-update and test.

[lowflyerUK]

Okay! You are a star!! I can confirm that after the rpi-update, concurrent instances of pyaudio and speaker-test can be opened, run and closed correctly. So I am very happy!

However I still get

[392.960571]bcm2835_audio_close:767 bcm2835_audio_close: failed on waiting for event (status=0)

[392.960625] vc_vchi_audio_deinit:348 vc_vchi_audio_deinit: failed to close VCHI service connection (status=1)

in dmesg log. I think I get one pair of these every time I kill a speaker-test with CTRL-C but not if the speaker-test ends itself - for example by running:

speaker-test -c2 -D hw:0,0 -s1

This is clearly not a problem in any way.

Thanks for your very quick action!

[popcornmix]

The good news is those messages in log can be safely ignored. I've changed the severity of those messages locally and CTRL-C of speaker-test is now quiet. I'll include that in next firmware update.

[popcornmix]

Latest rpi-update firmware should remove the complaints in dmesg when killing processes using alsa. Can you test?

[lowflyerUK]

Yes, I can confirm that I don't see those messages when killing speaker-test.

And the pyaudio works fine at the same time as speaker-test.

I would say that this issue is SOLVED! Many thanks for your help!