Messages in this thread |  | | | Date | Fri, 17 Apr 2009 07:09:42 -0400 (EDT) | | From | Steven Rostedt <> | | Subject | Re: [PATCH 2/2] tracing/events/lockdep: move tracepoints within recursive protection |
| |
On Fri, 17 Apr 2009, Mathieu Desnoyers wrote: > > ---[ end trace 03d889e04bc7a9a7 ]--- > > possible reason: unannotated irqs-on. > > irq event stamp: 12569 > > hardirqs last enabled at (12567): [<ffffffff8026206a>] local_bh_enable+0xaa/0x110 > > hardirqs last disabled at (12569): [<ffffffff80610c76>] int3+0x16/0x40 > > softirqs last enabled at (12566): [<ffffffff80514d2b>] lock_sock_nested+0xfb/0x110 > > softirqs last disabled at (12568): [<ffffffff8058454e>] tcp_prequeue_process+0x2e/0xa0 > > > > > > Note, for some reason we hit int3 ?? > > > > Tracepoints do not use int3 does it? > > > > Not in your ftrace tree. My LTTng tree includes the immediate values, > which brienfly uses the int3 handler when enabling/disabling > tracepoints. But this seems unrelated to your problem.
Maybe something else is adding it :-/
> > > I have kprobes defined but not any kprobe self tests on. > > > > Could this be a userspace breakpoint then ?
Nope, it happens right in the kernel. And the path I describe below points out that we have a bug in irq tracing when we take a int3 in kernel space.
> > > Anyway, let me describe what the above is and what I found in my > > investigation. > > > > The lockdep took a check_flags error when it noticed that interrupts were > > enabled, but the current->hardirqs_enabled was 0. Lockdep thought > > interrupts were disabled but they were in fact enabled. > > > > > > The last 4 lines of the warning have the numbers in the parenthesis > > annotate the order of events: (Here they are in order) > > > > softirqs last enabled at (12566): [<ffffffff80514d2b>] lock_sock_nested+0xfb/0x110 > > hardirqs last enabled at (12567): [<ffffffff8026206a>] local_bh_enable+0xaa/0x110 > > softirqs last disabled at (12568): [<ffffffff8058454e>] tcp_prequeue_process+0x2e/0xa0 > > hardirqs last disabled at (12569): [<ffffffff80610c76>] int3+0x16/0x40 > > > > The last change that lockdep saw was interrupts being disabled by int3. I > > still don't understand why int3 was enabled. I have startup tests for > > ftrace and the event tracer, but this blob happened when I first ssh'd > > into the box. > > Also note that maybe some entry.S annotation could be missing, making > kallsyms think it was running within int3 when in fact it was running in > a different function. I would double-check with objdump givin the > ffffffff80610c76 address to make sure.
Actually, that was the first thing I did. Because I thought int3 was weird.
> > Just giving my 2 cents before going to bed. I don't have any more brain > left for tonight.
Thanks,
-- Steve
|  |