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.

Sign up for GitHub

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

Jump to bottom

[ao/alsa] Error received from snd_pcm_avail (Regression) #5890

Closed
orbea opened this issue Jun 6, 2018 · 11 comments
Closed

[ao/alsa] Error received from snd_pcm_avail (Regression) #5890

orbea opened this issue Jun 6, 2018 · 11 comments

Comments

@orbea
Copy link
Contributor

orbea commented Jun 6, 2018 •
edited
Loading

mpv version and platform

OS: Slackware64-current
mpv commit: bca5951
ffmpeg commit: FFmpeg/FFmpeg@318d0fc

Reproduction steps

  1. mpv --ao alsa https://angellore.bandcamp.com/album/la-litanie-des-cendres
  2. Pause the stream.
  3. Move the mouse over the rendered video to make it spam more.

Expected behavior

mpv should not spam the console when paused.

Actual behavior

mpv spams the console when paused when playing ytdl streams or local files.

AV: 00:00:04 / 00:50:55 (0%) A-V: -0.001 DS: 2.510/0 Cache: 593s+247MB
[ao/alsa] Error received from snd_pcm_avail (-77, File descriptor in bad state)!
(Paused) AV: 00:00:04 / 00:50:55 (0%) A-V: -0.001 DS: 2.510/0 Cache: 592s+247MB
[ao/alsa] Error received from snd_pcm_avail (-77, File descriptor in bad state)!
[ao/alsa] Error received from snd_pcm_avail (-77, File descriptor in bad state)!
[ao/alsa] Error received from snd_pcm_avail (-77, File descriptor in bad state)!
[ao/alsa] Error received from snd_pcm_avail (-77, File descriptor in bad state)!
(Paused) AV: 00:00:04 / 00:50:55 (0%) A-V: -0.001 DS: 2.510/0 Cache: 592s+247MB
[ao/alsa] Error received from snd_pcm_avail (-77, File descriptor in bad state)!
[ao/alsa] Error received from snd_pcm_avail (-77, File descriptor in bad state)!
[ao/alsa] Error received from snd_pcm_avail (-77, File descriptor in bad state)!

I bisected this to the following commit.

commit 945303a92ecac73ba430b9eac0f10279cd95a32a
Author: Muhammad Faiz <mfcc64@gmail.com>
Date:   Fri May 11 22:35:10 2018 +0700

    ao_alsa: replace snd_pcm_status() with snd_pcm_avail() in get_space()
    
    Fixes a bug with alsa dmix on Fedora 29. After several minutes,
    audio suddenly becomes bad and muted.
    
    Actually, I don't know what causes this. Probably this is a bug in alsa.
    In any case, as snd_pcm_status() returns not only 'avail', but also other
    fields such as tstamp, htstamp, etc, this could be considered a good
    simplification, as only avail is required for this function.

:040000 040000 a871a0b8a80eb5c6ba1ae39eae9b6e72a68c8aee c9a2983a7ebac3676d0008d92f40d800e818d78f M	audio

945303a

Log file

https://0x0.st/s_SJ.txt

Sample files

This bandcamp link will reproduce it.
https://angellore.bandcamp.com/album/la-litanie-des-cendres
@orbea
Copy link
Contributor Author

orbea commented Jun 6, 2018

@mfcc64 and @jeeb Can you please take a look at this issue?

@orbea orbea mentioned this issue Jun 6, 2018
Closed
@jeeb
Copy link
Member

jeeb commented Jun 6, 2018

Thanks for the bisect, that logging is added by me in the following commit from that.

Seems like the AO is being queried during pause while something with the actual alsa connection is in a funky state? Possibly the whole AO has been stopped and something's just querying (and now that I added logging for errors we're getting notices of it).

@jeeb
Copy link
Member

jeeb commented Jun 9, 2018

Also it seems like I haven't completely non-tested this stuff, since it seems like it isn't happening to me at least.

