Bug 475236

Summary: snd-ens1371: snd_pcm_delay()/snd_pcm_avail() overflows
Product: [Fedora] Fedora Reporter: Peter F. Patel-Schneider <pfpschneider>
Component: kernelAssignee: Jaroslav Kysela <jkysela>
Status: CLOSED WONTFIX QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: medium Docs Contact:
Priority: low    
Version: 10CC: belegdol, bugs.michael, james, jbastian, johnthehammer23, kernel-maint, lkundrak, lpoetter, pachoramos1, yaneti
Target Milestone: ---   
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2009-12-18 07:12:33 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 473302    
Attachments:
Description Flags
Log of pulseaudio -vvvv running rhythmbox for a while
none
kernel messages on snd_hda_intel none

Description Peter F. Patel-Schneider 2008-12-08 16:35:23 UTC
Description of problem:

On one of my machines, I'm not getting any sound, plus I get repeated error messages from pulseaudio.

Version-Release number of selected component (if applicable):

pulseaudio 0.9.13 under Fedora 10 current as of 8 December 2008

How reproducible:

Always (on particular hardware)

Steps to Reproduce:
1. Boot machine (with Ensoniq ES1370 audio device)
2. Try to play a sound (tried using multiple sound apps)
  
Actual results:

No sound; multiple errors (on /var/log/messages)

Dec  8 11:22:53 getafix pulseaudio[2474]: module-alsa-sink.c: ALSA woke us up to write new data to the device, but there was actually nothing to write! Most likely this is an ALSA driver bug. Please report this issue to the PulseAudio developers.
Dec  8 11:22:59 getafix pulseaudio[2474]: module-alsa-sink.c: ALSA woke us up to write new data to the device, but there was actually nothing to write! Most likely this is an ALSA driver bug. Please report this issue to the PulseAudio developers.
Dec  8 11:23:00 getafix pulseaudio[2474]: module-alsa-sink.c: ALSA woke us up to write new data to the device, but there was actually nothing to write! Most likely this is an ALSA driver bug. Please report this issue to the PulseAudio developers.
Dec  8 11:23:08 getafix pulseaudio[2474]: module-alsa-sink.c: ALSA woke us up to write new data to the device, but there was actually nothing to write! Most likely this is an ALSA driver bug. Please report this issue to the PulseAudio developers.
....

Expected results:

Sound; no error messages.

Additional info:

It appears that sounds are recorded from the same PCI card - at least pulseaudio volume control and gnome-sound-recorder (2.24.0.1) both show sound recording and playback shows sound energy.

Pulseaudio volume control lists the output device as Ensoniq AudioPCI - ES1370 DAC 1

Portion of output from lspci -v:

02:08.0 Multimedia audio controller: Ensoniq ES1370 [AudioPCI] (rev 01)
	Subsystem: Device 4942:4c4c
	Flags: bus master, slow devsel, latency 64, IRQ 20
	I/O ports at ef00 [size=64]
	Kernel driver in use: ENS1370
	Kernel modules: snd-ens1370

Output from lsmod:

