Featured Articles
Announcing Pi
Technical Specifications
Raspberry Pi FAQs
Win a Pi
Raspberry Pi Wishlist
Actions
Forum Thread Details
  • State Suggested Answer
  • Replies 21 replies
  • Answers 1 answer
  • Subscribers 676 subscribers
  • Views 2999 views
  • Users 0 members are here
Related

Driver instability issue

Former Member

I've got the Wolfson Audio card running with an application that makes use of the Line-In and Line-Out ports. The Line-In port is _constantly_ read and to the Line-out port audio is written in parallel from time to time. Sampling rate is 48k. The kernel is compiled following the description here in this forum.

 

 

I now had the issue twice that the app hangs after about a day and a half. The second time I was able to collect the following info:

 

End of dmesg:

root@raspberrypi:/home/pi# dmesg | tail
 [135777.724427] arizona spi0.1: FLL1: Timed out waiting for lock
 [136377.676455] arizona spi0.1: FLL1: Timed out waiting for lock
 [136977.638482] arizona spi0.1: FLL1: Timed out waiting for lock
 [137577.600549] arizona spi0.1: FLL1: Timed out waiting for lock
 [138099.977529] arizona spi0.1: FLL1: Timed out waiting for lock
 [138777.524608] arizona spi0.1: FLL1: Timed out waiting for lock
 [139377.496589] arizona spi0.1: FLL1: Timed out waiting for lock
 [139977.448573] arizona spi0.1: FLL1: Timed out waiting for lock
 [139977.522931] ERROR: 4096 KiB atomic DMA coherent pool is too small!
 [139977.522931] Please increase it with coherent_pool= kernel parameter!

 

 

The app hangs. After kill -9 any attempt to restart fails with the following message from the app:

 

*** ERROR: snd_pcm_start failed (unrecoverable error): Cannot allocate memory
 *** ERROR: Start capture failed

 

Here is the end of the corresponding strace of an app start attempt:

 

