public inbox for linux-kernel@vger.kernel.org
 help / color / mirror / Atom feed
From: Ed Tomlinson <edt@aei.ca>
To: Takashi Iwai <tiwai@suse.de>
Cc: "Rafael J. Wysocki" <rjw@sisk.pl>,
	linux-kernel@vger.kernel.org, alsa-devel@alsa-project.org
Subject: Re: [LOCKDEP] 33-rc8 Running aplay with pulse as the default
Date: Mon, 15 Feb 2010 17:24:54 -0500	[thread overview]
Message-ID: <201002151724.54807.edt@aei.ca> (raw)
In-Reply-To: <s5hfx52cnjg.wl%tiwai@suse.de>

On Monday 15 February 2010 14:21:55 Takashi Iwai wrote:
> At Mon, 15 Feb 2010 20:20:22 +0100,
> I wrote:
> > 
> > At Sat, 13 Feb 2010 12:17:10 -0500,
> > Ed Tomlinson wrote:
> > > 
> > > Hi,
> > > 
> > > Inorder to get skype working with linux I have the following in .asoundrc for my normal userid.
> > > 
> > > ---
> > > pcm.pulse {
> > >     type pulse
> > > }
> > > 
> > > ctl.pulse {
> > >     type pulse
> > > }
> > > 
> > > pcm.!default {
> > >     type pulse
> > > }
> > > ctl.!default {
> > >     type pulse
> > > ---
> > > 
> > > Try #1
> > > Starting as root if I do:
> > > su - <id>
> > > aplay sound.wav
> > > <traceback inlined below>
> > > aplay sound.wav 
> > > (silence)
> > > killall pulseaudio
> > > aplay sound.wav
> > > (works as expected now going thru pulseaudio)
> > > 
> > > Try #2
> > > Starting as root if I do:
> > > aplay sound.wav
> > > (works as expected using alsa alone)
> > > su - <id>
> > > aplay sound.wav
> > > <another lockdep traceback>
> > > aplay sound.wav
> > > (works as expected now going thru pulseaudio)
> > > 
> > > With .32 there were no tracebacks (lockdep was enabled) and try #1 would work where I now get silence.
> > > 
> > > Ideas?
> > > Ed Tomlinson
> > > 
> > > aplay -l
> > > **** List of PLAYBACK Hardware Devices ****
> > > card 0: SB [HDA ATI SB], device 0: ALC1200 Analog [ALC1200 Analog]
> > >   Subdevices: 0/1
> > >   Subdevice #0: subdevice #0
> > > card 0: SB [HDA ATI SB], device 1: ALC1200 Digital [ALC1200 Digital]
> > >   Subdevices: 1/1
> > >   Subdevice #0: subdevice #0
> > > card 1: HDMI [HDA ATI HDMI], device 3: ATI HDMI [ATI HDMI]
> > >   Subdevices: 1/1
> > >   Subdevice #0: subdevice #0
> > > 
> > > "ALC1200 Analog" is what has speakers connected
> > > 
> > > The em28xx in the traceback is an input source from a usb hdtv dongle.
> > > 
> > > pavucontrol setup has been verified.
> > > 
> > > [   91.070620]                                                                                                                               
> > > [   91.070621] =======================================================                                                                       
> > > [   91.071378] [ INFO: possible circular locking dependency detected ]                                                                       
> > > [   91.071378] 2.6.33-rc8-crc #106                                                                                                           
> > > [   91.071378] -------------------------------------------------------                                                                       
> > > [   91.071378] pulseaudio/2717 is trying to acquire lock:                                                                                    
> > > [   91.071378]  (&dev->lock){+.+.+.}, at: [<ffffffffa02797f1>] snd_em28xx_capture_open+0x61/0x190 [em28xx_alsa]                              
> > > [   91.071378]                                                                                                                               
> > > [   91.071378] but task is already holding lock:                                                                                             
> > > [   91.071378]  (&pcm->open_mutex){+.+.+.}, at: [<ffffffffa010ecd2>] snd_pcm_open+0x182/0x450 [snd_pcm]                                      
> > > [   91.071378]                                                                                                                               
> > > [   91.071378] which lock already depends on the new lock.                                                                                   
> > > [   91.071378]                                                                                                                               
> > > [   91.071378]                                                                                                                               
> > > [   91.071378] the existing dependency chain (in reverse order) is:                                                                          
> > > [   91.071378]                                                                                                                               
> > > [   91.071378] -> #3 (&pcm->open_mutex){+.+.+.}:                                                                                             
> > > [   91.071378]        [<ffffffff81083215>] __lock_acquire+0xfc5/0x1550                                                                       
> > > [   91.071378]        [<ffffffff8108383c>] lock_acquire+0x9c/0x140                                                                           
> > > [   91.071378]        [<ffffffff814b96c1>] __mutex_lock_common+0x61/0x610                                                                    
> > > [   91.071378]        [<ffffffff814b9d53>] mutex_lock_nested+0x43/0x50                                                                       
> > > [   91.071378]        [<ffffffffa010ad32>] snd_pcm_release+0x42/0xb0 [snd_pcm]                                                               
> > > [   91.071378]        [<ffffffff8112115d>] __fput+0x15d/0x290                                                                                
> > > [   91.071378]        [<ffffffff811212ad>] fput+0x1d/0x30                                                                                    
> > > [   91.071378]        [<ffffffff810fe001>] remove_vma+0x51/0x80                                                                              
> > > [   91.071378]        [<ffffffff810ffa1d>] do_munmap+0x2fd/0x390                                                                             
> > > [   91.071378]        [<ffffffff810ffb06>] sys_munmap+0x56/0x80                                                                              
> > > [   91.071378]        [<ffffffff81002adb>] system_call_fastpath+0x16/0x1b                                                                    
> > > [   91.071378]                                                                                                                               
> > > [   91.071378] -> #2 (&mm->mmap_sem){++++++}:                                                                                                
> > > [   91.071378]        [<ffffffff81083215>] __lock_acquire+0xfc5/0x1550                                                                       
> > > [   91.071378]        [<ffffffff8108383c>] lock_acquire+0x9c/0x140                                                                           
> > > [   91.071378]        [<ffffffff810f62c7>] might_fault+0xa7/0xd0                                                                             
> > > [   91.071378]        [<ffffffff8113102b>] filldir+0x7b/0xe0                                                                                 
> > > [   91.071378]        [<ffffffff8118aa21>] sysfs_readdir+0xf1/0x1b0                                                                          
> > > [   91.071378]        [<ffffffff81131268>] vfs_readdir+0xb8/0xe0                                                                             
> > > [   91.071378]        [<ffffffff8113144d>] sys_getdents+0xad/0x110                                                                           
> > > [   91.071378]        [<ffffffff81002adb>] system_call_fastpath+0x16/0x1b                                                                    
> > > [   91.071378]                                                                                                                               
> > > [   91.071378] -> #1 (sysfs_mutex){+.+.+.}:                                                                                                  
> > > [   91.071378]        [<ffffffff81083215>] __lock_acquire+0xfc5/0x1550                                                                       
> > > [   91.071378]        [<ffffffff8108383c>] lock_acquire+0x9c/0x140                                                                           
> > > [   91.071378]        [<ffffffff814b96c1>] __mutex_lock_common+0x61/0x610                                                                    
> > > [   91.071378]        [<ffffffff814b9d53>] mutex_lock_nested+0x43/0x50                                                                       
> > > [   91.071378]        [<ffffffff8118b082>] sysfs_addrm_start+0x22/0x30                                                                       
> > > [   91.071378]        [<ffffffff8118bc58>] create_dir+0x58/0xb0                                                                              
> > > [   91.514885]        [<ffffffff8118bd0a>] sysfs_create_dir+0x5a/0x70                                                                        
> > > [   91.514885]        [<ffffffff8123ebbd>] kobject_add_internal+0xbd/0x1f0                                                                   
> > > [   91.514885]        [<ffffffff8123ee08>] kobject_add_varg+0x38/0x60                                                                        
> > > [   91.514885]        [<ffffffff8123eee4>] kobject_add+0x44/0x70                                                                             
> > > [   91.514885]        [<ffffffff81392510>] device_add+0xb0/0x5e0                                                                             
> > > [   91.514885]        [<ffffffff81392a5e>] device_register+0x1e/0x30                                                                         
> > > [   91.514885]        [<ffffffff8140a50d>] i2c_register_adapter+0x12d/0x250                                                                  
> > > [   91.514885]        [<ffffffff8140a7f1>] i2c_add_adapter+0xb1/0xd0                                                                         
> > > [   91.514885]        [<ffffffffa0231ba4>] em28xx_i2c_register+0x104/0x520 [em28xx]                                                          
> > > [   91.514885]        [<ffffffffa0233daa>] em28xx_usb_probe+0x68a/0xb90 [em28xx]                                                             
> > > [   91.514885]        [<ffffffff813eb4ab>] usb_probe_interface+0xeb/0x1b0                                                                    
> > > [   91.514885]        [<ffffffff81395546>] driver_probe_device+0xc6/0x1d0                                                                    
> > > [   91.514885]        [<ffffffff813956eb>] __driver_attach+0x9b/0xa0                                                                         
> > > [   91.514885]        [<ffffffff8139492c>] bus_for_each_dev+0x6c/0xa0                                                                        
> > > [   91.514885]        [<ffffffff8139535e>] driver_attach+0x1e/0x20                                                                           
> > > [   91.514885]        [<ffffffff81394c11>] bus_add_driver+0xe1/0x280                                                                         
> > > [   91.514885]        [<ffffffff81395a58>] driver_register+0x98/0x140                                                                        
> > > [   91.514885]        [<ffffffff813ea06c>] usb_register_driver+0xdc/0x1a0                                                                    
> > > [   91.514885]        [<ffffffffa0248023>] 0xffffffffa0248023                                                                                
> > > [   91.514885]        [<ffffffff810001dc>] do_one_initcall+0x3c/0x1d0                                                                        
> > > [   91.514885]        [<ffffffff81092d75>] sys_init_module+0xe5/0x250                                                                        
> > > [   91.514885]        [<ffffffff81002adb>] system_call_fastpath+0x16/0x1b                                                                    
> > > [   91.514885]                                                                                                                               
> > > [   91.514885] -> #0 (&dev->lock){+.+.+.}:                                                                                                   
> > > [   91.514885]        [<ffffffff81083668>] __lock_acquire+0x1418/0x1550                                                                      
> > > [   91.514885]        [<ffffffff8108383c>] lock_acquire+0x9c/0x140                                                                           
> > > [   91.514885]        [<ffffffff814b96c1>] __mutex_lock_common+0x61/0x610                                                                    
> > > [   91.514885]        [<ffffffff814b9d53>] mutex_lock_nested+0x43/0x50
> > > [   91.514885]        [<ffffffffa02797f1>] snd_em28xx_capture_open+0x61/0x190 [em28xx_alsa]
> > > [   91.514885]        [<ffffffffa010adee>] snd_pcm_open_substream+0x4e/0x90 [snd_pcm]
> > > [   91.514885]        [<ffffffffa010ece9>] snd_pcm_open+0x199/0x450 [snd_pcm]
> > > [   91.514885]        [<ffffffffa010efd4>] snd_pcm_capture_open+0x34/0x40 [snd_pcm]
> > > [   91.514885]        [<ffffffffa00c5778>] snd_open+0x198/0x4e0 [snd]
> > > [   91.514885]        [<ffffffff8112384d>] chrdev_open+0x17d/0x320
> > > [   91.514885]        [<ffffffff8111d358>] __dentry_open+0x1a8/0x400
> > > [   91.514885]        [<ffffffff8111d6b4>] nameidata_to_filp+0x54/0x70
> > > [   91.514885]        [<ffffffff8112e7f1>] do_filp_open+0x841/0xc00
> > > [   91.514885]        [<ffffffff8111e954>] do_sys_open+0xa4/0x180
> > > [   91.514885]        [<ffffffff8111ea70>] sys_open+0x20/0x30
> > > [   91.514885]        [<ffffffff81002adb>] system_call_fastpath+0x16/0x1b
> > > [   91.514885]
> > > [   91.514885] other info that might help us debug this:
> > > [   91.514885]
> > > [   91.514885] 1 lock held by pulseaudio/2717:
> > > [   91.514885]  #0:  (&pcm->open_mutex){+.+.+.}, at: [<ffffffffa010ecd2>] snd_pcm_open+0x182/0x450 [snd_pcm]
> > > [   91.514885]
> > > [   91.514885] stack backtrace:
> > > [   91.514885] Pid: 2717, comm: pulseaudio Not tainted 2.6.33-rc8-crc #106
> > > [   91.514885] Call Trace:
> > > [   91.514885]  [<ffffffff81080fd9>] print_circular_bug+0xe9/0xf0
> > > [   91.514885]  [<ffffffff81083668>] __lock_acquire+0x1418/0x1550
> > > [   91.514885]  [<ffffffff81081dc8>] ? debug_check_no_locks_freed+0xc8/0x150
> > > [   91.514885]  [<ffffffff8108383c>] lock_acquire+0x9c/0x140
> > > [   91.514885]  [<ffffffffa02797f1>] ? snd_em28xx_capture_open+0x61/0x190 [em28xx_alsa]
> > > [   91.514885]  [<ffffffff814b96c1>] __mutex_lock_common+0x61/0x610
> > > [   91.514885]  [<ffffffffa02797f1>] ? snd_em28xx_capture_open+0x61/0x190 [em28xx_alsa]
> > > [   91.514885]  [<ffffffffa02797f1>] ? snd_em28xx_capture_open+0x61/0x190 [em28xx_alsa]
> > > [   91.514885]  [<ffffffffa0109c70>] ? snd_pcm_hw_rule_muldivk+0x0/0xa0 [snd_pcm]
> > > [   91.514885]  [<ffffffff8107fd54>] ? lockdep_init_map+0x44/0x130
> > > [   91.514885]  [<ffffffff814b9d53>] mutex_lock_nested+0x43/0x50
> > > [   91.514885]  [<ffffffffa02797f1>] snd_em28xx_capture_open+0x61/0x190 [em28xx_alsa]
> > > [   91.514885]  [<ffffffffa010adee>] snd_pcm_open_substream+0x4e/0x90 [snd_pcm]
> > > [   91.514885]  [<ffffffffa010ece9>] snd_pcm_open+0x199/0x450 [snd_pcm]
> > > [   91.514885]  [<ffffffff81081cfd>] ? trace_hardirqs_on+0xd/0x10
> > > [   91.514885]  [<ffffffff810434f0>] ? default_wake_function+0x0/0x20
> > > [   91.514885]  [<ffffffff814b965e>] ? mutex_unlock+0xe/0x10
> > > [   91.514885]  [<ffffffffa010efd4>] snd_pcm_capture_open+0x34/0x40 [snd_pcm]
> > > [   91.514885]  [<ffffffffa00c5778>] snd_open+0x198/0x4e0 [snd]
> > > [   91.514885]  [<ffffffff8112384d>] chrdev_open+0x17d/0x320
> > > [   91.514885]  [<ffffffff8111d358>] __dentry_open+0x1a8/0x400
> > > [   91.514885]  [<ffffffff811236d0>] ? chrdev_open+0x0/0x320
> > > [   91.514885]  [<ffffffff8111d6b4>] nameidata_to_filp+0x54/0x70
> > > [   91.514885]  [<ffffffff8112e7f1>] do_filp_open+0x841/0xc00
> > > [   91.514885]  [<ffffffff814bf981>] ? sub_preempt_count+0x51/0x60
> > > [   91.514885]  [<ffffffff814bbb7c>] ? _raw_spin_unlock+0x5c/0x70
> > > [   91.514885]  [<ffffffff8111e954>] do_sys_open+0xa4/0x180
> > > [   91.514885]  [<ffffffff8111ea70>] sys_open+0x20/0x30
> > > [   91.514885]  [<ffffffff81002adb>] system_call_fastpath+0x16/0x1b
> > > [   92.643423] hda-intel: IRQ timing workaround is activated for card #0. Suggest a bigger bdl_pos_adj.
> > 
> > It looks rather a bug of em28xx driver.  Changing dev->lock with an
> > individual one that is only for audio instance should fix the
> > problem.
> 
> And, I believe this is no regression but a long-standing problem.
> It hits just occasionally by an app like pulseauiod which loves
> tight races.

I guess it depends on how you define a regression.  From my POV it worked
in all three cases on .32, its failing in .33-rc and in one case is oppsing.  In
my books thats a regression.  There may have been races in .32 but they
did not trigger lockdep and never oppsed.

In any case, the real question is how do we fix the problem?

Ed

  reply	other threads:[~2010-02-15 22:25 UTC|newest]

Thread overview: 21+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2010-02-12 19:49 Linux 2.6.33-rc8 Linus Torvalds
2010-02-12 20:11 ` Thomas Backlund
2010-02-12 20:26   ` Paul Rolland
2010-02-12 20:39     ` Thomas Backlund
2010-02-12 22:24 ` Stephen Rothwell
2010-02-13  0:31   ` Justin P. Mattock
2010-02-13  9:16   ` Geert Uytterhoeven
2010-02-13 12:43     ` Stephen Rothwell
2010-02-13 17:17 ` [LOCKDEP] 33-rc8 Running aplay with pulse as the default Ed Tomlinson
2010-02-13 19:18   ` Ed Tomlinson
2010-02-15 19:20   ` Takashi Iwai
2010-02-15 19:21     ` Takashi Iwai
2010-02-15 22:24       ` Ed Tomlinson [this message]
2010-02-15 22:35         ` Takashi Iwai
2010-02-15 23:21           ` Takashi Iwai
2010-02-16 13:19             ` Ed Tomlinson
2010-02-16 13:37               ` Takashi Iwai
2010-02-17 13:16                 ` Ed Tomlinson
2010-02-17 14:29                   ` Takashi Iwai
2010-02-18 12:25                     ` Ed Tomlinson
2010-02-18 13:21                       ` Takashi Iwai

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=201002151724.54807.edt@aei.ca \
    --to=edt@aei.ca \
    --cc=alsa-devel@alsa-project.org \
    --cc=linux-kernel@vger.kernel.org \
    --cc=rjw@sisk.pl \
    --cc=tiwai@suse.de \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox