Issues with Pi 4, DACs and VLC

phofman · 2021-08-26 8:07 am

That looks ok. Can you try a different USB cable? I have two USB cables here and only one works glitch-free with my USB2 soundcard.

rpi · 2021-08-26 8:10 am

Here is the VLC log when there is no issue:

Code:

main debug: Buffering 0%
main debug: Buffering 0%
main error: Invalid PCR value in ES_OUT_SET_(GROUP_)PCR !
main debug: Buffering 37%
main debug: restarting module due to input format change
main debug: removing module "flac"
main debug: looking for audio decoder module matching "any": 21 candidates
main debug: using audio decoder module "flac"
flac debug: decode STREAMINFO
flac debug: channels:2 samplerate:44100 bitspersamples:16
flac debug: STREAMINFO decoded
main debug: reusing audio output
alsa debug: using ALSA device: default
alsa debug:  Hardware PCM card 2 'E30' device 0 subdevice 0
alsa debug:  device name   : USB Audio
alsa debug:  device ID     : USB Audio
alsa debug:  subdevice name: subdevice #0
alsa debug: initial hardware setup:
ACCESS:  MMAP_INTERLEAVED RW_INTERLEAVED
FORMAT:  S32_LE SPECIAL DSD_U32_BE
SUBFORMAT:  STD
SAMPLE_BITS: 32
FRAME_BITS: 64
CHANNELS: 2
RATE: [44100 768000]
PERIOD_TIME: [125 1486078)
PERIOD_SIZE: [8 65536]
PERIOD_BYTES: [64 524288]
PERIODS: [2 1024]
BUFFER_TIME: (20 2972155)
BUFFER_SIZE: [16 131072]
BUFFER_BYTES: [128 1048576]
TICK_TIME: ALL
main debug: Buffering 46%
alsa debug: using channels map 0, type 1, 2 channel(s)
main debug: Buffering 55%
main debug: Buffering 65%
main debug: Buffering 74%
main debug: Buffering 83%
main debug: Buffering 92%
main debug: Stream buffering done (1021 ms in 1 ms)
alsa debug: final HW setup:
ACCESS:  RW_INTERLEAVED
FORMAT:  S32_LE
SUBFORMAT:  STD
SAMPLE_BITS: 32
FRAME_BITS: 64
CHANNELS: 2
RATE: 44100
PERIOD_TIME: 40000
PERIOD_SIZE: 1764
PERIOD_BYTES: 14112
PERIODS: (74 75)
BUFFER_TIME: (2972154 2972155)
BUFFER_SIZE: 131072
BUFFER_BYTES: 1048576
TICK_TIME: 0
alsa debug: initial software parameters:
tstamp_mode: NONE
tstamp_type: MONOTONIC
period_step: 1
avail_min: 1764
start_threshold: 1
stop_threshold: 131072
silence_threshold: 0
silence_size: 0
boundary: 1073741824
alsa debug: final software parameters:
tstamp_mode: NONE
tstamp_type: MONOTONIC
period_step: 1
avail_min: 1764
start_threshold: 1
stop_threshold: 131072
silence_threshold: 0
silence_size: 0
boundary: 1073741824
main debug: output 's32l' 44100 Hz Stereo frame=1 samples/8 bytes
main debug: looking for audio volume module matching "any": 3 candidates
main debug: using audio volume module "integer_mixer"
main debug: input 's32l' 44100 Hz Stereo frame=1 samples/8 bytes
main debug: conversion: 's32l'->'s32l' 44100 Hz->44100 Hz Stereo->Stereo
main debug: conversion pipeline complete
main debug: looking for audio resampler module matching "disable": 4 candidates
main debug: using audio resampler module "ugly"
main debug: Decoder wait done in 6 ms
main debug: inserting 16820 zeroes

phofman · 2021-08-26 8:13 am

Is this correct?

Code:

main debug: looking for audio resampler module matching "disable": 4 candidates
main debug: using audio resampler module "ugly"

rpi · 2021-08-26 8:24 am

Yeah, that name sounds strange 🙂
I tried another cable with the same result.
Here is additional VLC log when there is issue:

Code:

alsa error: cannot estimate delay: File descriptor in bad state
alsa error: cannot recover playback stream: File descriptor in bad state
alsa debug: current status:
  state       : SETUP
  trigger_time: 269.334865
  tstamp      : 0.000000
  delay       : 0
  avail       : 66914
  avail_max   : 0
