Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

VC audio service locks up #696

Closed
gonzoua opened this issue Dec 10, 2016 · 4 comments
Closed

VC audio service locks up #696

gonzoua opened this issue Dec 10, 2016 · 4 comments

Comments

@gonzoua
Copy link

gonzoua commented Dec 10, 2016

I am working on improving VCHI audio driver for FreeBSD and while debugging I came across what I believe is a firmware issue. Firmware gets into weird state: audio plays fine for couple hours then kernel receives VC_AUDIO_MSG_TYPE_COMPLETE callback with error bit set (bit 30) and some invalid data in count part. After that no audio can go through, any submit operation ends with the same callback: error bit set.

Driver works like this:

  • On initialization it connects to audio service and passes VC_AUDIO_MSG_TYPE_OPEN message
  • When playback starts it passes VC_AUDIO_MSG_TYPE_START
  • Samples are submitted in 4000 bytes packets, and maximum 32000 bytes are allowed to be buffered on VC side
  • When playback stops VC_AUDIO_MSG_TYPE_STOP message is sent to VC

I use headphones output and my test is mpg123 playing bunch of mp3s. mpg123 does not issue stop/start between files, so essentially it's: start playback, submit audio samples for 2 hours, firmware audio service locks up

There is no vcdbg for FreeBSD so I can't check VC logs or examine its state in any other way. Any help with troubleshooting this issue would be appreciated.

@gonzoua
Copy link
Author

gonzoua commented Dec 12, 2016

This seems to be a problem only with PWM audio. HDMI audio didn't stuck for almost two days. I tested it with destination set to HDMI but without actual hardware connected. I do not have audio-enabled HDMI device here. I will try to tun the test with HDMI audio device too.

@popcornmix
Copy link
Contributor

The complete.count field of VC_AUDIO_MSG_TYPE_COMPLETE message indicated the number of samples output since last "complete" message was sent.
Bit 30 being set in message means stream has finished (i.e. we have played all samples given to us).

It will be hard to debug this. Options are:
Reproduce with raspbian. If it's a firmware bug then you may expect it to occur there.
Get vcdbg working on FreeBSD. Logging may provide useful info.
Provide me with what is needed to reproduce. I can extract the log through firmware debugger. I guess this would need to be an sdcard image that auto runs the music playback. Ideally keep it as simple as possible, and have it fail as quickly as possible.

@gonzoua
Copy link
Author

gonzoua commented Dec 15, 2016

Thanks for explanation of bit 30.

When preparing image I realized that I used old firmware binaries for test. After updating to the latest master I was able to play audio for more than 20 hours so far. I'll run the test over weekend to make sure that this lock-up is indeed fixed. I noticed several cases of 1-second or so pauses in playback though. They were not caused by samples starvation because VC never reported bit 30 in callback.

Although the issue doesn't seem to be in latest fw I'd still like to get vcdbg running on FreeBSD if possible, that would give better visibility of what's happening on VC side and probably make debugging easier. Is there sources for vcdbg or do you need image with build environment to prepare binaries? Most of userland VC tools should be compilable on FreeBSD as-is or with minor changes.

uqs pushed a commit to freebsd/freebsd-src that referenced this issue Dec 27, 2016
Rework general approach to locking and working with audio worker thread:

- Use flags to signal requested worker action
- Fix submitted buffer calculations to avoid samples starvation
- Protect buffer pointers with locks to fix race condition between callback
  and audio worker thread
- Remove unnecessary vchi_service_use
- Do not use lock to serialize VCHI requests since only one thread issues them now
- Fix unloading signaling per hselasky@ suggestion
- Add output to detect inconsistent callback data caused by possible firmware bug
  raspberrypi/firmware#696
- Add stats/debug sysctls to troubleshoot possible bugs

PR:		213687, 205979, 215194
MFC after:	1 week