stat64("/usr/share/alsa/alsa.conf", {st_mode=S_IFREG|0644, st_size=9184, ...}) = 0
 open("/dev/snd/controlC0", O_RDONLY|O_CLOEXEC) = 5
 fcntl64(5, F_SETFD, FD_CLOEXEC)         = 0
 ioctl(5, UI_DEV_CREATE, 0xbef492cc)     = 0
 close(5)                                = 0
 open("/dev/snd/controlC0", O_RDWR|O_CLOEXEC) = 5
 fcntl64(5, F_SETFD, FD_CLOEXEC)         = 0
 ioctl(5, USBDEVFS_CONTROL or USBDEVFS_CONTROL32, 0xbef4946c) = 0
 ioctl(5, 0x40045532, 0xbef494a4)        = 0
 open("/dev/snd/pcmC0D0c", O_RDWR|O_NONBLOCK|O_CLOEXEC) = 6
 fcntl64(6, F_SETFD, FD_CLOEXEC)         = 0
 close(5)                                = 0
 ioctl(6, AGPIOC_ACQUIRE or APM_IOC_STANDBY, 0xbef492e8) = 0
 fcntl64(6, F_GETFL)                     = 0x802 (flags O_RDWR|O_NONBLOCK)
 ioctl(6, AGPIOC_INFO, 0xbef492dc)       = 0
 clock_gettime(CLOCK_MONOTONIC, {172144, 75851672}) = 0
 ioctl(6, AGPIOC_SETUP, 0xbef492e4)      = 0
 mmap2(NULL, 4096, PROT_READ, MAP_SHARED, 6, 0x80000) = -1 ENXIO (No such device or address)
 ioctl(6, 0xc0844123, 0xbef49408)        = 0
 fcntl64(6, F_GETFL)                     = 0x802 (flags O_RDWR|O_NONBLOCK)
 fcntl64(6, F_SETFL, O_RDWR)             = 0
 ioctl(6, 0xc25c4110, 0x1935718)         = 0
 ioctl(6, 0xc25c4110, 0x1935718)         = 0
 ioctl(6, 0xc25c4110, 0x1935718)         = 0
 ioctl(6, 0xc25c4110, 0x1935718)         = 0
 ioctl(6, 0xc25c4110, 0x1935718)         = 0
 ioctl(6, 0xc25c4110, 0x1935718)         = 0
 ioctl(6, 0xc25c4110, 0x1935718)         = 0
 ioctl(6, 0xc25c4110, 0x1935718)         = 0
 ioctl(6, 0xc25c4110, 0x1935718)         = 0
 ioctl(6, 0xc25c4110, 0x1935718)         = 0
 ioctl(6, 0xc25c4110, 0x1935718)         = 0
 ioctl(6, 0xc25c4111, 0x1935718)         = 0
 ioctl(6, 0xc0844123, 0x1935bb8)         = 0
 ioctl(6, 0xc0684113, 0xbef496d4)        = 0
 ioctl(6, 0x4140, 0xb69d5000)            = 0
 ioctl(6, 0xc0844123, 0x1935bb8)         = 0
 ioctl(6, 0xc0684113, 0x19353e0)         = 0
 ioctl(6, 0x4140, 0xb69d5000)            = 0
 ioctl(6, 0xc0844123, 0x1935bb8)         = 0
 ioctl(6, 0xc0844123, 0x1935bb8)         = 0
 ioctl(6, 0x4142, 0x1935bb8)             = -1 ENOMEM (Cannot allocate memory)
 write(2, "*** ERROR: snd_pcm_start failed "..., 55*** ERROR: snd_pcm_start failed (unrecoverable error): ) = 55
 write(2, "Cannot allocate memory", 22Cannot allocate memory)  = 22
 write(2, "\n", 1
 )                       = 1
 write(2, "*** ERROR: Start capture failed", 31*** ERROR: Start capture failed) = 31
 write(2, "\n", 1
 )                       = 1
 ioctl(6, 0x4143, 0xb69d5000)            = 0
 ioctl(6, 0x4112, 0xf5519900)            = 0
 close(6)                                = 0
 write(2, "*** ERROR: Could not open audio "..., 53*** ERROR: Could not open audio device for receiver ") = 53
 write(2, "Rx1", 3Rx1)                      = 3
 write(2, "\"\n", 2"
 )                     = 2
 close(4)                                = 0
 brk(0x1955000)                          = 0x1955000
 brk(0x1947000)                          = 0x1947000
 write(2, "*** ERROR: Could not initialize "..., 36*** ERROR: Could not initialize RX ") = 36
 write(2, "Rx1", 3Rx1)                      = 3
 write(2, "\"\n", 2"
 )                     = 2
 write(2, "*** ERROR: Could not initialize "..., 46*** ERROR: Could not initialize Logic object ") = 46
 write(2, "RepeaterLogic", 13RepeaterLogic)           = 13
 write(2, "\". Skipping...\n", 15". Skipping...
 )       = 15
 write(2, "*** ERROR: No logics available. "..., 47*** ERROR: No logics available. Bailing out...
 ) = 47
 exit_group(1)                           = ?

 

BTW, the app is supposed to run _for-ever_ reading and processing audio... running for two years without restart is common for users of this app on x86 hardware.

 

Is there any driver update on the way that could fix this (and allow lower sampling rates on the analogue input)?

Thanks?

Parents
  • 0

    SvxLink?

     

    I also see the

      arizona spi0.1: FLL1: Timed out waiting for lock

    and

      bcm2708-i2s bcm2708-i2s.0: I2S SYNC error!

    messages, but I think they are benign.

    The bcm2708-i2s bcm2708-i2s.0: I2S SYNC error message pops up when i configure the sound card, i.e. when I run the "Reset.." + some other use case script.

     

    My system also constantly reads from Line In and every 10 minutes it plays a sound on Line Out. No, not  SvxLink. Simple mp3 streaming and time announcements with two different applications.

    I get the arizona spi0.1: FLL1: Timed out waiting for lock message every time Line Out is opened for playback.

    But in my case, everything seems to work.

     

    The killer in your case is ERROR: 4096 KiB atomic DMA coherent pool is too small!

    That is when the I2S driver for the Broadcom BCM2708 - sound/soc/bcm/bcm2708-i2s.c - tries to allocate memory from the 4MB pool (the "coherent pool") that is set aside for DMA transfers, and fails.

     

    What you could try is to increase the size of the coherent pool. You do that by adding e.g. coherent_pool=6M to the end of the single line in /boot/cmdline.txt, to increase the size to 6 MB.
    That could make the error go away. Or the error might still show up, but it would probably take longer.

    --

    Ragnar

Reply
  • 0

    SvxLink?

     

    I also see the

      arizona spi0.1: FLL1: Timed out waiting for lock

    and

      bcm2708-i2s bcm2708-i2s.0: I2S SYNC error!

    messages, but I think they are benign.

    The bcm2708-i2s bcm2708-i2s.0: I2S SYNC error message pops up when i configure the sound card, i.e. when I run the "Reset.." + some other use case script.

     

    My system also constantly reads from Line In and every 10 minutes it plays a sound on Line Out. No, not  SvxLink. Simple mp3 streaming and time announcements with two different applications.

    I get the arizona spi0.1: FLL1: Timed out waiting for lock message every time Line Out is opened for playback.

    But in my case, everything seems to work.

     

    The killer in your case is ERROR: 4096 KiB atomic DMA coherent pool is too small!

    That is when the I2S driver for the Broadcom BCM2708 - sound/soc/bcm/bcm2708-i2s.c - tries to allocate memory from the 4MB pool (the "coherent pool") that is set aside for DMA transfers, and fails.

     

    What you could try is to increase the size of the coherent pool. You do that by adding e.g. coherent_pool=6M to the end of the single line in /boot/cmdline.txt, to increase the size to 6 MB.
    That could make the error go away. Or the error might still show up, but it would probably take longer.

    --

    Ragnar

Children
  • 0 in reply to Former Member

    Hi Ragnar,

     

    the app is indeed svxlink. Sometime today it happened again - and again within less than two days.

     

    [152246.367695] arizona spi0.1: FLL1: Timed out waiting for lock
[152821.921298] arizona spi0.1: FLL1: Timed out waiting for lock
[153421.883321] arizona spi0.1: FLL1: Timed out waiting for lock
[153421.957775] ERROR: 4096 KiB atomic DMA coherent pool is too small!
[153421.957775] Please increase it with coherent_pool= kernel parameter!
root@raspberrypi:/home/pi#

     

    After seeing three times the same behaviour I'd say it's reproducible.

     

    I'll go the other way first. Let's see how long it'll work with coherent_pool=3M image