Module                  Size  Used by
fuse                   49436  2 
sco                    12932  2 
bridge                 43668  0 
stp                     6148  1 bridge
bnep                   14848  2 
l2cap                  21504  3 bnep
bluetooth              48608  5 sco,bnep,l2cap
autofs4                21124  3 
sunrpc                155924  3 
ip6t_REJECT             7296  2 
nf_conntrack_ipv6      15864  2 
ip6table_filter         6400  1 
ip6_tables             14736  1 ip6table_filter
ipv6                  230132  22 ip6t_REJECT,nf_conntrack_ipv6
p4_clockmod             8324  0 
dm_multipath           17164  0 
uinput                 10624  0 
ppdev                  10372  0 
snd_ens1370            24324  3 
gameport               13452  1 snd_ens1370
snd_rawmidi            22528  1 snd_ens1370
snd_seq_dummy           6660  0 
snd_seq_oss            30364  0 
snd_seq_midi_event      9600  1 snd_seq_oss
snd_seq                48576  5 snd_seq_dummy,snd_seq_oss,snd_seq_midi_event
snd_seq_device         10124  4 snd_rawmidi,snd_seq_dummy,snd_seq_oss,snd_seq
snd_pcm_oss            42496  0 
snd_mixer_oss          16896  1 snd_pcm_oss
snd_pcm                65924  2 snd_ens1370,snd_pcm_oss
snd_timer              22024  2 snd_seq,snd_pcm
snd                    50616  16 snd_ens1370,snd_rawmidi,snd_seq_dummy,snd_seq_oss,snd_seq,snd_seq_device,snd_pcm_oss,snd_mixer_oss,snd_pcm,snd_timer
soundcore               9416  1 snd
snd_page_alloc         11016  2 snd_ens1370,snd_pcm
nvidia               7090812  18 
floppy                 51988  0 
parport_pc             25620  0 
parport                31956  2 ppdev,parport_pc
i2c_ali1535             9476  0 
pcspkr                  6272  0 
e100                   33804  0 
mii                     8192  1 e100
i2c_ali1563             9732  0 
i2c_ali15x3             9988  0 
i2c_core               21396  4 nvidia,i2c_ali1535,i2c_ali1563,i2c_ali15x3
ata_generic             8452  0 
pata_acpi               7680  0 
pata_ali               12420  2

Comment 1 Lennart Poettering 2008-12-08 18:23:51 UTC
Your sound driver is broken. It's an ALSA bug. The audio fd signals "writability", but snd_pcm_update_avail() says there's actually nothinbg to write.

Comment 2 Peter F. Patel-Schneider 2008-12-16 17:49:55 UTC
Hmm, so what should be done to notify the appropriate people then?

Comment 3 James 2008-12-19 18:19:05 UTC
I see a lot of these in the syslog, too, but I've not noticed sound breaking. This is with Intel HDA/Realtek 883 hardware:

kernel-2.6.27.9-163.fc10.x86_64
pulseaudio-0.9.13-6.fc10.x86_64
alsa-lib-1.0.18-6.rc3.fc10.x86_64
alsa-lib-1.0.18-6.rc3.fc10.i386

Comment 4 James 2008-12-29 11:40:23 UTC
[Tracking notice: I've filed Bug 478394 for this showing up on Intel HDA.]

Comment 5 John 2009-02-03 22:42:57 UTC
See bug 471941, comment 8 for a workaround for your message log filling up.

Comment 6 Lennart Poettering 2009-03-03 01:37:33 UTC
*** Bug 473153 has been marked as a duplicate of this bug. ***

Comment 7 Jeff Bastian 2009-04-29 14:04:33 UTC
FWIW, I'm still seeing this with Fedora 11 Beta/Rawhide.
  kernel-PAE-2.6.29.1-111.fc11.i686
  pulseaudio-0.9.15-11.fc11.i586

I'm seeing a few similar messages too, e.g., "...nothing to read!" and some "exceptionally large value" errors.

Apr 29 08:48:32 mollusk pulseaudio[2265]: alsa-util.c: snd_pcm_avail() returned a value that is exceptionally large: 327153508 bytes (1854611 ms).
Apr 29 08:48:32 mollusk pulseaudio[2265]: alsa-util.c: snd_pcm_delay() returned a value that is exceptionally large: -326959556 bytes (-1853512 ms).
Apr 29 08:48:36 mollusk pulseaudio[2265]: alsa-source.c: ALSA woke us up to read new data from the device, but there was actually nothing to read!
Apr 29 08:48:36 mollusk pulseaudio[2265]: alsa-source.c: Most likely this is a bug in the ALSA driver 'snd_ens1371'. Please report thisissue to the ALSA developers.
Apr 29 08:48:36 mollusk pulseaudio[2265]: alsa-source.c: We were woken up with POLLIN set -- however a subsequent snd_pcm_avail() returned 0 or another value < min_avail.
Apr 29 08:48:36 mollusk pulseaudio[2265]: alsa-sink.c: ALSA woke us up to write new data to the device, but there was actually nothing to write!
Apr 29 08:48:36 mollusk pulseaudio[2265]: alsa-sink.c: Most likely this is a bug in the ALSA driver 'snd_ens1371'. Please report this issue to the ALSA developers.
Apr 29 08:48:36 mollusk pulseaudio[2265]: alsa-sink.c: We were woken up with POLLOUT set -- however a subsequent snd_pcm_avail() returned 0 or another value < min_avail.

Comment 8 Peter F. Patel-Schneider 2009-05-14 20:25:19 UTC
I'm now running 2.6.29.3-140.fc11.i586, and haven't seen the "nothing to read" bug showing up in several days of continuous sound play (obviously not all on this kernel).  I have seen the following twice today, however:

May 14 09:17:41 getafix pulseaudio[1890]: alsa-source.c: Increasing wakeup watermark to 35.99 ms
May 14 09:17:51 getafix pulseaudio[1890]: alsa-util.c: snd_pcm_avail() returned a value that is exceptionally large: 2147418208 bytes (24347145 ms).
May 14 09:17:51 getafix pulseaudio[1890]: alsa-util.c: Most likely this is a bug in the ALSA driver 'snd_ens1370'. Please report this issue to the ALSA developers.
May 14 09:17:51 getafix pulseaudio[1890]: alsa-util.c: snd_pcm_dump():
May 14 09:17:51 getafix pulseaudio[1890]: alsa-util.c: Hardware PCM card 0 'Ensoniq AudioPCI' device 0 subdevice 0
May 14 09:17:51 getafix pulseaudio[1890]: alsa-util.c: Its setup is:
May 14 09:17:51 getafix pulseaudio[1890]: alsa-util.c:   stream       : CAPTURE
May 14 09:17:51 getafix pulseaudio[1890]: alsa-util.c:   access       : MMAP_INTERLEAVED
May 14 09:17:51 getafix pulseaudio[1890]: alsa-util.c:   format       : S16_LE
May 14 09:17:51 getafix pulseaudio[1890]: alsa-util.c:   subformat    : STD
May 14 09:17:51 getafix pulseaudio[1890]: alsa-util.c:   channels     : 1
May 14 09:17:51 getafix pulseaudio[1890]: alsa-util.c:   rate         : 44100
May 14 09:17:51 getafix pulseaudio[1890]: alsa-util.c:   exact rate   : 44100 (1411200/32)
May 14 09:17:51 getafix pulseaudio[1890]: alsa-util.c:   msbits       : 16
May 14 09:17:51 getafix pulseaudio[1890]: alsa-util.c:   buffer_size  : 32768
May 14 09:17:51 getafix pulseaudio[1890]: alsa-util.c:   period_size  : 32768
May 14 09:17:51 getafix pulseaudio[1890]: alsa-util.c:   period_time  : 743038
May 14 09:17:51 getafix pulseaudio[1890]: alsa-util.c:   tstamp_mode  : ENABLE
May 14 09:17:51 getafix pulseaudio[1890]: alsa-util.c:   period_step  : 1
May 14 09:17:51 getafix pulseaudio[1890]: alsa-util.c:   avail_min    : 32768
May 14 09:17:51 getafix pulseaudio[1890]: alsa-util.c:   period_event : 0
May 14 09:17:51 getafix pulseaudio[1890]: alsa-util.c:   start_threshold  : -1
May 14 09:17:51 getafix pulseaudio[1890]: alsa-util.c:   stop_threshold   : 1073741824
May 14 09:17:51 getafix pulseaudio[1890]: alsa-util.c:   silence_threshold: 0
May 14 09:17:51 getafix pulseaudio[1890]: alsa-util.c:   silence_size : 0
May 14 09:17:51 getafix pulseaudio[1890]: alsa-util.c:   boundary     : 1073741824
May 14 09:17:51 getafix pulseaudio[1890]: alsa-util.c:   appl_ptr     : 819184
May 14 09:17:51 getafix pulseaudio[1890]: alsa-util.c:   hw_ptr       : 786464
May 14 09:17:51 getafix pulseaudio[1890]: alsa-source.c: Increasing minimal latency to 56.00 ms

Comment 9 Julian Sikorski 2009-05-18 20:38:58 UTC
This is especially happening with kvm guests, since ens1370 is what is being emulated.

Comment 10 Lennart Poettering 2009-05-18 20:48:42 UTC
*** Bug 497392 has been marked as a duplicate of this bug. ***

Comment 11 Peter F. Patel-Schneider 2009-05-18 22:36:38 UTC
I haven't seen this problem since alsa-lib 1.0.20 was installed, so it may have been eradicated.

Comment 12 Yanko Kaneti 2009-05-19 04:02:53 UTC
I reported bug 497392 and my sound card isn't Ensoniq ES1370 , its a HDA with realtek chip. Either this bug isn't named properly or my bug was erroneously marked as duplicate.

Comment 13 Julian Sikorski 2009-05-19 08:47:51 UTC
I can still reproduce the problem with kvm guest:
Fedora 11 i386 guest
Fedora 10 x86_64 host
alsa-lib-1.0.20-1.fc11.i586
alsa-plugins-pulseaudio-1.0.18-3.fc11.i586
alsa-utils-1.0.20-3.fc11.i586
Please keep in mind that i586 kernel has to be running, i686 pae won't work at all due to bug #492838.

Comment 14 Julian Sikorski 2009-05-19 08:59:23 UTC
Created attachment 344593 [details]
Log of pulseaudio -vvvv running rhythmbox for a while

The only thing that goes out of the speakers is a looping first few miliseconds of the song. In case that matters, this is with kernel 2.6.29.3-140.fc11.i586 running on the guest.

Comment 15 Michael Schwendt 2009-06-21 10:18:35 UTC
What is written in comment 7 also affects me with Fedora 11.

Comment 16 Bill McGonigle 2009-06-23 15:40:29 UTC
Created attachment 349107 [details]
kernel messages on snd_hda_intel

I'm seeing similar on snd_hda_intel.  

00:1b.0 Audio device: Intel Corporation 82801G (ICH7 Family) High Definition Audio Controller (rev 02)
        Subsystem: ASUSTeK Computer Inc. Device 834a                                                  
        Flags: bus master, fast devsel, latency 0, IRQ 16                                             
        Memory at f7eb8000 (64-bit, non-prefetchable) [size=16K]                                      
        Capabilities: <access denied>                                                                 
        Kernel driver in use: HDA Intel                                                               
        Kernel modules: snd-hda-intel    

kernel-2.6.29.4-167.fc11.i586
pulseaudio-0.9.15-11.fc11.i586

Comment 17 Bug Zapper 2009-11-18 10:23:47 UTC
This message is a reminder that Fedora 10 is nearing its end of life.
Approximately 30 (thirty) days from now Fedora will stop maintaining
and issuing updates for Fedora 10.  It is Fedora's policy to close all
bug reports from releases that are no longer maintained.  At that time
this bug will be closed as WONTFIX if it remains open with a Fedora 
'version' of '10'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version prior to Fedora 10's end of life.

Bug Reporter: Thank you for reporting this issue and we are sorry that 
we may not be able to fix it before Fedora 10 is end of life.  If you 
would still like to see this bug fixed and are able to reproduce it 
against a later version of Fedora please change the 'version' of this 
bug to the applicable version.  If you are unable to change the version, 
please add a comment here and someone will do it for you.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events.  Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

The process we are following is described here: 
http://fedoraproject.org/wiki/BugZappers/HouseKeeping

Comment 18 Bug Zapper 2009-12-18 07:12:33 UTC
Fedora 10 changed to end-of-life (EOL) status on 2009-12-17. Fedora 10 is 
no longer maintained, which means that it will not receive any further 
security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of 
Fedora please feel free to reopen this bug against that version.

Thank you for reporting this bug and we are sorry it could not be fixed.