git-svn-id: svn+ssh://svn.freebsd.org/base/head@310636 ccf9f872-aa2e-dd11-9fc8-001c23d0bc1f
uqs pushed a commit to freebsd/freebsd-src that referenced this issue Dec 27, 2016
Rework general approach to locking and working with audio worker thread:

- Use flags to signal requested worker action
- Fix submitted buffer calculations to avoid samples starvation
- Protect buffer pointers with locks to fix race condition between callback
  and audio worker thread
- Remove unnecessary vchi_service_use
- Do not use lock to serialize VCHI requests since only one thread issues them now
- Fix unloading signaling per hselasky@ suggestion
- Add output to detect inconsistent callback data caused by possible firmware bug
  raspberrypi/firmware#696
- Add stats/debug sysctls to troubleshoot possible bugs

PR:		213687, 205979, 215194
MFC after:	1 week
bdrewery pushed a commit to bdrewery/freebsd that referenced this issue Jan 3, 2017
Rework general approach to locking and working with audio worker thread:

- Use flags to signal requested worker action
- Fix submitted buffer calculations to avoid samples starvation
- Protect buffer pointers with locks to fix race condition between callback
  and audio worker thread
- Remove unnecessary vchi_service_use
- Do not use lock to serialize VCHI requests since only one thread issues them now
- Fix unloading signaling per hselasky@ suggestion
- Add output to detect inconsistent callback data caused by possible firmware bug
  raspberrypi/firmware#696
- Add stats/debug sysctls to troubleshoot possible bugs

PR:		213687, 205979, 215194
MFC after:	1 week


git-svn-id: svn+ssh://svn.freebsd.org/base/head@310636 ccf9f872-aa2e-dd11-9fc8-001c23d0bc1f
uqs pushed a commit to freebsd/freebsd-src that referenced this issue May 8, 2017
r308424:
Fix locking in bcm2835_audio driver

- Move all VCHI activity to worker thread: channel methods are called with
    non-sleepable lock held and VCHI uses sleepable lock.

- In worker thread use sx(9) lock instead of mutex(9) for the same reason.

PR:		213801, 205979

r310636:
[rpi] Fix bcm2835_audio locking and samples starvation

Rework general approach to locking and working with audio worker thread:

- Use flags to signal requested worker action
- Fix submitted buffer calculations to avoid samples starvation
- Protect buffer pointers with locks to fix race condition between callback
  and audio worker thread
- Remove unnecessary vchi_service_use
- Do not use lock to serialize VCHI requests since only one thread issues them now
- Fix unloading signaling per hselasky@ suggestion
- Add output to detect inconsistent callback data caused by possible firmware bug
  raspberrypi/firmware#696
- Add stats/debug sysctls to troubleshoot possible bugs

PR:		213687, 205979, 215194
mat813 pushed a commit to mat813/freebsd that referenced this issue May 9, 2017
r308424:
Fix locking in bcm2835_audio driver

- Move all VCHI activity to worker thread: channel methods are called with
    non-sleepable lock held and VCHI uses sleepable lock.

- In worker thread use sx(9) lock instead of mutex(9) for the same reason.

PR:		213801, 205979

r310636:
[rpi] Fix bcm2835_audio locking and samples starvation

Rework general approach to locking and working with audio worker thread:

- Use flags to signal requested worker action
- Fix submitted buffer calculations to avoid samples starvation
- Protect buffer pointers with locks to fix race condition between callback
  and audio worker thread
- Remove unnecessary vchi_service_use
- Do not use lock to serialize VCHI requests since only one thread issues them now
- Fix unloading signaling per hselasky@ suggestion
- Add output to detect inconsistent callback data caused by possible firmware bug
  raspberrypi/firmware#696
- Add stats/debug sysctls to troubleshoot possible bugs

PR:		213687, 205979, 215194


git-svn-id: https://svn.freebsd.org/base/stable/11@317974 ccf9f872-aa2e-dd11-9fc8-001c23d0bc1f
@JamesH65
Copy link
Contributor

Closing this issue as questions answered/issue resolved.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants