Re: printk feature for syzbot?

[Steven Rostedt]

On Fri, 11 May 2018 18:50:04 +0900
Sergey Senozhatsky <sergey.senozhatsky.work@xxxxxxxxx> wrote:

> On (05/11/18 11:17), Dmitry Vyukov wrote:
> > 
> > From what I see, it seems that interrupts can be nested:  
> 
> Hm, I thought that in general IRQ handlers run with local IRQs
> disabled on CPU. So, generally, IRQs don't nest. Was I wrong?
> NMIs can nest, that's true; but I thought that at least IRQs
> don't.

We normally don't run nested interrupts, although as the comment in
preempt.h says:

 * The hardirq count could in theory be the same as the number of
 * interrupts in the system, but we run all interrupt handlers with
 * interrupts disabled, so we cannot have nesting interrupts. Though
 * there are a few palaeontologic drivers which reenable interrupts in
 * the handler, so we need more than one bit here.

And no, NMI handlers do not nest. Yes, we deal with nested NMIs, but in
those cases, we just set a bit as a latch, and return, and when the
first NMI is complete, it checks that bit and if it is set, it executes
another NMI handler.

> 
> > https://syzkaller.appspot.com/bug?id=72eddef9cedcf81486adb9dd3e789f0d77505ba5
> > https://syzkaller.appspot.com/bug?id=66fcf61c65f8aa50bbb862eb2fde27c08909a4ff
> > 
> > Will this in_nmi()/in_irq()/in_serving_softirq()/else be enough to
> > untangle output printed by such nested interrupts?  
> 
> Well, hm. __irq_enter() does preempt_count_add(HARDIRQ_OFFSET) and
> __irq_exit() does preempt_count_sub(HARDIRQ_OFFSET). So, technically,
> you can store
> 
> 	preempt_count() & HARDIRQ_MASK
> 	preempt_count() & SOFTIRQ_MASK
> 	preempt_count() & NMI_MASK
> 
> in that extended context tracking. The numbers will not tell you
> the IRQ line number, for instance, but at least you'll be able to
> distinguish different hard/soft IRQs, NMIs. Just an idea, I didn't
> check it, may be it won't work at all.
> 
> Ideally, the serial log should be like this
> 
> 	i:1 ... foo()
> 	i:1 ... bar()
> 	i:2 ... foo()  // __irq_enter()
> 	i:2 ... bar()
> 	i:2 ... buz()  // __irq_exit()
> 	i:1 ... buz()
> 
> but I may be completely wrong.
> 
> Petr and Steven probably will have better ideas.

I handle nesting of different contexts in the ftrace ring buffer using
the preempt count. See trace_recursive_lock/unlock() in
kernel/trace/ring_buffer.c.

-- Steve