alsa error: cannot estimate delay: File descriptor in bad state
alsa error: cannot recover playback stream: File descriptor in bad state
alsa debug: current status:
  state       : SETUP
  trigger_time: 269.334865
  tstamp      : 0.000000
  delay       : 0
  avail       : 66914
  avail_max   : 0
alsa error: cannot estimate delay: File descriptor in bad state
alsa error: cannot recover playback stream: File descriptor in bad state
alsa debug: current status:
  state       : SETUP
  trigger_time: 269.334865
  tstamp      : 0.000000
  delay       : 0
  avail       : 66914
  avail_max   : 0

rpi · 2021-08-26 8:46 am

Log from 'dmesg':

Code:

[ 1798.283826] raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-arm frequency: -12
[ 1798.483858] cpu cpu0: dev_pm_opp_set_rate: failed to find current OPP for freq 4294967284 (-34)
[ 1798.483888] raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-arm frequency: -12
[ 1798.684415] cpu cpu0: dev_pm_opp_set_rate: failed to find current OPP for freq 4294967284 (-34)
[ 1798.684487] raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-arm frequency: -12
[ 1798.784783] cpu cpu0: dev_pm_opp_set_rate: failed to find current OPP for freq 4294967284 (-34)
[ 1798.784852] raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-arm frequency: -12
[ 1801.291916] cpu cpu0: dev_pm_opp_set_rate: failed to find current OPP for freq 4294967284 (-34)
[ 1801.291945] raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-arm frequency: -12
[ 1801.392661] cpu cpu0: dev_pm_opp_set_rate: failed to find current OPP for freq 4294967284 (-34)
[ 1801.392690] raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-arm frequency: -12
[ 1801.493693] cpu cpu0: dev_pm_opp_set_rate: failed to find current OPP for freq 4294967284 (-34)
[ 1801.493722] raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-arm frequency: -12
[ 1801.694198] cpu cpu0: dev_pm_opp_set_rate: failed to find current OPP for freq 4294967284 (-34)
[ 1801.694227] raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-arm frequency: -12
[ 1801.795190] cpu cpu0: dev_pm_opp_set_rate: failed to find current OPP for freq 4294967284 (-34)
[ 1801.795218] raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-arm frequency: -12
[ 1801.995612] cpu cpu0: dev_pm_opp_set_rate: failed to find current OPP for freq 4294967284 (-34)
[ 1801.995641] raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-arm frequency: -12
[ 1802.095964] cpu cpu0: dev_pm_opp_set_rate: failed to find current OPP for freq 4294967284 (-34)
[ 1802.296840] cpu cpu0: dev_pm_opp_set_rate: failed to find current OPP for freq 4294967284 (-34)
[ 1802.397692] cpu cpu0: dev_pm_opp_set_rate: failed to find current OPP for freq 4294967284 (-34)
[ 1802.598888] cpu cpu0: dev_pm_opp_set_rate: failed to find current OPP for freq 4294967284 (-34)
[ 1802.699606] cpu cpu0: dev_pm_opp_set_rate: failed to find current OPP for freq 4294967284 (-34)
[ 1802.899921] cpu cpu0: dev_pm_opp_set_rate: failed to find current OPP for freq 4294967284 (-34)
[ 1804.404686] cpu cpu0: dev_pm_opp_set_rate: failed to find current OPP for freq 4294967284 (-34)
[ 1804.404711] raspberrypi_fw_set_rate: 6 callbacks suppressed
[ 1804.404722] raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-arm frequency: -12
[ 1804.504982] cpu cpu0: dev_pm_opp_set_rate: failed to find current OPP for freq 4294967284 (-34)
[ 1804.505012] raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-arm frequency: -12
[ 1804.706204] cpu cpu0: dev_pm_opp_set_rate: failed to find current OPP for freq 4294967284 (-34)
[ 1804.706234] raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-arm frequency: -12
[ 1807.261873] xhci_hcd 0000:01:00.0: Ring expansion failed
[ 1807.261896] usb 1-1.1: cannot submit urb 7, error -12: unknown error
[ 1807.413232] cpu cpu0: dev_pm_opp_set_rate: failed to find current OPP for freq 4294967284 (-34)
[ 1807.413262] raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-arm frequency: -12
[ 1807.513476] cpu cpu0: dev_pm_opp_set_rate: failed to find current OPP for freq 4294967284 (-34)
[ 1807.513505] raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-arm frequency: -12
[ 1807.713853] cpu cpu0: dev_pm_opp_set_rate: failed to find current OPP for freq 4294967284 (-34)
[ 1807.713883] raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-arm frequency: -12
[ 1807.815189] cpu cpu0: dev_pm_opp_set_rate: failed to find current OPP for freq 4294967284 (-34)
[ 1807.815233] raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-arm frequency: -12

