Maybe not related to rt10, but still can't build it, ".config" attached:
net/netfilter/nfnetlink_queue.c: In function 'instance_create':
net/netfilter/nfnetlink_queue.c:152: error: syntax error before '{'
token
net/netfilter/nfnetlink_queue.c:136: error: label 'out_unlock' used but
not defined
net/netfilter/nfnetlink_queue.c:152: warning: control reaches end of
non-void function
net/netfilter/nfnetlink_queue.c: At top level:
net/netfilter/nfnetlink_queue.c:158: error: syntax error before '&'
token
net/netfilter/nfnetlink_queue.c:161: warning: type defaults to 'int' in
declaration of 'local_bh_enable'
net/netfilter/nfnetlink_queue.c:161: warning: function declaration isn't
a prototype
net/netfilter/nfnetlink_queue.c:161: error: conflicting types for
'local_bh_enable'
include/linux/interrupt.h:105: error: previous declaration of
'local_bh_enable' was here
net/netfilter/nfnetlink_queue.c:161: warning: data definition has no
type or storage class
net/netfilter/nfnetlink_queue.c:161: error: syntax error before 'void'
net/netfilter/nfnetlink_queue.c:170: warning: type defaults to 'int' in
declaration of 'local_bh_enable'
net/netfilter/nfnetlink_queue.c:170: warning: function declaration isn't
a prototype
net/netfilter/nfnetlink_queue.c:170: error: conflicting types for
'local_bh_enable'
include/linux/interrupt.h:105: error: previous declaration of
'local_bh_enable' was here
net/netfilter/nfnetlink_queue.c:170: warning: data definition has no
type or storage class
net/netfilter/nfnetlink_queue.c:170: error: syntax error before 'void'
make[2]: *** [net/netfilter/nfnetlink_queue.o] Error 1
make[1]: *** [net/netfilter] Error 2
make: *** [net] Error 2
-- Fernando
* Fernando Lopez-Lezcano <[email protected]> wrote:
> Maybe not related to rt10, but still can't build it, ".config"
> attached:
ok, i fixed this in -rt11, does it build for you now?
Ingo
On Fri, 2005-10-07 at 13:41 +0200, Ingo Molnar wrote:
> * Fernando Lopez-Lezcano <[email protected]> wrote:
>
> > Maybe not related to rt10, but still can't build it, ".config"
> > attached:
>
> ok, i fixed this in -rt11, does it build for you now?
rt12 bombs here on the smp/i686 compile (smp config attached):
kernel/ktimers.c: In function 'migrate_ktimers':
kernel/ktimers.c:953: error: syntax error before 'do'
kernel/ktimers.c: At top level:
kernel/ktimers.c:953: error: syntax error before 'while'
make[1]: *** [kernel/ktimers.o] Error 1
make: *** [kernel] Error 2
-- Fernando
* Fernando Lopez-Lezcano <[email protected]> wrote:
> On Fri, 2005-10-07 at 13:41 +0200, Ingo Molnar wrote:
> > * Fernando Lopez-Lezcano <[email protected]> wrote:
> >
> > > Maybe not related to rt10, but still can't build it, ".config"
> > > attached:
> >
> > ok, i fixed this in -rt11, does it build for you now?
>
> rt12 bombs here on the smp/i686 compile (smp config attached):
ok - i have fixed these and have released -rt13 - does it work for you?
Ingo
On Fri, 2005-10-07 at 23:16 +0200, Ingo Molnar wrote:
> * Fernando Lopez-Lezcano <[email protected]> wrote:
>
> > On Fri, 2005-10-07 at 13:41 +0200, Ingo Molnar wrote:
> > > * Fernando Lopez-Lezcano <[email protected]> wrote:
> > >
> > > > Maybe not related to rt10, but still can't build it, ".config"
> > > > attached:
> > >
> > > ok, i fixed this in -rt11, does it build for you now?
> >
> > rt12 bombs here on the smp/i686 compile (smp config attached):
>
> ok - i have fixed these and have released -rt13 - does it work for you?
The kernel finally builds but I'm getting these on a depmod -a, will
check further:
WARNING: /lib/modules/2.6.13-0.7.rdt.rhfc4.ccrma/kernel/drivers/input/gameport/gameport.ko needs unknown symbol local_irq_restore_nort
WARNING: /lib/modules/2.6.13-0.7.rdt.rhfc4.ccrma/kernel/drivers/input/gameport/gameport.ko needs unknown symbol local_irq_save_nort
-- Fernando
* Fernando Lopez-Lezcano <[email protected]> wrote:
> On Fri, 2005-10-07 at 23:16 +0200, Ingo Molnar wrote:
> > * Fernando Lopez-Lezcano <[email protected]> wrote:
> >
> > > On Fri, 2005-10-07 at 13:41 +0200, Ingo Molnar wrote:
> > > > * Fernando Lopez-Lezcano <[email protected]> wrote:
> > > >
> > > > > Maybe not related to rt10, but still can't build it, ".config"
> > > > > attached:
> > > >
> > > > ok, i fixed this in -rt11, does it build for you now?
> > >
> > > rt12 bombs here on the smp/i686 compile (smp config attached):
> >
> > ok - i have fixed these and have released -rt13 - does it work for you?
>
> The kernel finally builds but I'm getting these on a depmod -a, will
> check further:
>
> WARNING: /lib/modules/2.6.13-0.7.rdt.rhfc4.ccrma/kernel/drivers/input/gameport/gameport.ko needs unknown symbol local_irq_restore_nort
> WARNING: /lib/modules/2.6.13-0.7.rdt.rhfc4.ccrma/kernel/drivers/input/gameport/gameport.ko needs unknown symbol local_irq_save_nort
should go away if you add this to drivers/input/gameport.c:
#include <linux/interrupt.h>
Ingo
On Sat, 2005-10-08 at 01:11 +0200, Ingo Molnar wrote:
> * Fernando Lopez-Lezcano <[email protected]> wrote:
>
> > On Fri, 2005-10-07 at 23:16 +0200, Ingo Molnar wrote:
> > > * Fernando Lopez-Lezcano <[email protected]> wrote:
> > >
> > > > On Fri, 2005-10-07 at 13:41 +0200, Ingo Molnar wrote:
> > > > > * Fernando Lopez-Lezcano <[email protected]> wrote:
> > > > >
> > > > > > Maybe not related to rt10, but still can't build it, ".config"
> > > > > > attached:
> > > > >
> > > > > ok, i fixed this in -rt11, does it build for you now?
> > > >
> > > > rt12 bombs here on the smp/i686 compile (smp config attached):
> > >
> > > ok - i have fixed these and have released -rt13 - does it work for you?
> >
> > The kernel finally builds but I'm getting these on a depmod -a, will
> > check further:
> >
> > WARNING: /lib/modules/2.6.13-0.7.rdt.rhfc4.ccrma/kernel/drivers/input/gameport/gameport.ko needs unknown symbol local_irq_restore_nort
> > WARNING: /lib/modules/2.6.13-0.7.rdt.rhfc4.ccrma/kernel/drivers/input/gameport/gameport.ko needs unknown symbol local_irq_save_nort
>
> should go away if you add this to drivers/input/gameport.c:
>
> #include <linux/interrupt.h>
Thanks, that got it going.
The problems I was seeing with Jack are still there but there's more
weird behavior.
X will blank the screen randomly, sometimes it takes a while till I can
get it back, sometimes it is a blink, sometimes longer, and typing in a
terminal under X will repeat keys (that does not happen in a text
console terminal). This is on Fedora Core 4 with the latest updates
installed.
This appears to be triggered from Freqtweak (a Jack application):
Oct 8 18:48:00 cmn3 kernel: freqtweak:4705 userspace BUG: scheduling in
user-atomic context!
Oct 8 18:48:00 cmn3 kernel: [<c037c05b>] schedule+0xeb/0x100 (8)
Oct 8 18:48:00 cmn3 kernel: [<c037d745>] rwsem_down_read_failed
+0xa5/0x1c0 (28)
Oct 8 18:48:00 cmn3 kernel: [<c01467ee>] .text.lock.futex+0xa9/0x2db
(52)
Oct 8 18:48:00 cmn3 kernel: [<c0130c46>] try_to_del_timer_sync
+0x46/0x50 (32)
Oct 8 18:48:00 cmn3 kernel: [<c0130c71>] del_timer_sync+0x21/0x30 (16)
Oct 8 18:48:00 cmn3 kernel: [<c0121330>] default_wake_function
+0x0/0x20 (32)
Oct 8 18:48:00 cmn3 kernel: [<c0151b5c>] audit_syscall_exit+0x4c/0x400
(12)
Oct 8 18:48:00 cmn3 kernel: [<c0146589>] do_futex+0x69/0xf0 (24)
Oct 8 18:48:00 cmn3 kernel: [<c0146674>] sys_futex+0x64/0x120 (24)
Oct 8 18:48:00 cmn3 kernel: [<c0103471>] syscall_call+0x7/0xb (60)
-- Fernando
* Fernando Lopez-Lezcano <[email protected]> wrote:
> This appears to be triggered from Freqtweak (a Jack application):
> Oct 8 18:48:00 cmn3 kernel: freqtweak:4705 userspace BUG: scheduling in
> user-atomic context!
> Oct 8 18:48:00 cmn3 kernel: [<c037c05b>] schedule+0xeb/0x100 (8)
> Oct 8 18:48:00 cmn3 kernel: [<c037d745>] rwsem_down_read_failed
> +0xa5/0x1c0 (28)
> Oct 8 18:48:00 cmn3 kernel: [<c01467ee>] .text.lock.futex+0xa9/0x2db
> (52)
> Oct 8 18:48:00 cmn3 kernel: [<c0130c46>] try_to_del_timer_sync
> +0x46/0x50 (32)
> Oct 8 18:48:00 cmn3 kernel: [<c0130c71>] del_timer_sync+0x21/0x30 (16)
> Oct 8 18:48:00 cmn3 kernel: [<c0121330>] default_wake_function
> +0x0/0x20 (32)
> Oct 8 18:48:00 cmn3 kernel: [<c0151b5c>] audit_syscall_exit+0x4c/0x400
> (12)
> Oct 8 18:48:00 cmn3 kernel: [<c0146589>] do_futex+0x69/0xf0 (24)
> Oct 8 18:48:00 cmn3 kernel: [<c0146674>] sys_futex+0x64/0x120 (24)
> Oct 8 18:48:00 cmn3 kernel: [<c0103471>] syscall_call+0x7/0xb (60)
could you enable CONFIG_DEBUG_PREEMPT and send me the same assert (which
will hopefully include a critical section list too).
Ingo
On Sun, 2005-10-09 at 06:33 +0200, Ingo Molnar wrote:
> * Fernando Lopez-Lezcano <[email protected]> wrote:
>
> > This appears to be triggered from Freqtweak (a Jack application):
> > Oct 8 18:48:00 cmn3 kernel: freqtweak:4705 userspace BUG: scheduling in
> > user-atomic context!
> > Oct 8 18:48:00 cmn3 kernel: [<c037c05b>] schedule+0xeb/0x100 (8)
> > Oct 8 18:48:00 cmn3 kernel: [<c037d745>] rwsem_down_read_failed
> > +0xa5/0x1c0 (28)
> > Oct 8 18:48:00 cmn3 kernel: [<c01467ee>] .text.lock.futex+0xa9/0x2db
> > (52)
> > Oct 8 18:48:00 cmn3 kernel: [<c0130c46>] try_to_del_timer_sync
> > +0x46/0x50 (32)
> > Oct 8 18:48:00 cmn3 kernel: [<c0130c71>] del_timer_sync+0x21/0x30 (16)
> > Oct 8 18:48:00 cmn3 kernel: [<c0121330>] default_wake_function
> > +0x0/0x20 (32)
> > Oct 8 18:48:00 cmn3 kernel: [<c0151b5c>] audit_syscall_exit+0x4c/0x400
> > (12)
> > Oct 8 18:48:00 cmn3 kernel: [<c0146589>] do_futex+0x69/0xf0 (24)
> > Oct 8 18:48:00 cmn3 kernel: [<c0146674>] sys_futex+0x64/0x120 (24)
> > Oct 8 18:48:00 cmn3 kernel: [<c0103471>] syscall_call+0x7/0xb (60)
>
> could you enable CONFIG_DEBUG_PREEMPT and send me the same assert (which
> will hopefully include a critical section list too).
I will try to do that tomorrow.
I forgot to mention, all this is with the SMP kernel running on a dual
core Athlon, PREEMPT_DESKTOP and HZ=1000.
The symptoms would seem to indicate some basic problem with timing and
what is reported to userspace (ie: wrong warnings about delayed
interrupts in Jack - I hear no audible problems and the time difference
reported by Jack keeps growing no matter what I do, seems to only be
realted to the time the kernel has been up, key repeat on X speeds up,
apparently the screensaver kicks in randomly, etc).
-- Fernando
On Sun, 2005-10-09 at 11:38 -0700, Fernando Lopez-Lezcano wrote:
> On Sun, 2005-10-09 at 06:33 +0200, Ingo Molnar wrote:
> > * Fernando Lopez-Lezcano <[email protected]> wrote:
> >
> > > This appears to be triggered from Freqtweak (a Jack application):
> > > Oct 8 18:48:00 cmn3 kernel: freqtweak:4705 userspace BUG: scheduling in
> > > user-atomic context!
> > > Oct 8 18:48:00 cmn3 kernel: [<c037c05b>] schedule+0xeb/0x100 (8)
> > > Oct 8 18:48:00 cmn3 kernel: [<c037d745>] rwsem_down_read_failed
> > > +0xa5/0x1c0 (28)
> > > Oct 8 18:48:00 cmn3 kernel: [<c01467ee>] .text.lock.futex+0xa9/0x2db
> > > (52)
> > > Oct 8 18:48:00 cmn3 kernel: [<c0130c46>] try_to_del_timer_sync
> > > +0x46/0x50 (32)
> > > Oct 8 18:48:00 cmn3 kernel: [<c0130c71>] del_timer_sync+0x21/0x30 (16)
> > > Oct 8 18:48:00 cmn3 kernel: [<c0121330>] default_wake_function
> > > +0x0/0x20 (32)
> > > Oct 8 18:48:00 cmn3 kernel: [<c0151b5c>] audit_syscall_exit+0x4c/0x400
> > > (12)
> > > Oct 8 18:48:00 cmn3 kernel: [<c0146589>] do_futex+0x69/0xf0 (24)
> > > Oct 8 18:48:00 cmn3 kernel: [<c0146674>] sys_futex+0x64/0x120 (24)
> > > Oct 8 18:48:00 cmn3 kernel: [<c0103471>] syscall_call+0x7/0xb (60)
> >
> > could you enable CONFIG_DEBUG_PREEMPT and send me the same assert (which
> > will hopefully include a critical section list too).
>
> I will try to do that tomorrow.
>
> I forgot to mention, all this is with the SMP kernel running on a dual
> core Athlon, PREEMPT_DESKTOP and HZ=1000.
I did not get the same one to repeat, got this instead (see below for
more latency traces):
[<c0104703>] dump_stack+0x23/0x30 (20)
[<c03b2ff5>] schedule+0x105/0x130 (28)
[<c03b31d4>] wait_for_completion+0xa4/0xe0 (48)
[<c0193579>] coredump_wait+0xa9/0xe0 (52)
[<c01936cc>] do_coredump+0x11c/0x2ac (120)
[<c01382c1>] get_signal_to_deliver+0x321/0x340 (44)
[<c010349c>] do_signal+0x5c/0x130 (188)
[<c01035a0>] do_notify_resume+0x30/0x40 (12)
[<c01037ac>] work_notifysig+0x13/0x1b (-8116)
---------------------------
| preempt count: 00000000 ]
| 0-level deep critical section nesting:
----------------------------------------
( softirq-timer/0-4 |#0): new 6 us maximum-latency wakeup.
( softirq-timer/0-4 |#0): new 11 us maximum-latency wakeup.
( gnome-terminal-4657 |#1): new 519 us maximum-latency wakeup.
( kjournald-444 |#1): new 2295 us maximum-latency wakeup.
( softirq-timer/1-13 |#1): new 3014 us maximum-latency wakeup.
( X-4463 |#1): new 7458 us maximum-latency wakeup.
( X-4463 |#1): new 18489 us maximum-latency wakeup.
( softirq-timer/1-13 |#1): new 36000 us maximum-latency wakeup.
These are the RT processes and their priorities, upping the
softirq-timer processes priority does not seem to make any difference:
12 41 1 [softirq-high/1]
13 41 1 [softirq-timer/1]
14 41 1 [softirq-net-tx/]
15 41 1 [softirq-net-rx/]
16 41 1 [softirq-scsi/1]
17 41 1 [softirq-tasklet]
20 41 1 [events/0]
21 41 1 [events/1]
3 41 1 [softirq-high/0]
4 41 1 [softirq-timer/0]
5 41 1 [softirq-net-tx/]
6 41 1 [softirq-net-rx/]
7 41 1 [softirq-scsi/0]
8 41 1 [softirq-tasklet]
4495 74 34 [IRQ 225]
4022 75 35 [IRQ 7]
3997 76 36 [IRQ 3]
3996 77 37 [IRQ 4]
962 81 41 [IRQ 193]
936 82 42 [IRQ 6]
414 84 44 [IRQ 177]
352 86 46 [IRQ 14]
27 89 49 [IRQ 9]
319 89 49 [IRQ 12]
384 90 50 [IRQ 1]
1222 99 59 [IRQ 217]
427 100 60 [IRQ 185]
1062 109 69 [IRQ 209]
1049 110 70 [IRQ 201]
301 120 80 [IRQ 8]
11 139 99 [migration/1]
18 139 99 [watchdog/1]
2 139 99 [migration/0]
9 139 99 [watchdog/0]
# cat /proc/interrupts
CPU0 CPU1
0: 6882 1191382 IO-APIC-edge [........N/ 0] timer
1: 6 1705 IO-APIC-edge [........./ 0] i8042
7: 2 1 IO-APIC-edge [..P....../ 0] parport0
8: 0 1 IO-APIC-edge [........N/ 0] rtc
9: 0 0 IO-APIC-level [........./ 0] acpi
12: 581 68040 IO-APIC-edge [........./ 1] i8042
14: 84 10711 IO-APIC-edge [........./ 0] ide0
177: 0 0 IO-APIC-level [........./ 0] libata
185: 107 25623 IO-APIC-level [........./ 0] libata,
ehci_hcd:usb1
193: 6238 484611 IO-APIC-level [........./ 0] SysKonnect
SK-98xx
201: 5159 773150 IO-APIC-level [........N/ 0] ICE1712,
ohci1394
209: 0 0 IO-APIC-level [........N/ 0] NVidia CK8S,
ohci_hcd:usb2
217: 0 0 IO-APIC-level [........./ 0]
ohci_hcd:usb3
225: 506 67236 IO-APIC-level [........./ 1]
radeon@pci:0000:01:00.0
NMI: 0 0
LOC: 1197825 1197903
ERR: 1
MIS: 0
-- Fernando
----
preemption latency trace v1.1.5 on 2.6.13-0.7.rdtd.rhfc4.ccrmasmp
--------------------------------------------------------------------
latency: 40968 us, #20/20, CPU#1 | (M:preempt VP:0, KP:0, SP:1 HP:1
#P:2)
-----------------
| task: jackd-4735 (uid:743 nice:0 policy:1 rt_prio:62)
-----------------
_------=> CPU#
/ _-----=> irqs-off
| / _----=> need-resched
|| / _---=> hardirq/softirq
||| / _--=> preempt-depth
|||| /
||||| delay
cmd pid ||||| time | caller
\ / ||||| \ | /
ardour-4871 1.... 0us : _raw_spin_lock_irqsave (remove_wait_queue)
ardour-4871 1Dn.1 0us : _raw_spin_unlock_irqrestore
(remove_wait_queue)
ardour-4871 1Dn.. 1us : smp_reschedule_interrupt (c03b5540 0 0)
ardour-4871 1Dn.. 2us : preempt_schedule_irq (need_resched)
ardour-4871 1Dn.. 2us : __schedule (preempt_schedule_irq)
ardour-4871 1Dn.. 3us : profile_hit (__schedule)
ardour-4871 1Dn.1 3us : sched_clock (__schedule)
ardour-4871 1Dn.1 3us : check_tsc_unstable (sched_clock)
ardour-4871 1Dn.1 4us : tsc_read_c3_time (sched_clock)
ardour-4871 1Dn.1 4us : _raw_spin_lock_irq (__schedule)
ardour-4871 1Dn.1 5us : _raw_spin_lock_irqsave
(_raw_spin_lock_irq)
ardour-4871 1Dn.2 5us : dependent_sleeper (__schedule)
<...>-4735 1D..2 6us : __switch_to (__schedule)
<...>-4735 1D..2 6us : __schedule <ardour-4871> (73 25)
<...>-4735 1D..2 6us : _raw_spin_unlock_irq (__schedule)
<...>-4735 1...1 7us : trace_stop_sched_switched (__schedule)
<...>-4735 1D..1 7us : _raw_spin_lock (trace_stop_sched_switched)
<...>-4735 1D..2 7us : trace_stop_sched_switched <<...>-4735> (25
1)
<...>-4735 1D..2 7us : trace_stop_sched_switched (__schedule)
vim:ft=help
----
preemption latency trace v1.1.5 on 2.6.13-0.7.rdtd.rhfc4.ccrmasmp
--------------------------------------------------------------------
latency: 1008 us, #21/21, CPU#0 | (M:preempt VP:0, KP:0, SP:1 HP:1
#P:2)
-----------------
| task: softirq-timer/0-4 (uid:0 nice:0 policy:1 rt_prio:1)
-----------------
_------=> CPU#
/ _-----=> irqs-off
| / _----=> need-resched
|| / _---=> hardirq/softirq
||| / _--=> preempt-depth
|||| /
||||| delay
cmd pid ||||| time | caller
\ / ||||| \ | /
hydrogen-4887 0.n.1 0us : trace_stop_sched_switched (__schedule)
hydrogen-4887 0Dn.1 0us : _raw_spin_lock (trace_stop_sched_switched)
hydrogen-4887 0Dn.2 0us : trace_stop_sched_switched <<...>-4> (62
74)
hydrogen-4887 0Dn.2 0us : _raw_spin_unlock
(trace_stop_sched_switched)
hydrogen-4887 0Dn.1 0us : preempt_schedule (_raw_spin_unlock)
hydrogen-4887 0.n.. 1us : __schedule (schedule)
hydrogen-4887 0.n.. 1us : profile_hit (__schedule)
hydrogen-4887 0.n.1 1us : sched_clock (__schedule)
hydrogen-4887 0.n.1 2us : check_tsc_unstable (sched_clock)
hydrogen-4887 0.n.1 2us : tsc_read_c3_time (sched_clock)
hydrogen-4887 0.n.1 2us : _raw_spin_lock_irq (__schedule)
hydrogen-4887 0.n.1 2us : _raw_spin_lock_irqsave
(_raw_spin_lock_irq)
hydrogen-4887 0Dn.2 3us : dependent_sleeper (__schedule)
<...>-4 0D..2 3us : __switch_to (__schedule)
<...>-4 0D..2 3us : __schedule <hydrogen-4887> (74 62)
<...>-4 0D..2 4us : _raw_spin_unlock_irq (__schedule)
<...>-4 0...1 4us : trace_stop_sched_switched (__schedule)
<...>-4 0D..1 4us : _raw_spin_lock (trace_stop_sched_switched)
<...>-4 0D..2 4us : trace_stop_sched_switched <<...>-4> (62 0)
<...>-4 0D..2 5us : trace_stop_sched_switched (__schedule)
vim:ft=help
----
preemption latency trace v1.1.5 on 2.6.13-0.7.rdtd.rhfc4.ccrmasmp
--------------------------------------------------------------------
latency: 1978 us, #18/18, CPU#1 | (M:preempt VP:0, KP:0, SP:1 HP:1
#P:2)
-----------------
| task: softirq-timer/1-13 (uid:0 nice:0 policy:1 rt_prio:1)
-----------------
_------=> CPU#
/ _-----=> irqs-off
| / _----=> need-resched
|| / _---=> hardirq/softirq
||| / _--=> preempt-depth
|||| /
||||| delay
cmd pid ||||| time | caller
\ / ||||| \ | /
multiloa-4679 1.n.1 0us : _raw_spin_unlock (audit_syscall_exit)
multiloa-4679 1.n.. 0us : preempt_schedule (_raw_spin_unlock)
multiloa-4679 1Dn.. 0us : __schedule (preempt_schedule)
multiloa-4679 1Dn.. 0us : profile_hit (__schedule)
multiloa-4679 1Dn.1 0us : sched_clock (__schedule)
multiloa-4679 1Dn.1 1us : check_tsc_unstable (sched_clock)
multiloa-4679 1Dn.1 1us : tsc_read_c3_time (sched_clock)
multiloa-4679 1Dn.1 1us : _raw_spin_lock_irq (__schedule)
multiloa-4679 1Dn.1 1us : _raw_spin_lock_irqsave
(_raw_spin_lock_irq)
multiloa-4679 1Dn.2 1us : dependent_sleeper (__schedule)
<...>-13 1D..2 2us : __switch_to (__schedule)
<...>-13 1D..2 2us : __schedule <multiloa-4679> (73 62)
<...>-13 1D..2 2us : _raw_spin_unlock_irq (__schedule)
<...>-13 1...1 2us : trace_stop_sched_switched (__schedule)
<...>-13 1D..1 2us : _raw_spin_lock (trace_stop_sched_switched)
<...>-13 1D..2 3us : trace_stop_sched_switched <<...>-13> (62
1)
<...>-13 1D..2 3us : trace_stop_sched_switched (__schedule)
vim:ft=help
----
preemption latency trace v1.1.5 on 2.6.13-0.7.rdtd.rhfc4.ccrmasmp
--------------------------------------------------------------------
latency: 741 us, #21/21, CPU#0 | (M:preempt VP:0, KP:0, SP:1 HP:1 #P:2)
-----------------
| task: IRQ 225-4495 (uid:0 nice:-5 policy:1 rt_prio:34)
-----------------
_------=> CPU#
/ _-----=> irqs-off
| / _----=> need-resched
|| / _---=> hardirq/softirq
||| / _--=> preempt-depth
|||| /
||||| delay
cmd pid ||||| time | caller
\ / ||||| \ | /
X-4463 0.... 0us : poll_freewait (do_select)
X-4463 0.... 0us : __might_sleep (sys_select)
X-4463 0.n.. 0us : __copy_to_user_ll (sys_select)
X-4463 0Dn.. 1us : smp_reschedule_interrupt (c021aae4 0 0)
X-4463 0Dn.. 1us : preempt_schedule_irq (need_resched)
X-4463 0Dn.. 1us : __schedule (preempt_schedule_irq)
X-4463 0Dn.. 1us : profile_hit (__schedule)
X-4463 0Dn.1 1us : sched_clock (__schedule)
X-4463 0Dn.1 2us : check_tsc_unstable (sched_clock)
X-4463 0Dn.1 2us : tsc_read_c3_time (sched_clock)
X-4463 0Dn.1 2us : _raw_spin_lock_irq (__schedule)
X-4463 0Dn.1 2us : _raw_spin_lock_irqsave
(_raw_spin_lock_irq)
X-4463 0Dn.2 2us : dependent_sleeper (__schedule)
<...>-4495 0D..2 3us : __switch_to (__schedule)
<...>-4495 0D..2 3us : __schedule <X-4463> (74 41)
<...>-4495 0D..2 3us : _raw_spin_unlock_irq (__schedule)
<...>-4495 0...1 3us : trace_stop_sched_switched (__schedule)
<...>-4495 0D..1 4us : _raw_spin_lock (trace_stop_sched_switched)
<...>-4495 0D..2 4us : trace_stop_sched_switched <<...>-4495> (41
0)
<...>-4495 0D..2 4us : trace_stop_sched_switched (__schedule)
vim:ft=help
----
preemption latency trace v1.1.5 on 2.6.13-0.7.rdtd.rhfc4.ccrmasmp
--------------------------------------------------------------------
latency: 741 us, #21/21, CPU#0 | (M:preempt VP:0, KP:0, SP:1 HP:1 #P:2)
-----------------
| task: IRQ 225-4495 (uid:0 nice:-5 policy:1 rt_prio:34)
-----------------
_------=> CPU#
/ _-----=> irqs-off
| / _----=> need-resched
|| / _---=> hardirq/softirq
||| / _--=> preempt-depth
|||| /
||||| delay
cmd pid ||||| time | caller
\ / ||||| \ | /
X-4463 0.... 0us : poll_freewait (do_select)
X-4463 0.... 0us : __might_sleep (sys_select)
X-4463 0.n.. 0us : __copy_to_user_ll (sys_select)
X-4463 0Dn.. 1us : smp_reschedule_interrupt (c021aae4 0 0)
X-4463 0Dn.. 1us : preempt_schedule_irq (need_resched)
X-4463 0Dn.. 1us : __schedule (preempt_schedule_irq)
X-4463 0Dn.. 1us : profile_hit (__schedule)
X-4463 0Dn.1 1us : sched_clock (__schedule)
X-4463 0Dn.1 2us : check_tsc_unstable (sched_clock)
X-4463 0Dn.1 2us : tsc_read_c3_time (sched_clock)
X-4463 0Dn.1 2us : _raw_spin_lock_irq (__schedule)
X-4463 0Dn.1 2us : _raw_spin_lock_irqsave
(_raw_spin_lock_irq)
X-4463 0Dn.2 2us : dependent_sleeper (__schedule)
<...>-4495 0D..2 3us : __switch_to (__schedule)
<...>-4495 0D..2 3us : __schedule <X-4463> (74 41)
<...>-4495 0D..2 3us : _raw_spin_unlock_irq (__schedule)
<...>-4495 0...1 3us : trace_stop_sched_switched (__schedule)
<...>-4495 0D..1 4us : _raw_spin_lock (trace_stop_sched_switched)
<...>-4495 0D..2 4us : trace_stop_sched_switched <<...>-4495> (41
0)
<...>-4495 0D..2 4us : trace_stop_sched_switched (__schedule)
vim:ft=help
----
preemption latency trace v1.1.5 on 2.6.13-0.7.rdtd.rhfc4.ccrmasmp
--------------------------------------------------------------------
latency: 1004 us, #18/18, CPU#0 | (M:preempt VP:0, KP:0, SP:1 HP:1
#P:2)
-----------------
| task: softirq-timer/0-4 (uid:0 nice:0 policy:1 rt_prio:1)
-----------------
_------=> CPU#
/ _-----=> irqs-off
| / _----=> need-resched
|| / _---=> hardirq/softirq
||| / _--=> preempt-depth
|||| /
||||| delay
cmd pid ||||| time | caller
\ / ||||| \ | /
multiloa-4679 0.n.1 0us : _raw_spin_unlock (new_inode)
multiloa-4679 0.n.. 0us : preempt_schedule (_raw_spin_unlock)
multiloa-4679 0Dn.. 0us : __schedule (preempt_schedule)
multiloa-4679 0Dn.. 0us : profile_hit (__schedule)
multiloa-4679 0Dn.1 0us : sched_clock (__schedule)
multiloa-4679 0Dn.1 0us : check_tsc_unstable (sched_clock)
multiloa-4679 0Dn.1 0us : tsc_read_c3_time (sched_clock)
multiloa-4679 0Dn.1 0us : _raw_spin_lock_irq (__schedule)
multiloa-4679 0Dn.1 1us : _raw_spin_lock_irqsave
(_raw_spin_lock_irq)
multiloa-4679 0Dn.2 1us : dependent_sleeper (__schedule)
<...>-4 0D..2 2us : __switch_to (__schedule)
<...>-4 0D..2 2us : __schedule <multiloa-4679> (73 62)
<...>-4 0D..2 2us : _raw_spin_unlock_irq (__schedule)
<...>-4 0...1 2us : trace_stop_sched_switched (__schedule)
<...>-4 0D..1 2us : _raw_spin_lock (trace_stop_sched_switched)
<...>-4 0D..2 2us : trace_stop_sched_switched <<...>-4> (62 0)
<...>-4 0D..2 3us : trace_stop_sched_switched (__schedule)
vim:ft=help
----
preemption latency trace v1.1.5 on 2.6.13-0.7.rdtd.rhfc4.ccrmasmp
--------------------------------------------------------------------
latency: 1657 us, #21/21, CPU#0 | (M:preempt VP:0, KP:0, SP:1 HP:1
#P:2)
-----------------
| task: IRQ 12-319 (uid:0 nice:-5 policy:1 rt_prio:49)
-----------------
_------=> CPU#
/ _-----=> irqs-off
| / _----=> need-resched
|| / _---=> hardirq/softirq
||| / _--=> preempt-depth
|||| /
||||| delay
cmd pid ||||| time | caller
\ / ||||| \ | /
X-4463 0.... 0us : avc_audit (avc_has_perm)
X-4463 0.n.. 0us : unix_stream_recvmsg (sock_aio_read)
X-4463 0.n.. 0us : __might_sleep (unix_stream_recvmsg)
X-4463 0Dn.. 1us : smp_reschedule_interrupt (c0149d7f 0 0)
X-4463 0Dn.. 1us : preempt_schedule_irq (need_resched)
X-4463 0Dn.. 1us : __schedule (preempt_schedule_irq)
X-4463 0Dn.. 1us : profile_hit (__schedule)
X-4463 0Dn.1 1us : sched_clock (__schedule)
X-4463 0Dn.1 1us : check_tsc_unstable (sched_clock)
X-4463 0Dn.1 2us : tsc_read_c3_time (sched_clock)
X-4463 0Dn.1 2us : _raw_spin_lock_irq (__schedule)
X-4463 0Dn.1 2us : _raw_spin_lock_irqsave
(_raw_spin_lock_irq)
X-4463 0Dn.2 2us : dependent_sleeper (__schedule)
<...>-319 0D..2 3us : __switch_to (__schedule)
<...>-319 0D..2 3us : __schedule <X-4463> (74 32)
<...>-319 0D..2 3us : _raw_spin_unlock_irq (__schedule)
<...>-319 0...1 3us : trace_stop_sched_switched (__schedule)
<...>-319 0D..1 3us : _raw_spin_lock (trace_stop_sched_switched)
<...>-319 0D..2 4us : trace_stop_sched_switched <<...>-319> (32
0)
<...>-319 0D..2 4us : trace_stop_sched_switched (__schedule)
vim:ft=help
----
preemption latency trace v1.1.5 on 2.6.13-0.7.rdtd.rhfc4.ccrmasmp
--------------------------------------------------------------------
latency: 2140 us, #21/21, CPU#0 | (M:preempt VP:0, KP:0, SP:1 HP:1
#P:2)
-----------------
| task: IRQ 12-319 (uid:0 nice:-5 policy:1 rt_prio:49)
-----------------
_------=> CPU#
/ _-----=> irqs-off
| / _----=> need-resched
|| / _---=> hardirq/softirq
||| / _--=> preempt-depth
|||| /
||||| delay
cmd pid ||||| time | caller
\ / ||||| \ | /
X-4463 0D..1 0us : _raw_spin_unlock_irqrestore
(tty_ldisc_try)
X-4463 0.... 0us : normal_poll (tty_poll)
X-4463 0.n.. 0us : __pollwait (normal_poll)
X-4463 0Dn.. 1us : smp_reschedule_interrupt (c019bf66 0 0)
X-4463 0Dn.. 1us : preempt_schedule_irq (need_resched)
X-4463 0Dn.. 1us : __schedule (preempt_schedule_irq)
X-4463 0Dn.. 1us : profile_hit (__schedule)
X-4463 0Dn.1 1us : sched_clock (__schedule)
X-4463 0Dn.1 1us : check_tsc_unstable (sched_clock)
X-4463 0Dn.1 2us : tsc_read_c3_time (sched_clock)
X-4463 0Dn.1 2us : _raw_spin_lock_irq (__schedule)
X-4463 0Dn.1 2us : _raw_spin_lock_irqsave
(_raw_spin_lock_irq)
X-4463 0Dn.2 2us : dependent_sleeper (__schedule)
<...>-319 0D..2 3us : __switch_to (__schedule)
<...>-319 0D..2 3us : __schedule <X-4463> (74 32)
<...>-319 0D..2 4us : _raw_spin_unlock_irq (__schedule)
<...>-319 0...1 4us : trace_stop_sched_switched (__schedule)
<...>-319 0D..1 4us : _raw_spin_lock (trace_stop_sched_switched)
<...>-319 0D..2 4us : trace_stop_sched_switched <<...>-319> (32
0)
<...>-319 0D..2 5us : trace_stop_sched_switched (__schedule)
vim:ft=help
----