librespot: ERROR ALSA function 'snd_pcm_hw_params_set_buffer_time_near' failed with error 'EINVAL: Invalid argument' on playback on Vero4K

On my Vero4K (OSMC) I get the following error on playback:

[2021-11-28T23:21:41Z ERROR librespot_playback::player] Audio Sink Error Invalid Parameters: <AlsaSink> Hardware, ALSA function 'snd_pcm_hw_params_set_buffer_time_near' failed with error 'EINVAL: Invalid argument'

The librespot command:

osmc@osmc0:~$ /usr/bin/librespot --name DEBUG --device-type speaker --backend alsa --bitrate 320 --disable-audio-cache --enable-volume-normalisation --volume-ctrl linear --initial-volume 100 --verbose
[2021-11-28T23:21:14Z INFO  librespot] librespot 0.3.1 bbd575e (Built on 2021-11-26, Build ID: a6e0Ery3, Profile: release)

I have nothing in /etc/asound.conf or ~/.asoundrc. Output of aplay -l:

osmc@osmc0:~$ aplay -l
**** List of PLAYBACK Hardware Devices ****
card 0: AMLMESONAUDIO [AML-MESONAUDIO], device 0: I2S T9015-audio-hifi-0 []
  Subdevices: 0/1
  Subdevice #0: subdevice #0
card 0: AMLMESONAUDIO [AML-MESONAUDIO], device 1: SPDIF dit-hifi-1 []
  Subdevices: 1/1
  Subdevice #0: subdevice #0
card 0: AMLMESONAUDIO [AML-MESONAUDIO], device 2: PCM pcm2bt-pcm-2 []
  Subdevices: 1/1
  Subdevice #0: subdevice #0

and aplay -L:

osmc@osmc0:~$ aplay -L
null
    Discard all samples (playback) or generate zero samples (capture)
btaudio
    Bluetooth Audio
default:CARD=AMLMESONAUDIO
    AML-MESONAUDIO,
    Default Audio Device
sysdefault:CARD=AMLMESONAUDIO
    AML-MESONAUDIO,
    Default Audio Device
hdmi:CARD=AMLMESONAUDIO,DEV=0
    AML-MESONAUDIO,
    HDMI Audio Output
dmix:CARD=AMLMESONAUDIO,DEV=0
    AML-MESONAUDIO,
    Direct sample mixing device
dmix:CARD=AMLMESONAUDIO,DEV=1
    AML-MESONAUDIO,
    Direct sample mixing device
dmix:CARD=AMLMESONAUDIO,DEV=2
    AML-MESONAUDIO,
    Direct sample mixing device
dsnoop:CARD=AMLMESONAUDIO,DEV=0
    AML-MESONAUDIO,
    Direct sample snooping device
dsnoop:CARD=AMLMESONAUDIO,DEV=1
    AML-MESONAUDIO,
    Direct sample snooping device
dsnoop:CARD=AMLMESONAUDIO,DEV=2
    AML-MESONAUDIO,
    Direct sample snooping device
hw:CARD=AMLMESONAUDIO,DEV=0
    AML-MESONAUDIO,
    Direct hardware device without any conversions
hw:CARD=AMLMESONAUDIO,DEV=1
    AML-MESONAUDIO,
    Direct hardware device without any conversions
hw:CARD=AMLMESONAUDIO,DEV=2
    AML-MESONAUDIO,
    Direct hardware device without any conversions
plughw:CARD=AMLMESONAUDIO,DEV=0
    AML-MESONAUDIO,
    Hardware device with all software conversions
plughw:CARD=AMLMESONAUDIO,DEV=1
    AML-MESONAUDIO,
    Hardware device with all software conversions
plughw:CARD=AMLMESONAUDIO,DEV=2
    AML-MESONAUDIO,
    Hardware device with all software conversions

I reported this originally in https://github.com/dtcooper/raspotify/issues/466 there are some more details there.

About this issue

  • Original URL
  • State: closed
  • Created 3 years ago
  • Reactions: 2
  • Comments: 34 (28 by maintainers)

Most upvoted comments

