Re: [ALSA] emu10k1: hw_ptr skipping when unpausing mplayer

[Takashi Iwai <tiwai@suse.de>]

At Sat, 18 Jul 2009 16:07:07 +0000 (UTC),
Piotr Kaczuba wrote:
> 
> Since 2.6.30 I'm experiencing sound and video stuttering when unpausing 
> mplayer. The soundcard is an Audigy 1, driver is emu10k1. Kernel is 
> x86_64, userspace is 32-bit. I doesn't happen always, but regularly 
> enough.

To be sure -- isn't it arch-independent?  I guess 64bit user-space
can cause the same problem.

> 
> 
> Below is the ouput of mplayer:
> 
> [AO_ALSA] alsa-lib: pcm.c:6482:(snd_pcm_mmap_commit) commit offset (8886) 
> doesn't match with appl_ptr (139955) % buf_size (16384)
> [AO_ALSA] Write error: Broken pipe
> [AO_ALSA] Trying to reset soundcard.
> [AO_ALSA] alsa-lib: pcm_hw.c:578:(snd_pcm_hw_prepare) 
> SNDRV_PCM_IOCTL_PREPARE failed: Device or resource busy
> [AO_ALSA] alsa-lib: pcm_hw.c:578:(snd_pcm_hw_prepare) 
> SNDRV_PCM_IOCTL_PREPARE failed: Device or resource busy
> [AO_ALSA] alsa-lib: pcm_hw.c:578:(snd_pcm_hw_prepare) 
> SNDRV_PCM_IOCTL_PREPARE failed: Device or resource busy
> [AO_ALSA] pcm prepare error: Device or resource busy

Hm, these errors in snd_pcm_hw_prepare look different.
Maybe it's a bug in libao, but needs more investigation.