When it works without issues dmesg shows only these:

Code:

[ 2108.193141] cpu cpu0: dev_pm_opp_set_rate: failed to find current OPP for freq 4294967284 (-34)
[ 2108.193191] raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-arm frequency: -12

phofman · 2021-08-26 9:49 am

So when you attach the non-working DAC, start playing to this DAC with VLC, rpi starts complaining about setting clk rate?

What RPi USB output do you use for the DACs?

RPi4?

Your problem suggests the SoC gets stuck for moments, but I do not see any coincidence with USB2 DACs. Is your PSU powerful enough?

rpi · 2021-08-26 5:29 pm

It doesn't complain immediately when the issue occurs. Maybe that's just a delay in logging (dmesg).
I use USB3 output from the Pi 4. I tried USB2 with the same result.

Pi powered by 5A power supply and DAC by 1A power supply.

One observation - the DAC has sample rate indicator on the front panel. It shows 44.1 only one time when it starts playing the tracks. After that it always shows 00.0 when there is no issue and when there is the issue.

rpi · 2021-08-29 6:54 am

Here is additional information.
I installed the 'Raspberry Pi OS with desktop and recommended software'. It includes PulseAudio and VLC. I played the same FLAC files as before.

Initially there is no issue. VLC plays files without any issues, skip and track switch work fine.

Here is the content of the 'asound' files:
/proc/asound/card2/pcm0p/sub0/sw_params:

Code:

tstamp_mode: ENABLE
period_step: 1
avail_min: 661
start_threshold: 4294967295
stop_threshold: 1386217472
silence_threshold: 0
silence_size: 0
boundary: 1386217472

/proc/asound/card2/pcm0p/sub0/hw_params:

Code:

access: MMAP_INTERLEAVED
format: S32_LE
subformat: STD
channels: 2
rate: 44100 (44100/1)
period_size: 661
buffer_size: 2644

Then I uninstalled PulseAudio. I didn't make any other changes:

Code:

sudo apt-get remove pulseaudio
sudo apt autoremove
sudo /etc/init.d/alsa-utils reset
sudo reboot

After that the issues described in the first post started showing up.
Here is the content of the 'asound' files:
/proc/asound/card2/pcm0p/sub0/sw_params:

Code:

tstamp_mode: NONE
period_step: 1
avail_min: 661
start_threshold: 1
stop_threshold: 131072
silence_threshold: 0
silence_size: 0
boundary: 1073741824

/proc/asound/card2/pcm0p/sub0/hw_params:

Code:

access: RW_INTERLEAVED
format: S32_LE
subformat: STD
channels: 2
rate: 44100 (44100/1)
period_size: 1764

buffer_size: 131072

Then I installed PulseAudio again:

Code:

sudo apt-get install pulseaudio

After that all worked fine again and the asound files were the same as before uninstalling the PulseAudio.

Here are the main differences in those files:
ENABLE -> NONE,
MMAP_INTERLEAVED -> RW_INTERLEAVED

I'm not sure if that's what makes the issues to occur but that's what I observed.

Now the question is how to switch on properties ENABLE and MMAP_INTERLEAVED without PulseAudio? I need to avoid PulseAudio as I use Raspberry OS Lite which doesn't include it.

Thanks!

phofman · 2021-08-29 8:31 am

Interesting troubleshooting. MMAP is the preferred mode since it's generally more performant. MMAP support was added to the RPi I2S driver just for this reason bcm2708-i2s lacks mmap support * Issue #1004 * raspberrypi/linux * GitHub

VLC uses RW mode - IMO hard-coded in the source git.videolan.org Git - vlc.git/blob - modules/audio_output/alsa.c .