[ao] Trying audio driver 'alsa'
[ao/alsa] requested format: 44100 Hz, stereo channels, floatp
[ao/alsa] using ALSA version: 1.1.6
[ao/alsa] opening device 'default'
[ao/alsa] PCM setup:
[ao/alsa] ---
[ao/alsa] ALSA <-> PulseAudio PCM I/O Plugin
[ao/alsa] ---
[ao/alsa] Start HW params:
[ao/alsa] ---
[ao/alsa] ACCESS:  RW_INTERLEAVED
[ao/alsa] FORMAT:  U8 S16_LE S16_BE S24_LE S24_BE S32_LE S32_BE FLOAT_LE FLOAT_BE MU_LAW A_LAW S24_3LE S24_3BE
[ao/alsa] SUBFORMAT:  STD
[ao/alsa] SAMPLE_BITS: [8 32]
[ao/alsa] FRAME_BITS: [8 1024]
[ao/alsa] CHANNELS: [1 32]
[ao/alsa] RATE: [1 384000]
[ao/alsa] PERIOD_TIME: (2 4294967295)
[ao/alsa] PERIOD_SIZE: [1 1398102)
[ao/alsa] PERIOD_BYTES: [128 1398102)
[ao/alsa] PERIODS: [3 1024]
[ao/alsa] BUFFER_TIME: (7 4294967295]
[ao/alsa] BUFFER_SIZE: [3 4194304]
[ao/alsa] BUFFER_BYTES: [384 4194304]
[ao/alsa] TICK_TIME: ALL
[ao/alsa] ---
[ao/alsa] HW params after rate:
[ao/alsa] ---
[ao/alsa] ACCESS:  RW_INTERLEAVED
[ao/alsa] FORMAT:  U8 S16_LE S16_BE S24_LE S24_BE S32_LE S32_BE FLOAT_LE FLOAT_BE MU_LAW A_LAW S24_3LE S24_3BE
[ao/alsa] SUBFORMAT:  STD
[ao/alsa] SAMPLE_BITS: [8 32]
[ao/alsa] FRAME_BITS: [8 1024]
[ao/alsa] CHANNELS: [1 32]
[ao/alsa] RATE: [1 384000]
[ao/alsa] PERIOD_TIME: (2 4294967295)
[ao/alsa] PERIOD_SIZE: [1 1398102)
[ao/alsa] PERIOD_BYTES: [128 1398102)
[ao/alsa] PERIODS: [3 1024]
[ao/alsa] BUFFER_TIME: (7 4294967295]
[ao/alsa] BUFFER_SIZE: [3 4194304]
[ao/alsa] BUFFER_BYTES: [384 4194304]
[ao/alsa] TICK_TIME: ALL
[ao/alsa] ---
[ao/alsa] HW params after access:
[ao/alsa] ---
[ao/alsa] ACCESS:  RW_INTERLEAVED
[ao/alsa] FORMAT:  U8 S16_LE S16_BE S24_LE S24_BE S32_LE S32_BE FLOAT_LE FLOAT_BE MU_LAW A_LAW S24_3LE S24_3BE
[ao/alsa] SUBFORMAT:  STD
[ao/alsa] SAMPLE_BITS: [8 32]
[ao/alsa] FRAME_BITS: [8 1024]
[ao/alsa] CHANNELS: [1 32]
[ao/alsa] RATE: [1 384000]
[ao/alsa] PERIOD_TIME: (2 4294967295)
[ao/alsa] PERIOD_SIZE: [1 1398102)
[ao/alsa] PERIOD_BYTES: [128 1398102)
[ao/alsa] PERIODS: [3 1024]
[ao/alsa] BUFFER_TIME: (7 4294967295]
[ao/alsa] BUFFER_SIZE: [3 4194304]
[ao/alsa] BUFFER_BYTES: [384 4194304]
[ao/alsa] TICK_TIME: ALL
[ao/alsa] ---
[ao/alsa] trying format float/14
[ao/alsa] HW params after format:
[ao/alsa] ---
[ao/alsa] ACCESS:  RW_INTERLEAVED
[ao/alsa] FORMAT:  FLOAT_LE
[ao/alsa] SUBFORMAT:  STD
[ao/alsa] SAMPLE_BITS: 32
[ao/alsa] FRAME_BITS: [32 1024]
[ao/alsa] CHANNELS: [1 32]
[ao/alsa] RATE: [1 384000]
[ao/alsa] PERIOD_TIME: (2 4294967295)
[ao/alsa] PERIOD_SIZE: [1 349526)
[ao/alsa] PERIOD_BYTES: [128 1398102)
[ao/alsa] PERIODS: [3 1024]
[ao/alsa] BUFFER_TIME: (7 4294967295]
[ao/alsa] BUFFER_SIZE: [3 1048576]
[ao/alsa] BUFFER_BYTES: [384 4194304]
[ao/alsa] TICK_TIME: ALL
[ao/alsa] ---
[ao/alsa] HW params after channels:
[ao/alsa] ---
[ao/alsa] ACCESS:  RW_INTERLEAVED
[ao/alsa] FORMAT:  FLOAT_LE
[ao/alsa] SUBFORMAT:  STD
[ao/alsa] SAMPLE_BITS: 32
[ao/alsa] FRAME_BITS: 64
[ao/alsa] CHANNELS: 2
[ao/alsa] RATE: [1 384000]
[ao/alsa] PERIOD_TIME: (41 4294967295)
[ao/alsa] PERIOD_SIZE: [16 174763)
[ao/alsa] PERIOD_BYTES: [128 1398102)
[ao/alsa] PERIODS: [3 1024]
[ao/alsa] BUFFER_TIME: [125 4294967295]
[ao/alsa] BUFFER_SIZE: [48 524288]
[ao/alsa] BUFFER_BYTES: [384 4194304]
[ao/alsa] TICK_TIME: ALL
[ao/alsa] ---
[ao/alsa] HW params after rate-2:
[ao/alsa] ---
[ao/alsa] ACCESS:  RW_INTERLEAVED
[ao/alsa] FORMAT:  FLOAT_LE
[ao/alsa] SUBFORMAT:  STD
[ao/alsa] SAMPLE_BITS: 32
[ao/alsa] FRAME_BITS: 64
[ao/alsa] CHANNELS: 2
[ao/alsa] RATE: 44100
[ao/alsa] PERIOD_TIME: (362 3962880)
[ao/alsa] PERIOD_SIZE: [16 174763)
[ao/alsa] PERIOD_BYTES: [128 1398102)
[ao/alsa] PERIODS: [3 1024]
[ao/alsa] BUFFER_TIME: (1088 11888617)
[ao/alsa] BUFFER_SIZE: [48 524288]
[ao/alsa] BUFFER_BYTES: [384 4194304]
[ao/alsa] TICK_TIME: ALL
[ao/alsa] ---
[ao/alsa] Going to set final HW params:
[ao/alsa] ---
[ao/alsa] ACCESS:  RW_INTERLEAVED
[ao/alsa] FORMAT:  FLOAT_LE
[ao/alsa] SUBFORMAT:  STD
[ao/alsa] SAMPLE_BITS: 32
[ao/alsa] FRAME_BITS: 64
[ao/alsa] CHANNELS: 2
[ao/alsa] RATE: 44100
[ao/alsa] PERIOD_TIME: (24988 25012)
[ao/alsa] PERIOD_SIZE: (1102 1103)
[ao/alsa] PERIOD_BYTES: 8820
[ao/alsa] PERIODS: 4
[ao/alsa] BUFFER_TIME: 100000
[ao/alsa] BUFFER_SIZE: 4410
[ao/alsa] BUFFER_BYTES: 35280
[ao/alsa] TICK_TIME: ALL
[ao/alsa] ---
[ao/alsa] Final HW params:
[ao/alsa] ---
[ao/alsa] ACCESS:  RW_INTERLEAVED
[ao/alsa] FORMAT:  FLOAT_LE
[ao/alsa] SUBFORMAT:  STD
[ao/alsa] SAMPLE_BITS: 32
[ao/alsa] FRAME_BITS: 64
[ao/alsa] CHANNELS: 2
[ao/alsa] RATE: 44100
[ao/alsa] PERIOD_TIME: (24988 24989)
[ao/alsa] PERIOD_SIZE: (1102 1103)
[ao/alsa] PERIOD_BYTES: 8820
[ao/alsa] PERIODS: 4
[ao/alsa] BUFFER_TIME: 100000
[ao/alsa] BUFFER_SIZE: 4410
[ao/alsa] BUFFER_BYTES: 35280
[ao/alsa] TICK_TIME: [0 0]
[ao/alsa] ---
[ao/alsa] hw pausing supported: yes
[ao/alsa] buffersize: 4410 samples
[ao/alsa] period size: 1102 samples
[ao/alsa] device buffer: 4410 samples.
[ao/alsa] using soft-buffer of 8820 samples.

@jeeb
Copy link
Member

jeeb commented Jun 9, 2018

Also one thing that is different that in my case the output supports hw pausing, but seemingly yours doesn't?

[   5.471][v][ao/alsa] hw pausing supported: no

@orbea
Copy link
Contributor Author

orbea commented Jun 9, 2018

I'm not sure, but I suppose the onboard audio card on my motherboard doesn't have support for hw pausing in alsa?

$  aplay --list-devices
**** List of PLAYBACK Hardware Devices ****
card 0: SB [HDA ATI SB], device 0: ALC1150 Analog [ALC1150 Analog]
  Subdevices: 0/1
  Subdevice #0: subdevice #0
card 0: SB [HDA ATI SB], device 1: ALC1150 Digital [ALC1150 Digital]
  Subdevices: 1/1
  Subdevice #0: subdevice #0

@mfcc64 mfcc64 mentioned this issue Jun 20, 2018
Closed
@mfcc64
Copy link
Contributor

mfcc64 commented Jun 20, 2018

Take a look at #5937

qmega referenced this issue Jul 8, 2018
@mfcc64 @jeeb
ao_alsa: replace snd_pcm_status() with snd_pcm_avail() in get_space()
945303a 
Fixes a bug with alsa dmix on Fedora 29. After several minutes,
audio suddenly becomes bad and muted.

