22172 – alsa-util.c: snd_pcm_avail_delay() returned strange values: delay 0 is less than avail 32

Bug 22172 - alsa-util.c: snd_pcm_avail_delay() returned strange values: delay 0 is less than avail 32

Summary: alsa-util.c: snd_pcm_avail_delay() returned strange values: delay 0 is less t...

Status:	CLOSED UNREPRODUCIBLE

Alias:	None

Product:	Drivers
Classification:	Unclassified
Component:	Sound(ALSA) (show other bugs)
Hardware:	All Linux

Importance:	P1 normal
Assignee:	Jaroslav Kysela

URL:
Keywords:

Depends on:
Blocks:	16444
	Show dependency tree

Reported:	2010-11-06 09:33 UTC by Tobias
Modified:	2011-04-21 08:57 UTC (History)
CC List:	7 users (show)

See Also:
Kernel Version:	2.6.37-rc1
Subsystem:
Regression:	Yes
Bisected commit-id:

Attachments
Add an attachment (proposed patch, testcase, etc.)

Description Tobias 2010-11-06 09:33:11 UTC

I am starting to see this in syslog:


Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c: snd_pcm_avail_delay() returned strange values: delay 0 is less than avail 32.
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c: Most likely this is a bug in the ALSA driver 'snd_hda_intel'. Please report this issue to the ALSA developers.
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c: snd_pcm_dump():
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c: Soft volume PCM
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c: Control: PCM Playback Volume
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c: min_dB: -51
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c: max_dB: 0
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c: resolution: 256
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c: Its setup is:
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   stream       : CAPTURE
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   access       : MMAP_INTERLEAVED
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   format       : S16_LE
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   subformat    : STD
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   channels     : 2
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   rate         : 44100
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   exact rate   : 44100 (44100/1)
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   msbits       : 16
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   buffer_size  : 16384
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   period_size  : 8192
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   period_time  : 185759
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   tstamp_mode  : ENABLE
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   period_step  : 1
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   avail_min    : 15502
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   period_event : 0
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   start_threshold  : -1
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   stop_threshold   : 4611686018427387904
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   silence_threshold: 0
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   silence_size : 0
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   boundary     : 4611686018427387904
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c: Slave: Hardware PCM card 0 'HDA Intel' device 0 subdevice 0
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c: Its setup is:
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   stream       : CAPTURE
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   access       : MMAP_INTERLEAVED
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   format       : S16_LE
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   subformat    : STD
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   channels     : 2
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   rate         : 44100
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   exact rate   : 44100 (44100/1)
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   msbits       : 16
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   buffer_size  : 16384
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   period_size  : 8192
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   period_time  : 185759
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   tstamp_mode  : ENABLE
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   period_step  : 1
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   avail_min    : 15502
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   period_event : 0
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   start_threshold  : -1
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   stop_threshold   : 4611686018427387904
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   silence_threshold: 0
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   silence_size : 0
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   boundary     : 4611686018427387904
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   appl_ptr     : 15536
Nov  6 10:21:11 lucid pulseaudio[1490]: alsa-util.c:   hw_ptr       : 15536

Comment 1 Tobias 2010-11-06 09:36:04 UTC

Probably related:

Nov  6 08:48:06 lucid pulseaudio[10496]: alsa-sink.c: ALSA woke us up to write new data to the device, but there was actually nothing to write!
Nov  6 08:48:06 lucid pulseaudio[10496]: alsa-sink.c: Most likely this is a bug in the ALSA driver 'snd_hda_intel'. Please report this issue to the ALSA deve
lopers.
Nov  6 08:48:06 lucid pulseaudio[10496]: alsa-sink.c: We were woken up with POLLOUT set -- however a subsequent snd_pcm_avail() returned 0 or another value <
 min_avail.

Forgot to add device info:

00:1b.0 Audio device: Intel Corporation N10/ICH 7 Family High Definition Audio Controller (rev 02)

Comment 2 Daniel T Chen 2010-12-05 20:23:33 UTC

Please use http://www.alsa-project.org/alsa-info.sh

Comment 3 Tom Gundersen 2010-12-12 02:54:57 UTC

I'm observing a similar problem. Here is my alsa-info: <http://www.alsa-project.org/db/?f=2edaf27ae5afd76f0767e82d31d4515c134ef18c>.

And here is my syslog output:

Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c: snd_pcm_avail_delay() returned strange values: delay 0 is less than avail 16.
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c: Most likely this is a bug in the ALSA driver 'snd_hda_intel'. Please report this issue to the ALSA developers.
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c: snd_pcm_dump():
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c: Soft volume PCM
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c: Control: PCM Playback Volume
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c: min_dB: -51
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c: max_dB: 0
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c: resolution: 256
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c: Its setup is:
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   stream       : CAPTURE
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   access       : MMAP_INTERLEAVED
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   format       : S16_LE
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   subformat    : STD
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   channels     : 2
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   rate         : 44100
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   exact rate   : 44100 (44100/1)
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   msbits       : 16
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   buffer_size  : 16384
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   period_size  : 8192
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   period_time  : 185759
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   tstamp_mode  : ENABLE
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   period_step  : 1
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   avail_min    : 15502
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   period_event : 0
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   start_threshold  : -1
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   stop_threshold   : 4611686018427387904
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   silence_threshold: 0
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   silence_size : 0
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   boundary     : 4611686018427387904
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c: Slave: Hardware PCM card 0 'HDA Intel' device 0 subdevice 0
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c: Its setup is:
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   stream       : CAPTURE
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   access       : MMAP_INTERLEAVED
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   format       : S16_LE
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   subformat    : STD
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   channels     : 2
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   rate         : 44100
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   exact rate   : 44100 (44100/1)
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   msbits       : 16
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   buffer_size  : 16384
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   period_size  : 8192
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   period_time  : 185759
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   tstamp_mode  : ENABLE
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   period_step  : 1
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   avail_min    : 15502
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   period_event : 0
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   start_threshold  : -1
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   stop_threshold   : 4611686018427387904
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   silence_threshold: 0
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   silence_size : 0
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   boundary     : 4611686018427387904
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   appl_ptr     : 15520
Dec 12 02:53:20 dell pulseaudio[756]: alsa-util.c:   hw_ptr       : 15520

Comment 4 Florian Mickler 2011-03-29 21:48:13 UTC

Is this still happening on 2.6.38.y?

Comment 5 Florian Mickler 2011-04-20 20:03:31 UTC

*ping*

Comment 6 Tom Gundersen 2011-04-20 22:42:32 UTC

Sorry for the slow response.

I have not seen this in a while (using 2.6.39-rcX). I will report back if I do.

Comment 7 Florian Mickler 2011-04-21 08:56:55 UTC

Thanks for the update. Please do. 

In the meantime, I will close this report.

Note You need to log in before you can comment on or make changes to this bug.