> After setting xrun_debug to 5 I get the following in the log:
> 
> PCM: hw_ptr skipping! [Q] (pos=3071, delta=17225, period=1024, 
> jdelta=18/358/0)
> Pid: 0, comm: swapper Not tainted 2.6.30.1-orbiter.x86-64.1 #1
> Call Trace:
>  <IRQ>  [<ffffffffa02d7c7f>] ? snd_pcm_period_elapsed+0x4df/0x520 
> [snd_pcm]
>  [<ffffffffa031f15f>] ? snd_emu10k1_interrupt+0x25f/0x550 [snd_emu10k1]
>  [<ffffffff8023a9ba>] ? run_timer_softirq+0x1a/0x250
>  [<ffffffff80268e99>] ? handle_IRQ_event+0x39/0xe0
>  [<ffffffff8026ad19>] ? handle_fasteoi_irq+0x79/0x110
>  [<ffffffff8020dd17>] ? handle_irq+0x17/0x20
>  [<ffffffff8020d7c1>] ? do_IRQ+0x51/0xd0
>  [<ffffffff8020bd13>] ? ret_from_intr+0x0/0x9
>  <EOI>  [<ffffffff8021bea0>] ? lapic_next_event+0x0/0x20
>  [<ffffffff802127aa>] ? default_idle+0x3a/0x40
>  [<ffffffff8020a017>] ? cpu_idle+0x47/0xa0
>  [<ffffffff805a5aba>] ? start_kernel+0x2c3/0x384
>  [<ffffffff805a5373>] ? x86_64_start_kernel+0xe1/0xf2
> PCM: hw_ptr skipping! (pos=5482, delta=3434, period=1024, jdelta=50/71)
> Pid: 2870, comm: mplayer Not tainted 2.6.30.1-orbiter.x86-64.1 #1
> Call Trace:
>  [<ffffffffa02d6bd3>] ? snd_pcm_update_hw_ptr+0x1d3/0x220 [snd_pcm]
>  [<ffffffffa02d211d>] ? snd_pcm_hwsync+0x9d/0xe0 [snd_pcm]
>  [<ffffffffa02d54e3>] ? snd_pcm_ioctl_compat+0x753/0x980 [snd_pcm]
>  [<ffffffff80209b36>] ? __switch_to+0x226/0x270
>  [<ffffffff80475407>] ? thread_return+0x30/0x1f9
>  [<ffffffff8024a032>] ? hrtimer_cancel+0x12/0x20
>  [<ffffffff80476710>] ? do_nanosleep+0x30/0xb0
>  [<ffffffff8024a0e0>] ? hrtimer_nanosleep+0xa0/0x130
>  [<ffffffff802ddd8b>] ? compat_sys_ioctl+0x19b/0x3e0
>  [<ffffffff8024d3bb>] ? getnstimeofday+0x5b/0xe0
>  [<ffffffff80266b56>] ? audit_syscall_entry+0x166/0x190
>  [<ffffffff80227266>] ? cstar_dispatch+0x7/0x26
> PCM: hw_ptr skipping! [Q] (pos=7443, delta=5395, period=1024, 
> jdelta=91/112/2)
> Pid: 2870, comm: mplayer Not tainted 2.6.30.1-orbiter.x86-64.1 #1
> Call Trace:
>  <IRQ>  [<ffffffffa02d7c7f>] ? snd_pcm_period_elapsed+0x4df/0x520 
> [snd_pcm]
>  [<ffffffffa031f15f>] ? snd_emu10k1_interrupt+0x25f/0x550 [snd_emu10k1]
>  [<ffffffff80268e99>] ? handle_IRQ_event+0x39/0xe0
>  [<ffffffff8022cd9d>] ? try_to_wake_up+0x14d/0x160
>  [<ffffffff8026ad19>] ? handle_fasteoi_irq+0x79/0x110
>  [<ffffffff8020dd17>] ? handle_irq+0x17/0x20
>  [<ffffffff8020d7c1>] ? do_IRQ+0x51/0xd0
>  [<ffffffff8020bd13>] ? ret_from_intr+0x0/0x9
>  [<ffffffff8021bea0>] ? lapic_next_event+0x0/0x20
>  [<ffffffff802354bd>] ? __do_softirq+0x3d/0xf0
>  [<ffffffff8020c2ea>] ? call_softirq+0x1a/0x30
>  [<ffffffff8020dcbd>] ? do_softirq+0x2d/0x70
>  [<ffffffff802352a5>] ? irq_exit+0x85/0xa0
>  [<ffffffff8021c74e>] ? smp_apic_timer_interrupt+0x4e/0x80
>  [<ffffffff8020be63>] ? apic_timer_interrupt+0x13/0x20
>  <EOI>  [<ffffffffa02d20d9>] ? snd_pcm_hwsync+0x59/0xe0 [snd_pcm]
>  [<ffffffffa02d211d>] ? snd_pcm_hwsync+0x9d/0xe0 [snd_pcm]
>  [<ffffffffa02d54e3>] ? snd_pcm_ioctl_compat+0x753/0x980 [snd_pcm]
>  [<ffffffff80209b36>] ? __switch_to+0x226/0x270
>  [<ffffffff80475407>] ? thread_return+0x30/0x1f9
>  [<ffffffff8024a032>] ? hrtimer_cancel+0x12/0x20
>  [<ffffffff80476710>] ? do_nanosleep+0x30/0xb0
>  [<ffffffff8024a0e0>] ? hrtimer_nanosleep+0xa0/0x130
>  [<ffffffff802ddd8b>] ? compat_sys_ioctl+0x19b/0x3e0
>  [<ffffffff8024d3bb>] ? getnstimeofday+0x5b/0xe0
>  [<ffffffff80266b56>] ? audit_syscall_entry+0x166/0x190
>  [<ffffffff80227266>] ? cstar_dispatch+0x7/0x26
> 
> The log is virtually flooded with these messages until I interrupt 
> mplayer.

It's endless because the reset failed in the above.

The problem is likely due to some wrong operation in the pause/restart.
Does the patch below work around a problem?

If this works (somehow, not causing the same error), we can focus more
on the pause implementation of emu10k1.


thanks,

Takashi

---
diff --git a/sound/pci/emu10k1/emupcm.c b/sound/pci/emu10k1/emupcm.c
index 55b83ef..ae405a4 100644
--- a/sound/pci/emu10k1/emupcm.c
+++ b/sound/pci/emu10k1/emupcm.c
@@ -953,7 +953,7 @@ static struct snd_pcm_hardware snd_emu10k1_playback =
 	.info =			(SNDRV_PCM_INFO_MMAP | SNDRV_PCM_INFO_INTERLEAVED |
 				 SNDRV_PCM_INFO_BLOCK_TRANSFER |
 				 SNDRV_PCM_INFO_RESUME |
-				 SNDRV_PCM_INFO_MMAP_VALID | SNDRV_PCM_INFO_PAUSE),
+				 SNDRV_PCM_INFO_MMAP_VALID /*| SNDRV_PCM_INFO_PAUSE*/),
 	.formats =		SNDRV_PCM_FMTBIT_U8 | SNDRV_PCM_FMTBIT_S16_LE,
 	.rates =		SNDRV_PCM_RATE_CONTINUOUS | SNDRV_PCM_RATE_8000_96000,
 	.rate_min =		4000,