Actually, I don't know what causes this. Probably this is a bug in alsa.
In any case, as snd_pcm_status() returns not only 'avail', but also other
fields such as tstamp, htstamp, etc, this could be considered a good
simplification, as only avail is required for this function.
@Anachron
Copy link

I'm still having this issue, hope it gets resolved soon. (There are PRs for this issue)

@umop3plsdn
Copy link

umop3plsdn commented Aug 19, 2018 •
edited
Loading

I'm having the same issue myself. It spams the console like CRAZY! it's weird though if it starts paused it doesn't do it then.

@alex3kov
Copy link

alex3kov commented Aug 22, 2018 •
edited
Loading

Same thing here on Arch and mpv 0.29.0:

~: aplay --list-devices
**** List of PLAYBACK Hardware Devices ****
card 0: HDMI [HDA Intel HDMI], device 3: HDMI 0 [HDMI 0]
  Subdevices: 1/1
  Subdevice #0: subdevice #0
card 0: HDMI [HDA Intel HDMI], device 7: HDMI 1 [HDMI 1]
  Subdevices: 1/1
  Subdevice #0: subdevice #0
card 0: HDMI [HDA Intel HDMI], device 8: HDMI 2 [HDMI 2]
  Subdevices: 1/1
  Subdevice #0: subdevice #0
card 1: PCH [HDA Intel PCH], device 0: ALC3235 Analog [ALC3235 Analog]
  Subdevices: 0/1
  Subdevice #0: subdevice #0
~: echo $ALSA_CARD 
PCH
~: mpv --version
mpv 0.29.0 Copyright © 2000-2018 mpv/MPlayer/mplayer2 projects
 built on Sun Jul 22 21:06:23 CEST 2018
ffmpeg library versions:
   libavutil       56.14.100
   libavcodec      58.18.100
   libavformat     58.12.100
   libswscale      5.1.100
   libavfilter     7.16.100
   libswresample   3.1.100
ffmpeg version: n4.0.2

And according to mpv logs, my card doesn't support hw pausing (it's been mentioned in this issue discussion):

[ao/alsa] hw pausing supported: no

@ghost
Copy link