As soon as it hits dev I will ship it in Raspotify. It should be plenty of exposure there.

Thanks for that work. I’ll take some time to test it on my rig this weekend and get it merged. Then when it lives in dev it can get some proper exposure before we release a new version.

@JasonLG1979 it looks like it was exactly same issue as @oebeledrijfhout had. I try to reproduce the error and it looks like i didn’t configure external USB sound card, so it used internal one. Sorry for mystification. Nevertheless the update fix the problem when using internal card and log is same as @oebeledrijfhout posted.

[2021-12-03T07:26:12Z TRACE librespot_playback::player] == Starting sink ==
[2021-12-03T07:26:12Z TRACE librespot_playback::audio_backend::alsa] Desired Buffer Frame range: 4410 - 22050
[2021-12-03T07:26:12Z TRACE librespot_playback::audio_backend::alsa] Buffer Frame range reported by device: 32 - 131072
[2021-12-03T07:26:12Z TRACE librespot_connect::spirc] Sending status to server: [kPlayStatusPlay]
[2021-12-03T07:26:12Z TRACE librespot_connect::spirc] ==> kPlayStatusPlay
[2021-12-03T07:26:12Z TRACE librespot_playback::audio_backend::alsa] Desired Period Frame range: 0 - 0
[2021-12-03T07:26:12Z TRACE librespot_playback::audio_backend::alsa] Period Frame range reported by device: 32 - 16384
[2021-12-03T07:26:12Z TRACE librespot_playback::audio_backend::alsa] Failed to set buffer size, falling back to the device's defaults.
[2021-12-03T07:26:12Z TRACE librespot_playback::audio_backend::alsa] Frames per Buffer: 131072
[2021-12-03T07:26:12Z TRACE librespot_playback::audio_backend::alsa] Frames per Period: 256
[2021-12-03T07:26:12Z TRACE librespot_playback::audio_backend::alsa] Period Buffer size in bytes: 1024
[2021-12-03T07:26:12Z TRACE librespot_playback::audio_backend::alsa] Period Buffer capacity: 1024

On my Vero4k (OSMC) version: raspotify_0.31.3-4-g8d41bd0-dirty~librespot.v0.2.0-150-gc737337_armhf.deb fixed my issue (same as @oebeledrijfhout posted originally). I don’t have any complains about set buffer size, but i’m using external USB sound card.

[2021-12-02T21:23:47Z TRACE librespot_playback::player] == Starting sink ==
[2021-12-02T21:23:47Z TRACE librespot_playback::audio_backend::alsa] Desired Buffer Frame range: 4410 - 22050
[2021-12-02T21:23:47Z TRACE librespot_playback::audio_backend::alsa] Buffer Frame range reported by device: 90 - 262144
[2021-12-02T21:23:47Z TRACE librespot_playback::audio_backend::alsa] Desired Period Frame range: 2205 - 5512
[2021-12-02T21:23:47Z TRACE librespot_playback::audio_backend::alsa] Period Frame range reported by device: 45 - 11025
[2021-12-02T21:23:47Z TRACE librespot_playback::audio_backend::alsa] Frames per Buffer: 22050
[2021-12-02T21:23:47Z TRACE librespot_playback::audio_backend::alsa] Frames per Period: 5512
[2021-12-02T21:23:47Z TRACE librespot_playback::audio_backend::alsa] Period Buffer size in bytes: 22048
[2021-12-02T21:23:47Z TRACE librespot_playback::audio_backend::alsa] Period Buffer capacity: 22048

Weird that it reports an available buffer size range of 16 - 65536 Frames and then totally fails when librespot tries to set the buffer to 22050 Frames which is obviously in that range. That’s clearly a driver/configuration bug. The expected result of calling snd_pcm_hw_params_set_buffer_size_near (and the rust bindings) would be for it to return what the driver set the buffer size to be (hopefully something close to what you asked for). You should basically be able to pass any Frame value to that function and it should never fail. The fact that it always fails is very, very broken. I would file a bug report upstream and tell them to fix their shit drivers/configuration.

looks (and sounds) good!

Dec 02 13:34:26 osmc0 librespot[27221]: [2021-12-02T12:34:26Z TRACE librespot_playback::player] == Starting sink ==
Dec 02 13:34:26 osmc0 librespot[27221]: [2021-12-02T12:34:26Z TRACE librespot_playback::audio_backend::alsa] Desired Buffer Frame range: 4410 - 22050
Dec 02 13:34:26 osmc0 librespot[27221]: [2021-12-02T12:34:26Z TRACE librespot_playback::audio_backend::alsa] Buffer Frame range reported by device: 16 - 65536
Dec 02 13:34:26 osmc0 librespot[27221]: [2021-12-02T12:34:26Z TRACE librespot_playback::audio_backend::alsa] Desired Period Frame range: 0 - 0
Dec 02 13:34:26 osmc0 librespot[27221]: [2021-12-02T12:34:26Z TRACE librespot_playback::audio_backend::alsa] Period Frame range reported by device: 32 - 8192
Dec 02 13:34:26 osmc0 librespot[27221]: [2021-12-02T12:34:26Z TRACE librespot_playback::audio_backend::alsa] Failed to set buffer size, falling back to the device's defaults.
Dec 02 13:34:26 osmc0 librespot[27221]: [2021-12-02T12:34:26Z TRACE librespot_playback::audio_backend::alsa] Frames per Buffer: 65536
Dec 02 13:34:26 osmc0 librespot[27221]: [2021-12-02T12:34:26Z TRACE librespot_playback::audio_backend::alsa] Frames per Period: 256
Dec 02 13:34:26 osmc0 librespot[27221]: [2021-12-02T12:34:26Z TRACE librespot_playback::audio_backend::alsa] Period Buffer size in bytes: 2048
Dec 02 13:34:26 osmc0 librespot[27221]: [2021-12-02T12:34:26Z TRACE librespot_playback::audio_backend::alsa] Period Buffer capacity: 2048

You can get it out of draft when you think the code is ready for review. No problem that it needs more testing after that. “Draft” to me means: I’m still at it, but know that this is on the way, and I welcome any input on-the-go.

I installed that build and playback is working, with the same warning as with the previous build:

Nov 30 00:27:54 osmc0 systemd[1]: Started Raspotify (Spotify Connect Client).
Nov 30 00:27:54 osmc0 librespot[27128]: [2021-11-29T23:27:54Z INFO  librespot] librespot 0.3.1 7cdc7e3 (Built on 2021-11-29, Build ID: lU0YRhKm, Profile: release)
<...>
Nov 30 00:28:22 osmc0 librespot[27128]: [2021-11-29T23:28:22Z TRACE librespot_playback::player] == Starting sink ==
Nov 30 00:28:22 osmc0 librespot[27128]: [2021-11-29T23:28:22Z WARN  librespot_playback::audio_backend::alsa] <AlsaSink> Failed to set buffer size, you may experience audio issues.
Nov 30 00:28:23 osmc0 librespot[27128]: [2021-11-29T23:28:23Z TRACE librespot_playback::audio_backend::alsa] Buffer Frames: 65536
Nov 30 00:28:23 osmc0 librespot[27128]: [2021-11-29T23:28:23Z TRACE librespot_playback::audio_backend::alsa] Period Frames: 256
Nov 30 00:28:23 osmc0 librespot[27128]: [2021-11-29T23:28:23Z TRACE librespot_playback::audio_backend::alsa] Period Buffer size in bytes: 2048
Nov 30 00:28:23 osmc0 librespot[27128]: [2021-11-29T23:28:23Z TRACE librespot_playback::audio_backend::alsa] Period Buffer capacity: 2048

BTW, CPU usage is not looking excessive during playback.

@oebeledrijfhout if all goes well with the PR that references this issue I will issue a new Raspotify release after it is merged.

@oebeledrijfhout Try this build:

https://drive.google.com/file/d/1IJDvD_iQOYCf0CNZFdQHVAZmrKiUjupp/view?usp=sharing

It’s based on this branch:

https://github.com/JasonLG1979/librespot/tree/best-effort-buffer

It doesn’t actually fix anything it just makes errors setting the buffer and period size non-fatal.