I would suggest first trying with aplay, setting the same params VLC uses, something like:

Code:

aplay -v --mmap -D hw:2 --period-size=1764 --buffer-size=131072 -r 44100 -c 2 -f S32_LE some_441_stereo_track.wav

vs. RW

Code:

aplay -v -D hw:2 --period-size=1764 --buffer-size=131072 -r 44100 -c 2 -f S32_LE some_441_stereo_track.wav

If the mmap plays OK, you can force mmap for vlc in .asoundrc by defining a hw device - IIUC MMAP will be used by default, RW requires sync_ptr_ioctl true ALSA project - the C library reference: PCM (digital audio) plugins .

rpi · 2021-08-29 6:16 pm

With PulseAudio the device hw:2 doesn't work. I changed it to the default which looks like this:

Code:

pcm.!default {
  type hw
  card E30
}

Here is the result:

Code:

pi@raspberrypi:~/Music $ aplay -v -D default --period-size=1764 --buffer-size=131072 -r 44100 -c 2 -f S32_LE sample-16.wav
Warning: format is changed to S16_LE
Playing WAVE 'sample-16.wav' : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo
ALSA <-> PulseAudio PCM I/O Plugin
Its setup is:
  stream       : PLAYBACK
  access       : RW_INTERLEAVED
  format       : S16_LE
  subformat    : STD
  channels     : 2
  rate         : 44100
  exact rate   : 44100 (44100/1)
  msbits       : 16
  buffer_size  : 130536
  period_size  : 1764
  period_time  : 40000
  tstamp_mode  : NONE
  tstamp_type  : GETTIMEOFDAY
  period_step  : 1
  avail_min    : 1764
  period_event : 0
  start_threshold  : 130536
  stop_threshold   : 130536
  silence_threshold: 0
  silence_size : 0
  boundary     : 2138701824

pi@raspberrypi:~/Music $ aplay -v --mmap -D default --period-size=1764 --buffer-size=131072 -r 44100 -c 2 -f S32_LE sample-16.wav
Warning: format is changed to S16_LE
Playing WAVE 'sample-16.wav' : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo
aplay: set_params:1334: Access type not available

Without PulseAudio:

Code:

pi@raspberrypi:~/Music $ aplay -v -D default --period-size=1764 --buffer-size=131072 -r 44100 -c 2 -f S32_LE sample-16.wav
Warning: format is changed to S16_LE
Playing WAVE 'sample-16.wav' : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo
aplay: set_params:1339: Sample format non available
Available formats:
- S32_LE
- SPECIAL
- DSD_U32_BE

pi@raspberrypi:~/Music $ aplay -v --mmap -D default --period-size=1764 --buffer-size=131072 -r 44100 -c 2 -f S32_LE sample-32.wav
Playing WAVE 'sample-32.wav' : Float 32 bit Little Endian, Rate 44100 Hz, Stereo
aplay: set_params:1339: Sample format non available
Available formats:
- S32_LE
- SPECIAL
- DSD_U32_BE


 $ speaker-test -c2 --test=wav -w /usr/share/sounds/alsa/Front_Center.wav

speaker-test 1.1.8

Playback device is default
Stream parameters are 48000Hz, S16_LE, 2 channels
WAV file(s)
Sample format not available for playback: Invalid argument
Setting of hwparams failed: Invalid argument

How do you enable MMAP in the .asoundrc?
Thanks!

phofman · 2021-08-29 8:01 pm

1. With pulsaudio installed your re-defined default device is ignored due to pulseaudio alsa config overriding the standard alsa configs.

2. Your wav is Float 32 bit Little Endian, not integer 32. Generate the file e.g. in sox (-b 32)

IMO mmap is enabled by default, RW must be requested explicitly by the sync_ptr_ioctl param. VLC explicitly asks for RW in snd_pcm_open (the link I posted above).

rpi · 2021-08-29 8:27 pm

How does it work with PulseAudio? Does it override the default VLC behavior RW to MMAP? Is it possible to do the same without PulseAudio?
Thanks!

rpi · 2021-08-29 8:36 pm

I converted WAV into signed-integer and tested with aplay. In both cases it worked:

Code:

pi@raspberrypi:~/Music $ aplay -v -D default --period-size=1764 --buffer-size=131072 -r 44100 -c 2 -f S32_LE sample-32-3.wav
Playing WAVE 'sample-32-3.wav' : Signed 32 bit Little Endian, Rate 44100 Hz, Stereo
Hardware PCM card 2 'E30' device 0 subdevice 0
Its setup is:
  stream       : PLAYBACK
  access       : RW_INTERLEAVED
  format       : S32_LE
  subformat    : STD
  channels     : 2
  rate         : 44100
  exact rate   : 44100 (44100/1)
  msbits       : 32
  buffer_size  : 131072
  period_size  : 1764
  period_time  : 40000
  tstamp_mode  : NONE
  tstamp_type  : MONOTONIC
  period_step  : 1
  avail_min    : 1764
  period_event : 0
  start_threshold  : 131072
  stop_threshold   : 131072
  silence_threshold: 0
  silence_size : 0
  boundary     : 1073741824
  appl_ptr     : 0
  hw_ptr       : 0

pi@raspberrypi:~/Music $ aplay -v --mmap -D default --period-size=1764 --buffer-size=131072 -r 44100 -c 2 -f S32_LE sample-32-3.wav
Playing WAVE 'sample-32-3.wav' : Signed 32 bit Little Endian, Rate 44100 Hz, Stereo
Hardware PCM card 2 'E30' device 0 subdevice 0
Its setup is:
  stream       : PLAYBACK
  access       : MMAP_INTERLEAVED
  format       : S32_LE
  subformat    : STD
  channels     : 2
  rate         : 44100
  exact rate   : 44100 (44100/1)
  msbits       : 32
  buffer_size  : 131072
  period_size  : 1764
  period_time  : 40000
  tstamp_mode  : NONE
  tstamp_type  : MONOTONIC
  period_step  : 1
  avail_min    : 1764
  period_event : 0
  start_threshold  : 131072
  stop_threshold   : 131072
  silence_threshold: 0
  silence_size : 0
  boundary     : 1073741824
  appl_ptr     : 0
  hw_ptr       : 0
mmap_area[0] = 0xb663b000,0,64 (32)
mmap_area[1] = 0xb663b000,32,64 (32)

phofman · 2021-08-29 8:37 pm

Your /proc/asound/card2/pcm0p/sub0/hw_params shows that with PA the mode is MMAP and with VLC directly the mode is RW. When VLC goes through PA, it's PA opening the alsa device, the VLC is communicating with PA (via the alsa pulse plugin).

Still I would try the aplay test first. It will reveal most as it's trivial to use different modes. That's what aplay was created for.

rpi · 2021-08-29 9:34 pm

Sure, please let me know if you need more testing.

phofman · 2021-08-29 9:41 pm

I would try creating some device with the plug plugin (to wrap something around the HW) and direct vlc to this device, instead of the hw. Theoretically the plug device would be opened with RW (as specified by VLC), while the HW device should be opened with MMAP (being the default mode).

rpi · 2021-08-29 10:26 pm

What should be there in the plug plugin?

Code:

pcm.test {
    type plug
    slave {
        pcm default
    }
}

pcm.!default {
  type hw
  card E30
}

Greg Erskine · 2021-08-30 2:07 am

Sorry for butting in, on the small chance that it is helpful, I would recommend setting mmap=0 for debugging. For many years mmap=1 always worked and could be used as default. In recent kernels, at least for this year, setting mmap=1 in "some circumstances" has caused "no sound".

I have not seen an issue with USB and the E30 though, only Headphones and b1 soundcards.

rpi · 2021-08-30 5:07 am

I'm not sure where that 'mmap' should be set. Is it in .asoundrc or somewhere else? Thanks!

rpi · 2021-08-31 3:33 pm

One more reply from the VLC forum:
'VLC cannot use MMAP mode. It wouldn't make sense for VLC to use it.'

Does it mean that only PulseAudio can set the MMAP mode? Does it also mean that in RW mode there is the issue in VLC?
Thanks!

Search

Amplifiers

Source & Line

Loudspeakers

Design & Build

General Interest

Live Sound

Member Areas

Site

Featured Vendors

Members Market

Vendors Market

Vendors

Search

Issues with Pi 4, DACs and VLC

phofman

rpi

phofman

rpi

rpi

phofman

rpi

rpi

phofman

rpi

phofman

rpi

rpi

phofman

rpi

phofman

rpi

Greg Erskine

rpi

rpi