Re: v2.6.21.5-rt19 (sched_getaffinity?)

[Fernando Lopez-Lezcano]

On Tue, 2007-07-17 at 22:12 +0200, Ingo Molnar wrote:
> * Fernando Lopez-Lezcano <nando@xxxxxxxxxxxxxxxxxx> wrote:
> 
> > On Tue, 2007-07-17 at 21:32 +0200, Ingo Molnar wrote:
> > > * Fernando Lopez-Lezcano <nando@xxxxxxxxxxxxxxxxxx> wrote:
> > > 
> > > > I do get flash 9 (I know, not the best example) and tomboy to hang as 
> > > > reported by one of my Planet CCRMA users - flash 9 tested working on 
> > > > stock fedora 7 kernel - and both seem to hang in the same system call:
> > > > 
> > > > sched_getaffinity(3528, 32, <unfinished ...>
> > > > 
> > > > Full output of strace attached for both cases.
> > > 
> > > hm, that's weird. Is it completely unkillable at that time? Could you do 
> > > a few things: enable CONFIG_PROVE_LOCKING (lockdep), and also try to get 
> > > a full task state dump via:
> > > 
> > >   echo t > /proc/sysrq-trigger
> > 
> > Trace attached... the process stays in D state no matter what. 
> 
> hm, seems to be related to:
> 
> Jul 17 12:51:18 localhost kernel: sched-powersa D [f0aaf930] 00000005  6584  3420   3407
> 
> which blocks the cpu-hotplug mutex:
> 
> Jul 17 12:51:18 localhost kernel: Call Trace:
> Jul 17 12:51:18 localhost kernel:  [<c0603f46>] schedule+0xe0/0xfa
> Jul 17 12:51:18 localhost kernel:  [<c0604d0d>] rt_mutex_slowlock+0x164/0x20b
> Jul 17 12:51:18 localhost kernel:  [<c0604a5c>] rt_mutex_lock+0x3c/0x3f
> Jul 17 12:51:18 localhost kernel:  [<c0423bb4>] sched_getaffinity+0x14/0x94
> Jul 17 12:51:18 localhost kernel:  [<c045a647>] __synchronize_sched+0xd/0x5a
> Jul 17 12:51:18 localhost kernel:  [<c0423732>] arch_reinit_sched_domains+0x18/0x33
> Jul 17 12:51:18 localhost kernel:  [<c0423789>] sched_power_savings_store+0x3c/0x49
> Jul 17 12:51:18 localhost kernel:  [<c0552cd4>] sysdev_class_store+0x1e/0x22
> Jul 17 12:51:18 localhost kernel:  [<c04b195b>] sysfs_write_file+0xa3/0xc6
> Jul 17 12:51:18 localhost kernel:  [<c047a64a>] vfs_write+0xa8/0x154
> Jul 17 12:51:18 localhost kernel:  [<c047ac65>] sys_write+0x41/0x67
> Jul 17 12:51:18 localhost kernel:  [<c0404f7c>] syscall_call+0x7/0xb
> 
> and firefox blocks on the same mutex too:
> 
> Jul 17 12:51:18 localhost kernel: firefox-bin   D [efc44670] 00000012  6368  4388      1
> Jul 17 12:51:18 localhost kernel: Call Trace:
> Jul 17 12:51:18 localhost kernel:  [<c0603f46>] schedule+0xe0/0xfa
> Jul 17 12:51:18 localhost kernel:  [<c0604d0d>] rt_mutex_slowlock+0x164/0x20b
> Jul 17 12:51:18 localhost kernel:  [<c0604a5c>] rt_mutex_lock+0x3c/0x3f
> Jul 17 12:51:18 localhost kernel:  [<c0423bb4>] sched_getaffinity+0x14/0x94
> Jul 17 12:51:18 localhost kernel:  [<c0423c53>] sys_sched_getaffinity+0x1f/0x41
> Jul 17 12:51:18 localhost kernel:  [<c0404f7c>] syscall_call+0x7/0xb
> Jul 17 12:51:18 localhost kernel:  [<b7f0f410>] 0xb7f0f410
> 
> does lockdep pinpoint anything?

Lots of stuff, and at the end the lock report for the problem. Hopefully
some of this will help... I have attached the whole bootup sequence as
logged in /var/log/messages. 

-- Fernando

Attachment: trace3.txt.gz
Description: GNU Zip compressed data