ghost commented Sep 18, 2018 •
edited by ghost
Loading

Same thing here on Void linux and mpv 0.29.0:

$ aplay --list-devices
**** List of PLAYBACK Hardware Devices ****
card 0: MID [HDA Intel MID], device 0: 92HD75B3X5 Analog [92HD75B3X5 Analog]
  Subdevices: 1/1
  Subdevice #0: subdevice #0
card 0: MID [HDA Intel MID], device 1: 92HD75B3X5 Digital [92HD75B3X5 Digital]
  Subdevices: 1/1
  Subdevice #0: subdevice #0
card 1: NVidia [HDA NVidia], device 3: HDMI 0 [HDMI 0]
  Subdevices: 1/1
  Subdevice #0: subdevice #0
card 1: NVidia [HDA NVidia], device 7: HDMI 0 [HDMI 0]
  Subdevices: 1/1
  Subdevice #0: subdevice #0
card 1: NVidia [HDA NVidia], device 8: HDMI 0 [HDMI 0]
  Subdevices: 1/1
  Subdevice #0: subdevice #0
card 1: NVidia [HDA NVidia], device 9: HDMI 0 [HDMI 0]
  Subdevices: 1/1
  Subdevice #0: subdevice #0

$ mpv --version
mpv 0.29.0 Copyright © 2000-2018 mpv/MPlayer/mplayer2 projects
 built on Mon Aug  6 05:01:38 UTC 2018
ffmpeg library versions:
   libavutil       56.14.100
   libavcodec      58.18.100
   libavformat     58.12.100
   libswscale      5.1.100
   libavfilter     7.16.100
   libswresample   3.1.100
ffmpeg version: 4.0.2

Exiting... (Quit)
[ao/alsa] Error received from snd_pcm_avail (-77, File descriptor in bad state)!
[ao/alsa] Error received from snd_pcm_avail (-77, File descriptor in bad state)!
[ao/alsa] Error received from snd_pcm_avail (-77, File descriptor in bad state)!
[ao/alsa] Error received from snd_pcm_avail (-77, File descriptor in bad state)!

@cz172638
Copy link

same here (fedora 28 / armv7hl):
[indy@localhost ~]$ mpv --start=3:20 --length=30 Videos/big_buck_bunny_720p_h264|
.mov |
Playing: Videos/big_buck_bunny_720p_h264.mov |
(+) Video --vid=1 () (h264 1280x720 24.000fps) |
(+) Audio --aid=1 --alang=eng () (aac 6ch 48000Hz) |
AO: [alsa] 48000Hz stereo 2ch float |
Using hardware decoding (vdpau). |
VO: [vdpau] 1280x720 vdpau[yuv420p]
AV: 00:03:49 / 00:09:56 (38%) A-V: 0.000 |
[ao/alsa] Error received from snd_pcm_avail (-32, Broken pipe)!
[ao/alsa] Error received from snd_pcm_avail (-32, Broken pipe)!
AV: 00:03:49 / 00:09:56 (38%) A-V: 0.000 |

Exiting... (End of file)
[indy@localhost ~]$ mpv --version
mpv 0.29.0 Copyright © 2000-2018 mpv/MPlayer/mplayer2 projects
built on UNKNOWN
ffmpeg library versions:
libavutil 56.14.100
libavcodec 58.18.100
libavformat 58.12.100
libswscale 5.1.100
libavfilter 7.16.100
libswresample 3.1.100
ffmpeg version: 4.0.2

[indy@localhost ~]$ rpm -q mpv |
mpv-0.29.0-1.fc28.armv7hl
[indy@localhost ~]$ aplay --list-devices
**** List of PLAYBACK Hardware Devices ****
card 0: PAZ00 [Compal PAZ00], device 0: ALC5632 PCM alc5632-hifi-0 []
Subdevices: 1/1
Subdevice #0: subdevice #0
[indy@localhost ~]$

@jeeb jeeb mentioned this issue Sep 29, 2018
Merged
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
7 participants
@jeeb @cz172638 @Anachron @umop3plsdn @alex3kov @orbea @mfcc64