Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]

Groups > linux.kernel > #1491941 > unrolled thread

[RFC][PATCH 0/7] printk: use alt_printk to handle printk() recursive calls

Back to article view | Back to linux.kernel

Contents

  [RFC][PATCH 0/7] printk: use alt_printk to handle printk() recursive calls Sergey Senozhatsky <sergey.senozhatsky@gmail.com> - 2016-09-27 16:30 +0200
    [RFC][PATCH 5/7] printk: drop vprintk_func function Sergey Senozhatsky <sergey.senozhatsky@gmail.com> - 2016-09-27 16:30 +0200
    [RFC][PATCH 3/7] printk: introduce per-cpu alt_print seq buffer Sergey Senozhatsky <sergey.senozhatsky@gmail.com> - 2016-09-27 16:30 +0200
      Re: [RFC][PATCH 3/7] printk: introduce per-cpu alt_print seq buffer Petr Mladek <pmladek@suse.com> - 2016-09-29 14:30 +0200
        Re: [RFC][PATCH 3/7] printk: introduce per-cpu alt_print seq buffer Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> - 2016-09-30 03:10 +0200
          Re: [RFC][PATCH 3/7] printk: introduce per-cpu alt_print seq buffer Petr Mladek <pmladek@suse.com> - 2016-09-30 13:40 +0200
    [RFC][PATCH 1/7] printk: use vprintk_func in vprintk() Sergey Senozhatsky <sergey.senozhatsky@gmail.com> - 2016-09-27 16:30 +0200
    [RFC][PATCH 2/7] printk: rename nmi.c and exported api Sergey Senozhatsky <sergey.senozhatsky@gmail.com> - 2016-09-27 16:30 +0200
    [RFC][PATCH 6/7] printk: use alternative printk buffers Sergey Senozhatsky <sergey.senozhatsky@gmail.com> - 2016-09-27 16:30 +0200
      Re: [RFC][PATCH 6/7] printk: use alternative printk buffers Petr Mladek <pmladek@suse.com> - 2016-09-29 15:10 +0200
        Re: [RFC][PATCH 6/7] printk: use alternative printk buffers Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> - 2016-09-30 03:20 +0200
          Re: [RFC][PATCH 6/7] printk: use alternative printk buffers Petr Mladek <pmladek@suse.com> - 2016-09-30 13:20 +0200
            Re: [RFC][PATCH 6/7] printk: use alternative printk buffers Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> - 2016-10-01 04:50 +0200
              Re: [RFC][PATCH 6/7] printk: use alternative printk buffers Petr Mladek <pmladek@suse.com> - 2016-10-04 14:30 +0200
                Re: [RFC][PATCH 6/7] printk: use alternative printk buffers Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> - 2016-10-05 03:40 +0200
                  Re: [RFC][PATCH 6/7] printk: use alternative printk buffers Petr Mladek <pmladek@suse.com> - 2016-10-05 12:20 +0200
            Re: [RFC][PATCH 6/7] printk: use alternative printk buffers Sergey Senozhatsky <sergey.senozhatsky@gmail.com> - 2016-10-03 10:00 +0200
            Re: [RFC][PATCH 6/7] printk: use alternative printk buffers Petr Mladek <pmladek@suse.com> - 2016-10-04 17:00 +0200
              Re: [RFC][PATCH 6/7] printk: use alternative printk buffers Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> - 2016-10-05 03:30 +0200
                Re: [RFC][PATCH 6/7] printk: use alternative printk buffers Petr Mladek <pmladek@suse.com> - 2016-10-05 12:00 +0200
                  Re: [RFC][PATCH 6/7] printk: use alternative printk buffers Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> - 2016-10-06 06:30 +0200
                    Re: [RFC][PATCH 6/7] printk: use alternative printk buffers Petr Mladek <pmladek@suse.com> - 2016-10-06 13:40 +0200
                      Re: [RFC][PATCH 6/7] printk: use alternative printk buffers Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> - 2016-10-10 06:20 +0200
                        Re: [RFC][PATCH 6/7] printk: use alternative printk buffers Petr Mladek <pmladek@suse.com> - 2016-10-10 13:20 +0200
                          Re: [RFC][PATCH 6/7] printk: use alternative printk buffers Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> - 2016-10-11 09:40 +0200
                            Re: [RFC][PATCH 6/7] printk: use alternative printk buffers Petr Mladek <pmladek@suse.com> - 2016-10-11 11:40 +0200
    [RFC][PATCH 4/7] printk: make alt_printk available when config printk set Sergey Senozhatsky <sergey.senozhatsky@gmail.com> - 2016-09-27 16:30 +0200
    [RFC][PATCH 7/7] printk: new printk() recursion detection Sergey Senozhatsky <sergey.senozhatsky@gmail.com> - 2016-09-27 16:30 +0200
      Re: [RFC][PATCH 7/7] printk: new printk() recursion detection Petr Mladek <pmladek@suse.com> - 2016-09-29 15:30 +0200
        Re: [RFC][PATCH 7/7] printk: new printk() recursion detection Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> - 2016-09-30 04:10 +0200
    Re: [RFC][PATCH 0/7] printk: use alt_printk to handle printk()  recursive calls Petr Mladek <pmladek@suse.com> - 2016-09-29 15:30 +0200
      Re: [RFC][PATCH 0/7] printk: use alt_printk to handle printk()  recursive calls Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> - 2016-09-30 04:50 +0200
        Re: [RFC][PATCH 0/7] printk: use alt_printk to handle printk()  recursive calls Petr Mladek <pmladek@suse.com> - 2016-09-30 13:30 +0200
          Re: [RFC][PATCH 0/7] printk: use alt_printk to handle printk()  recursive calls Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> - 2016-10-01 05:10 +0200
            Re: [RFC][PATCH 0/7] printk: use alt_printk to handle printk()  recursive calls Petr Mladek <pmladek@suse.com> - 2016-10-04 13:40 +0200

Page 2 of 2 — ← Prev page 1 [2]

#1496155 — Re: [RFC][PATCH 6/7] printk: use alternative printk buffers

On (10/05/16 11:50), Petr Mladek wrote:
[..]
> > well, it solves a number of problems that the existing implementation
> > cannot handle.
> 
> Please, provide a summary. I wonder if these are real life problems.

anything that starts from printk().
I'm trying to address printk() recursion only, by handling the top-most
recursion - printk -> printk, which causes all of the dependent recursions:
	printk -> spin_lock(logbuf) -> printk() -> spin_lock(logbuf)
	printk -> sem->lock() -> printk() -> sem->lock()
and so on.

I'm not building a lock dependency graph/etc.


the existing recursion detection logic is racy and quite limited in
scope: not only it protects only a tiny bit of printk, but it doesn't
even protect it fully. the very moment we do `logbuf_cpu = UINT_MAX;'
it's over - we still own the lock, but we don't remember it anymore.
a spin_dump() from raw_spin_unlock(&logbuf_lock) will kill us.


** a very quick list **
// a mixed list of theoretical and real problems can also be found
// in the patch set cover letter.


public reports:

1) some pathces/reports from Byungchul Park

the first one in my mailbox (seems to be)
https://marc.info/?l=linux-kernel&m=145406977822244
20160129121545.GH31266@X58A-UD3R

or here
https://marc.info/?l=linux-kernel&m=145570036513749

in his case, I believe, the lock was fine (not corrupted). it just he had
a spin_lock lockup on console semaphore spin_lock coming from:

static void __spin_lock_debug(raw_spinlock_t *lock)
{
	u64 i;
	u64 loops = loops_per_jiffy * HZ;

	for (i = 0; i < loops; i++) {
		if (arch_spin_trylock(&lock->raw_lock))
			return;
		__delay(1);
	}
	/* lockup suspected: */
	spin_dump(lock, "lockup suspected");


which ended up in an infinite recursion.

https://marc.info/?l=linux-kernel&m=145449014308161



2) a report from Viresh Kumar.

frankly, we were lucky to have Viresh on this: a less experienced developer
would probably give up. So would probably do a developer with no appropriate
hardware: jtag debugger/serial console/etc. and I don't know how much would
we spend on meditations to figure out it was a WARN from timekeeping. we
better be 'more prepared'.


=======
reports (unique occurrences only) that I have in internal bugzilla

4) sleeping function called from inside logbuf lock
   which resulted in spin_dump() call from spin_unlock(&logbuf_lock)
   when:
	a) we still owned the logbuf_lock
	b) yet logbuf_cpu was already reset, so printk recursion
	detection was helpless

   'a + b' leave us no chances to survive.

5) ARM specific
   an imprecise abort (http://infocenter.arm.com/help/topic/com.arm.doc.faqs/14809.html)
   hit the CPU while it was holding the printk-related spin-lock.
   that deadlocked the system, because abort handler attempted to
   printk() a message.


6) logbuf_lock corruption
   well, no cookies for us. un-fixable at the moment. we can probably
   do something about it. have a spinlock-debug bool function that would
   tell us whether the lock is corrupted, so we can re-init logbuf_lock,
   perhaps.


> Note that we need to put aside all problems that are solvable
> with printk_deferred(). It seems that printk_deferred() will
> need to stay because it avoids the deadlock caused by
> scheduler/timekeeping code locks.

agree. printk_deferred() takes only one lock and avoids console_unlock()
loop. as long as logbuf_lock is not on it's way printk_deferred() may be
helpful.

> By other words, if there is a missing printk_deferred() we
> need to put it there anyway because the same code might get
> first called outside printk().

right. and I'm not addressing this. there are just too many locks
that can be acquired out of order. not only timekeeping and sched
locks, but any of serial console locks adn so on. we need something
like lockdep locks graph here that would not report the issues (any
printk() can result in deadlock when we detect that at least one of
printk related locks was acquired out of order), but instead would
somehow selectively fix/workaround them.


can we somehow transparently for the rest of the system (just in
printk()) detect that we are in a potentially risky situation? hmm,
I don't know...

something *very* radical?

	vprintk_func()
	{
		if (this_cpu_read(alt_printk_ctx) & ALT_PRINTK_NMI_CONTEXT_MASK)
		return vprintk_nmi(fmt, args);

		if (in_atomic() ||
		/* ^^^^^^^^^^^^ */
			this_cpu_read(alt_printk_ctx) & ALT_PRINTK_CONTEXT_MASK)
			return vprintk_alt(fmt, args);

		return vprintk_default(fmt, args);
	}

	-ss

[toc] | [prev] | [next] | [standalone]

#1496607 — Re: [RFC][PATCH 6/7] printk: use alternative printk buffers

On Thu 2016-10-06 13:22:48, Sergey Senozhatsky wrote:
> On (10/05/16 11:50), Petr Mladek wrote:
> [..]
> > > well, it solves a number of problems that the existing implementation
> > > cannot handle.
> > 
> > Please, provide a summary. I wonder if these are real life problems.
> 
> 1) some pathces/reports from Byungchul Park
> 2) a report from Viresh Kumar.
> 4) sleeping function called from inside logbuf lock
> 5) ARM specific
> 6) logbuf_lock corruption

It is great that you have such a list in hands. It might help
to push this solution.

I actually have one more reason for this approach:

It seems that we will need to keep printk_deferred()/WARN_*DEFERRED().
We do not know about a better solution for the deadlocks caused
by scheduler/timekeeping/console_drivers locks.

The pain is that the list of affected locations is hard to maintain.
It would definitely help if such problems are reported by lockdep
in advance. But lockdep is disabled because it creates the deadlock
on its own.

The alternative printk() allows to enable lockdep and effectively
hunt other possible bugs.

Also the printk context per-CPU variable perfectly fits the
lockdep approach. It will allow to monitor in which printk context
all the other locks are taken and detect possible problems.


> can we somehow transparently for the rest of the system (just in
> printk()) detect that we are in a potentially risky situation? hmm,
> I don't know...
> 
> something *very* radical?
> 
> 	vprintk_func()
> 	{
> 		if (this_cpu_read(alt_printk_ctx) & ALT_PRINTK_NMI_CONTEXT_MASK)
> 		return vprintk_nmi(fmt, args);
> 
> 		if (in_atomic() ||
> 		/* ^^^^^^^^^^^^ */
> 			this_cpu_read(alt_printk_ctx) & ALT_PRINTK_CONTEXT_MASK)
> 			return vprintk_alt(fmt, args);
> 
> 		return vprintk_default(fmt, args);
> 	}

This would affect too many messages. If the error is too serious,
there is a risk that the messages from the alternative per-CPU
buffers will not appear in the main log buffer and the console.
IMHO, this is acceptable for printk-related errors. But people
would complain if other bugs are harder to debug because
the error messages were hidden.

I am going to continue reviewing v2 of the patch set.

BTW: I would like to ask you to slow down a bit. More versions
of such a non-trivial patchset, that are sent within few days,
are far too much. I have some other tasks that I need to work on.
Also I would like to hear opinion from other people. Note that
many people are busy with the merge window at the moment.

Best Regards,
Petr

[toc] | [prev] | [next] | [standalone]

#1498084 — Re: [RFC][PATCH 6/7] printk: use alternative printk buffers

On (10/06/16 13:32), Petr Mladek wrote:
> On Thu 2016-10-06 13:22:48, Sergey Senozhatsky wrote:
> > On (10/05/16 11:50), Petr Mladek wrote:
> > [..]
> > > > well, it solves a number of problems that the existing implementation
> > > > cannot handle.
> > > 
> > > Please, provide a summary. I wonder if these are real life problems.
> > 
> > 1) some pathces/reports from Byungchul Park
> > 2) a report from Viresh Kumar.
> > 4) sleeping function called from inside logbuf lock
> > 5) ARM specific
> > 6) logbuf_lock corruption
> 
> It is great that you have such a list in hands. It might help
> to push this solution.
> 
> I actually have one more reason for this approach:
> 
> It seems that we will need to keep printk_deferred()/WARN_*DEFERRED().
> We do not know about a better solution for the deadlocks caused
> by scheduler/timekeeping/console_drivers locks.

yes, seems so.

> The pain is that the list of affected locations is hard to maintain.
> It would definitely help if such problems are reported by lockdep
> in advance. But lockdep is disabled because it creates the deadlock
> on its own.

right. another issue is that those potentially recursive printk/WARN_ON
calls may be coming from error-handling branches, not all of which are
easily reachable for automated solutions. so in order to find out there
is a problem we must hit it [in some cases].

it may look that lockdep *probably* can report the issues via 'safe' printk,
but that's a notably huge behavior breakage -- if lockdep report comes from
an about-to-deadlock irq handler, then we won't see anything from that CPU
unless there is a panic/nmi panic.

so it probably has to be semi-automatic/semi-manual:
- add might_printk() that would acquire/release console sem; or
  logbuf_lock (which is probably even better)
- find all functions that do printk/WARN in kernel/time and kernel/sched
- add might_printk() to those functions (just like might_sleep())
- run the kernel
- ...
- profit

#ifdef CONFIG_VALIDATE_PRINTK_CALLS

#define might_printk()							\
	do {								\
		if (!printk_in_safe_mode()) {				\
			unsigned long flags;				\
									\
			printk_safe_enter(flags);			\
			mutex_acquire(&console_lock_dep_map...);	\
			mutex_release(&console_lock_dep_map...);	\
			/*						\
			 * or printk_deferred("");			\
			 */						\
			printk_safe_exit(flags);			\
		}							\
	} while (0)

#else

#define might_printk()

#endif


may be that will make it easier. need to think more.


> BTW: I would like to ask you to slow down a bit. More versions
> of such a non-trivial patchset, that are sent within few days,
> are far too much. I have some other tasks that I need to work on.
> Also I would like to hear opinion from other people. Note that
> many people are busy with the merge window at the moment.

sure, sorry about that! wasn't really happy with that as well.
and thanks for your help.

	-ss

[toc] | [prev] | [next] | [standalone]

#1498238 — Re: [RFC][PATCH 6/7] printk: use alternative printk buffers

On Mon 2016-10-10 13:09:57, Sergey Senozhatsky wrote:
> On (10/06/16 13:32), Petr Mladek wrote:
> > On Thu 2016-10-06 13:22:48, Sergey Senozhatsky wrote:
> > > On (10/05/16 11:50), Petr Mladek wrote:
> > > [..]
> > > > > well, it solves a number of problems that the existing implementation
> > > > > cannot handle.
> > > > 
> > > > Please, provide a summary. I wonder if these are real life problems.
> > > 
> > > 1) some pathces/reports from Byungchul Park
> > > 2) a report from Viresh Kumar.
> > > 4) sleeping function called from inside logbuf lock
> > > 5) ARM specific
> > > 6) logbuf_lock corruption
> > 
> > It is great that you have such a list in hands. It might help
> > to push this solution.
> > 
> > I actually have one more reason for this approach:
> > 
> > It seems that we will need to keep printk_deferred()/WARN_*DEFERRED().
> > We do not know about a better solution for the deadlocks caused
> > by scheduler/timekeeping/console_drivers locks.
> 
> yes, seems so.
> 
> > The pain is that the list of affected locations is hard to maintain.
> > It would definitely help if such problems are reported by lockdep
> > in advance. But lockdep is disabled because it creates the deadlock
> > on its own.
> 
> right. another issue is that those potentially recursive printk/WARN_ON
> calls may be coming from error-handling branches, not all of which are
> easily reachable for automated solutions. so in order to find out there
> is a problem we must hit it [in some cases].

yes

> it may look that lockdep *probably* can report the issues via 'safe' printk,
> but that's a notably huge behavior breakage -- if lockdep report comes from
> an about-to-deadlock irq handler, then we won't see anything from that CPU
> unless there is a panic/nmi panic.
> 
> so it probably has to be semi-automatic/semi-manual:
> - add might_printk() that would acquire/release console sem; or
>   logbuf_lock (which is probably even better)
> - find all functions that do printk/WARN in kernel/time and kernel/sched
> - add might_printk() to those functions (just like might_sleep())
> - run the kernel
> - ...
> - profit

I like the idea with might_printk(). I hope that it will be acceptable
for the scheduler/timekeeping people.

JFYI, I could work on the printk-context handling in lockdep.
I am just working on a lockdep support in NMI and am getting
kind of familiar with that code.

Best Regards,
Petr

[toc] | [prev] | [next] | [standalone]

#1498640 — Re: [RFC][PATCH 6/7] printk: use alternative printk buffers

On (10/10/16 13:17), Petr Mladek wrote:
[..]
> > it may look that lockdep *probably* can report the issues via 'safe' printk,
> > but that's a notably huge behavior breakage -- if lockdep report comes from
> > an about-to-deadlock irq handler, then we won't see anything from that CPU
> > unless there is a panic/nmi panic.
> > 
> > so it probably has to be semi-automatic/semi-manual:
> > - add might_printk() that would acquire/release console sem; or
> >   logbuf_lock (which is probably even better)
> > - find all functions that do printk/WARN in kernel/time and kernel/sched
> > - add might_printk() to those functions (just like might_sleep())
> > - run the kernel
> > - ...
> > - profit
> 
> I like the idea with might_printk(). I hope that it will be acceptable
> for the scheduler/timekeeping people.
> 
> JFYI, I could work on the printk-context handling in lockdep.
> I am just working on a lockdep support in NMI and am getting
> kind of familiar with that code.

sorry, what do you mean by 'printk-context handling in lockdep'?
wouldn't `lockdep + might_printk() + printk_safe' be enough? am I
missing something?

	-ss

[toc] | [prev] | [next] | [standalone]

#1498689 — Re: [RFC][PATCH 6/7] printk: use alternative printk buffers

On Tue 2016-10-11 16:35:28, Sergey Senozhatsky wrote:
> On (10/10/16 13:17), Petr Mladek wrote:
> [..]
> > > it may look that lockdep *probably* can report the issues via 'safe' printk,
> > > but that's a notably huge behavior breakage -- if lockdep report comes from
> > > an about-to-deadlock irq handler, then we won't see anything from that CPU
> > > unless there is a panic/nmi panic.
> > > 
> > > so it probably has to be semi-automatic/semi-manual:
> > > - add might_printk() that would acquire/release console sem; or
> > >   logbuf_lock (which is probably even better)
> > > - find all functions that do printk/WARN in kernel/time and kernel/sched
> > > - add might_printk() to those functions (just like might_sleep())
> > > - run the kernel
> > > - ...
> > > - profit
> > 
> > I like the idea with might_printk(). I hope that it will be acceptable
> > for the scheduler/timekeeping people.
> > 
> > JFYI, I could work on the printk-context handling in lockdep.
> > I am just working on a lockdep support in NMI and am getting
> > kind of familiar with that code.
> 
> sorry, what do you mean by 'printk-context handling in lockdep'?
> wouldn't `lockdep + might_printk() + printk_safe' be enough? am I
> missing something?

Good question. It was my intuition that we would need some extra
support in lockdep. It is quite complicated and I have not thought
about it deep enough yet.

Let's unwind some of my thoughts:

Well, the nice thing about the lockdep is that it is able to detect
dangerous lock chains in advance. It means even without being
in the deadlock situation.

IMHO, the printk-related deadlocks will be solved in two ways.
Either by replacing the classic printk() with the deferred
variant or by surrounding a problematic code with
printk_safe_enter()/exit() calls. If we do the fix correctly,
the lockdep warning should disappear.

Now, replacing printk() with printk_deferred() will have effect
even with the current lockdep code. It is because printk_deferred()
will not longer take the console-related locks, so they will not
longer appear in the call chain.

But what about adding printk_safe_enter()/exit()? Of course,
if we do it correctly, it will prevent a deadlock. But lockdep
is supposed to detect this in advance. And these functions just
handle the printk_context variable. The guarded code will still
take the same locks. Therefore my feeling is that lockdep will
need to be aware of the printk_context. It would have similar
effect like taking lock with interrupts enabled or disabled.
By other words, safe printk context would prevent entering
the same chain of locks recursively. It is like the disabled
interrupts prevent a recursion.

Finally, note that the proposed might_printk() emulates the classic
printk() call. It the classic printk() causes problems somewhere,
it will be replaced by printk_deferred() and might_printk()
will be removed. By other words, might_printk() shows where
we need the first solution (using printk_deferred) but it
does not tell the lockdep about the entire story.


I am not sure if the above makes sense. I need much more
coffee, sleep, and thinking to sort the problem completely.


Let me look at it from a slightly different angle:

The deadlock is caused by a chain of taken locks. lockdep
is able to warn about it in advance because it knows that
two partial lock chains might eventually happen together.
For this, the information about the interrupt context
and disabled interrupts is important. It tells what
chains of locks might happen together and what are
prevented. IMHO, the printk_context has similar effect
like the interrupt context stuff.

Well, there is a difference. Being in interrupt context
and having disabled interrupts are two separate values.
printk_context defines just one value. It either means
that the situation with printk is easier or that we
will need one more variable for the lockdep handling
of the printk state.

Anyway, I would not solve lockdep in this patchset.
Let's keep it as another challenge.

Best Regards,
Petr

[toc] | [prev] | [next] | [standalone]

#1491949 — [RFC][PATCH 4/7] printk: make alt_printk available when config printk set

alt_printk must be enabled on systems that have CONFIG_PRINTK set,
while NMI related functions must depend on CONFIG_PRINTK_NMI.

Signed-off-by: Sergey Senozhatsky <sergey.senozhatsky@gmail.com>
---
 include/linux/printk.h     | 14 ++++++++------
 kernel/printk/Makefile     |  2 +-
 kernel/printk/alt_printk.c | 23 +++++++++++++++++------
 kernel/printk/internal.h   | 31 +++++++++++++------------------
 4 files changed, 39 insertions(+), 31 deletions(-)

diff --git a/include/linux/printk.h b/include/linux/printk.h
index 7510613..fae308a 100644
--- a/include/linux/printk.h
+++ b/include/linux/printk.h
@@ -131,17 +131,11 @@ void early_printk(const char *s, ...) { }
 #endif
 
 #ifdef CONFIG_PRINTK_NMI
-extern void alt_printk_init(void);
 extern void printk_nmi_enter(void);
 extern void printk_nmi_exit(void);
-extern void alt_printk_flush(void);
-extern void alt_printk_flush_on_panic(void);
 #else
-static inline void alt_printk_init(void) { }
 static inline void printk_nmi_enter(void) { }
 static inline void printk_nmi_exit(void) { }
-static inline void alt_printk_flush(void) { }
-static inline void alt_printk_flush_on_panic(void) { }
 #endif /* PRINTK_NMI */
 
 #ifdef CONFIG_PRINTK
@@ -193,6 +187,10 @@ void __init setup_log_buf(int early);
 __printf(1, 2) void dump_stack_set_arch_desc(const char *fmt, ...);
 void dump_stack_print_info(const char *log_lvl);
 void show_regs_print_info(const char *log_lvl);
+
+extern void alt_printk_init(void);
+extern void alt_printk_flush(void);
+extern void alt_printk_flush_on_panic(void);
 #else
 static inline __printf(1, 0)
 int vprintk(const char *s, va_list args)
@@ -252,6 +250,10 @@ static inline void dump_stack_print_info(const char *log_lvl)
 static inline void show_regs_print_info(const char *log_lvl)
 {
 }
+
+static inline void alt_printk_init(void) { }
+static inline void alt_printk_flush(void) { }
+static inline void alt_printk_flush_on_panic(void) { }
 #endif
 
 extern asmlinkage void dump_stack(void) __cold;
diff --git a/kernel/printk/Makefile b/kernel/printk/Makefile
index 3fc5e4e..d11838c 100644
--- a/kernel/printk/Makefile
+++ b/kernel/printk/Makefile
@@ -1,3 +1,3 @@
 obj-y	= printk.o
-obj-$(CONFIG_PRINTK_NMI)		+= alt_printk.o
+obj-$(CONFIG_PRINTK)		+= alt_printk.o
 obj-$(CONFIG_A11Y_BRAILLE_CONSOLE)	+= braille.o
diff --git a/kernel/printk/alt_printk.c b/kernel/printk/alt_printk.c
index 8978390..8ac1daa 100644
--- a/kernel/printk/alt_printk.c
+++ b/kernel/printk/alt_printk.c
@@ -40,7 +40,6 @@
  */
 DEFINE_PER_CPU(printk_func_t, printk_func) = vprintk_default;
 static int alt_printk_irq_ready;
-atomic_t nmi_message_lost;
 
 #define ALT_LOG_BUF_LEN ((1 << CONFIG_ALT_PRINTK_LOG_BUF_SHIFT) -	\
 			 sizeof(atomic_t) - sizeof(struct irq_work))
@@ -50,7 +49,11 @@ struct alt_printk_seq_buf {
 	struct irq_work		work;	/* IRQ work that flushes the buffer */
 	unsigned char		buffer[ALT_LOG_BUF_LEN];
 };
+
+#ifdef CONFIG_PRINTK_NMI
 static DEFINE_PER_CPU(struct alt_printk_seq_buf, nmi_print_seq);
+atomic_t nmi_message_lost;
+#endif
 
 /*
  * There can be two alt_printk contexts at most - a `normal' alt_printk
@@ -320,8 +323,12 @@ void alt_printk_flush(void)
 {
 	int cpu;
 
-	for_each_possible_cpu(cpu)
-		__alt_printk_flush(&per_cpu(nmi_print_seq, cpu).work);
+	for_each_possible_cpu(cpu) {
+		if (IS_ENABLED(CONFIG_PRINTK_NMI))
+			__alt_printk_flush(&per_cpu(nmi_print_seq, cpu).work);
+
+		__alt_printk_flush(&per_cpu(alt_print_seq, cpu).work);
+	}
 }
 
 /**
@@ -356,12 +363,14 @@ void __init alt_printk_init(void)
 	int cpu;
 
 	for_each_possible_cpu(cpu) {
-		struct alt_printk_seq_buf *s = &per_cpu(nmi_print_seq, cpu);
+		struct alt_printk_seq_buf *s = &per_cpu(alt_print_seq, cpu);
 
 		init_irq_work(&s->work, __alt_printk_flush);
 
-		s = &per_cpu(alt_print_seq, cpu);
-		init_irq_work(&s->work, __alt_printk_flush);
+		if (IS_ENABLED(CONFIG_PRINTK_NMI)) {
+			s = &per_cpu(nmi_print_seq, cpu);
+			init_irq_work(&s->work, __alt_printk_flush);
+		}
 	}
 
 	/* Make sure that IRQ works are initialized before enabling. */
@@ -372,6 +381,7 @@ void __init alt_printk_init(void)
 	alt_printk_flush();
 }
 
+#ifdef CONFIG_PRINTK_NMI
 /*
  * Safe printk() for NMI context. It uses a per-CPU buffer to
  * store the message. NMIs are not nested, so there is always only
@@ -399,3 +409,4 @@ void printk_nmi_exit(void)
 {
 	__lockless_printk_exit();
 }
+#endif /* CONFIG_PRINTK_NMI */
diff --git a/kernel/printk/internal.h b/kernel/printk/internal.h
index c5f970e..3eebf6d 100644
--- a/kernel/printk/internal.h
+++ b/kernel/printk/internal.h
@@ -18,21 +18,9 @@
 
 typedef __printf(1, 0) int (*printk_func_t)(const char *fmt, va_list args);
 
-int __printf(1, 0) vprintk_default(const char *fmt, va_list args);
-
 #ifdef CONFIG_PRINTK
 
-void alt_printk_enter(void);
-void alt_printk_exit(void);
-
-#else
-
-void alt_printk_enter(void) { }
-void alt_printk_exit(void) { }
-
-#endif /* CONFIG_PRINTK */
-
-#ifdef CONFIG_PRINTK_NMI
+int __printf(1, 0) vprintk_default(const char *fmt, va_list args);
 
 extern raw_spinlock_t logbuf_lock;
 
@@ -48,6 +36,18 @@ static inline __printf(1, 0) int vprintk_func(const char *fmt, va_list args)
 	return this_cpu_read(printk_func)(fmt, args);
 }
 
+void alt_printk_enter(void);
+void alt_printk_exit(void);
+
+#else
+
+void alt_printk_enter(void) { }
+void alt_printk_exit(void) { }
+
+#endif /* CONFIG_PRINTK */
+
+#ifdef CONFIG_PRINTK_NMI
+
 extern atomic_t nmi_message_lost;
 static inline int get_nmi_message_lost(void)
 {
@@ -56,11 +56,6 @@ static inline int get_nmi_message_lost(void)
 
 #else /* CONFIG_PRINTK_NMI */
 
-static inline __printf(1, 0) int vprintk_func(const char *fmt, va_list args)
-{
-	return vprintk_default(fmt, args);
-}
-
 static inline int get_nmi_message_lost(void)
 {
 	return 0;
-- 
2.10.0.372.g6fe1b14

[toc] | [prev] | [next] | [standalone]

#1491950 — [RFC][PATCH 7/7] printk: new printk() recursion detection

We can't use alt_printk when we are flushing alt_printk buffers to logbuf,
because otherwise we would just flush messages back to alt_printk buffers.
At the same time, this opens a door for potential deadlock, should flushing
endup in recursive printk() call:

  irq_work_run()
    alt_printk_flush_line()
      printk()
        WARN_ON()
        ^^^^^^^^^
        depending on circumstances this can result in printk-deadlock.

To cope with it, we can use alt_printk context ->entry_count:
- __alt_printk_flush() sets ->entry_count to 1
- every printk() call from alt_printk_flush_foo() calls
  alt_printk_enter() and alt_printk_exit()
- alt_printk_enter() increments ->entry_count and tests the value:
  - if it's `==2' then we are in normal alt_printk_flush()->printk() path
  - if it's `>=3' then we are in recursion. The first time we detect
    recursion (->entry_count == 3) we switch from default printk() to
    alt_printk(), to avoid possible deadlocks.
- in alt_printk_exit() we test if we were in normal printk() path or
  in printk() recursion and rollback to default printk() if so;
  and decrement ->entry_count.

->entry_count is a per-cpu variable, which must be touched only with
local IRQs disabled. NMI should never touch ->entry_count.

An example:

WARN_ON() from printk() while alt_printk_flush() flushed messages
from alt_printk buffer to a logbuf:

 ------------[ cut here ]------------
 WARNING: CPU: 1 PID: 332 at kernel/printk/printk.c:1775 vprintk_emit+0x73/0x398
 CPU: 1 PID: 332 Comm: bash
 Call Trace:
  <IRQ>  [<ffffffff811f23ae>] dump_stack+0x68/0x92
  [<ffffffff8103d649>] __warn+0xb8/0xd3
  [<ffffffff8103d6ca>] warn_slowpath_null+0x18/0x1a
  [<ffffffff8107fdb6>] vprintk_emit+0x73/0x398
  [<ffffffff8108023d>] vprintk_default+0x18/0x1a
  [<ffffffff810c7fa5>] printk+0x43/0x4b
  [<ffffffff81080fc3>] alt_printk_flush_line+0x27/0x29
  [<ffffffff810810e1>] __alt_printk_flush+0xd7/0x12d
  [<ffffffff810b6356>] irq_work_run_list+0x43/0x67
  [<ffffffff810b6595>] irq_work_run+0x2a/0x44
  [<ffffffff81016925>] smp_trace_irq_work_interrupt+0x29/0x30
  [<ffffffff81016935>] smp_irq_work_interrupt+0x9/0xb
  [<ffffffff814c3fe6>] irq_work_interrupt+0x86/0x90
  <EOI>  [<ffffffff814c2577>] ? _raw_spin_unlock+0x2c/0x3f
  [<ffffffff8107fd12>] ? console_unlock+0x528/0x559
  [<ffffffff810800ca>] vprintk_emit+0x387/0x398
  [<ffffffff8108023d>] vprintk_default+0x18/0x1a
  [<ffffffff810c7fa5>] printk+0x43/0x4b
  [..]
  [<ffffffff814c2daa>] entry_SYSCALL_64_fastpath+0x18/0xad
 ---[ end trace ]---

Signed-off-by: Sergey Senozhatsky <sergey.senozhatsky@gmail.com>
---
 kernel/printk/alt_printk.c | 26 +++++++++++++++++++++++---
 kernel/printk/internal.h   |  5 +++++
 kernel/printk/printk.c     | 38 ++------------------------------------
 3 files changed, 30 insertions(+), 39 deletions(-)

diff --git a/kernel/printk/alt_printk.c b/kernel/printk/alt_printk.c
index 8ac1daa..0302ea3 100644
--- a/kernel/printk/alt_printk.c
+++ b/kernel/printk/alt_printk.c
@@ -69,6 +69,9 @@ atomic_t nmi_message_lost;
 #define MAX_ALT_PRINTK_CTX	1
 #endif
 
+#define CTX_ENTRY_FLUSHING	2
+#define CTX_ENTRY_FLUSHING_RECURSION	(CTX_ENTRY_FLUSHING + 1)
+
 struct alt_printk_ctx {
 	atomic_t	idx;
 	unsigned int	entry_count;
@@ -189,10 +192,15 @@ void alt_printk_enter(void)
 	 *     will see ->entry_count > 2.
 	 */
 	ctx->entry_count++;
-	if (ctx->entry_count > 1)
+	if (ctx->entry_count == CTX_ENTRY_FLUSHING)
 		return;
 
-	/* @TODO: do something sensible in case of printk() recursion */
+	/*
+	 * Once ->entry_coun == CTX_ENTRY_FLUSHING_RECURSION printk()
+	 * switches to alt_printk() buffers.
+	 */
+	if (ctx->entry_count > CTX_ENTRY_FLUSHING_RECURSION)
+		return;
 
 	__lockless_printk_enter(vprintk_alt);
 }
@@ -202,11 +210,23 @@ void alt_printk_exit(void)
 {
 	struct alt_printk_ctx *ctx = this_cpu_ptr(&alt_printk_ctx);
 
-	if (ctx->entry_count == 1)
+	/*
+	 * If we are returning from a normal alt_printk context or
+	 * from printk() recursion -- switch back to default printk.
+	 */
+	if (ctx->entry_count == 1 ||
+			ctx->entry_count == CTX_ENTRY_FLUSHING_RECURSION)
 		__lockless_printk_exit();
 	ctx->entry_count--;
 }
 
+bool recursed_printk_call(void)
+{
+	struct alt_printk_ctx *ctx = this_cpu_ptr(&alt_printk_ctx);
+
+	return oops_in_progress && (ctx->entry_count > CTX_ENTRY_FLUSHING);
+}
+
 static void alt_printk_flush_line(const char *text, int len)
 {
 	/*
diff --git a/kernel/printk/internal.h b/kernel/printk/internal.h
index b030ca0..7d082b7 100644
--- a/kernel/printk/internal.h
+++ b/kernel/printk/internal.h
@@ -34,11 +34,16 @@ DECLARE_PER_CPU(printk_func_t, printk_func);
 
 void alt_printk_enter(void);
 void alt_printk_exit(void);
+bool recursed_printk_call(void);
 
 #else
 
 void alt_printk_enter(void) { }
 void alt_printk_exit(void) { }
+bool recursed_printk_call(void)
+{
+	return false;
+}
 
 #endif /* CONFIG_PRINTK */
 
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index e5dacfb..47f1e0e 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -1748,18 +1748,14 @@ asmlinkage int vprintk_emit(int facility, int level,
 			    const char *dict, size_t dictlen,
 			    const char *fmt, va_list args)
 {
-	static bool recursion_bug;
 	static char textbuf[LOG_LINE_MAX];
 	char *text = textbuf;
 	size_t text_len = 0;
 	enum log_flags lflags = 0;
 	unsigned long flags;
-	int this_cpu;
 	int printed_len = 0;
 	int nmi_message_lost;
 	bool in_sched = false;
-	/* cpu currently holding logbuf_lock in this function */
-	static unsigned int logbuf_cpu = UINT_MAX;
 
 	if (level == LOGLEVEL_SCHED) {
 		level = LOGLEVEL_DEFAULT;
@@ -1770,42 +1766,13 @@ asmlinkage int vprintk_emit(int facility, int level,
 	printk_delay();
 
 	local_irq_save(flags);
-	this_cpu = smp_processor_id();
+	alt_printk_enter();
 
-	/*
-	 * Ouch, printk recursed into itself!
-	 */
-	if (unlikely(logbuf_cpu == this_cpu)) {
-		/*
-		 * If a crash is occurring during printk() on this CPU,
-		 * then try to get the crash message out but make sure
-		 * we can't deadlock. Otherwise just return to avoid the
-		 * recursion and return - but flag the recursion so that
-		 * it can be printed at the next appropriate moment:
-		 */
-		if (!oops_in_progress && !lockdep_recursing(current)) {
-			recursion_bug = true;
-			local_irq_restore(flags);
-			return 0;
-		}
+	if (recursed_printk_call())
 		zap_locks();
-	}
 
-	alt_printk_enter();
 	/* This stops the holder of console_sem just where we want him */
 	raw_spin_lock(&logbuf_lock);
-	logbuf_cpu = this_cpu;
-
-	if (unlikely(recursion_bug)) {
-		static const char recursion_msg[] =
-			"BUG: recent printk recursion!";
-
-		recursion_bug = false;
-		/* emit KERN_CRIT message */
-		printed_len += log_store(0, 2, LOG_PREFIX|LOG_NEWLINE, 0,
-					 NULL, 0, recursion_msg,
-					 strlen(recursion_msg));
-	}
 
 	nmi_message_lost = get_nmi_message_lost();
 	if (unlikely(nmi_message_lost)) {
@@ -1898,7 +1865,6 @@ asmlinkage int vprintk_emit(int facility, int level,
 						 dict, dictlen, text, text_len);
 	}
 
-	logbuf_cpu = UINT_MAX;
 	raw_spin_unlock(&logbuf_lock);
 	alt_printk_exit();
 	local_irq_restore(flags);
-- 
2.10.0.372.g6fe1b14

[toc] | [prev] | [next] | [standalone]

#1493463 — Re: [RFC][PATCH 7/7] printk: new printk() recursion detection

On Tue 2016-09-27 23:22:37, Sergey Senozhatsky wrote:
> We can't use alt_printk when we are flushing alt_printk buffers to logbuf,
> because otherwise we would just flush messages back to alt_printk buffers.
> At the same time, this opens a door for potential deadlock, should flushing
> endup in recursive printk() call:
> 
>   irq_work_run()
>     alt_printk_flush_line()
>       printk()
>         WARN_ON()
>         ^^^^^^^^^
>         depending on circumstances this can result in printk-deadlock.
> 
> To cope with it, we can use alt_printk context ->entry_count:
> - __alt_printk_flush() sets ->entry_count to 1
> - every printk() call from alt_printk_flush_foo() calls
>   alt_printk_enter() and alt_printk_exit()
> - alt_printk_enter() increments ->entry_count and tests the value:
>   - if it's `==2' then we are in normal alt_printk_flush()->printk() path
>   - if it's `>=3' then we are in recursion. The first time we detect
>     recursion (->entry_count == 3) we switch from default printk() to
>     alt_printk(), to avoid possible deadlocks.
> - in alt_printk_exit() we test if we were in normal printk() path or
>   in printk() recursion and rollback to default printk() if so;
>   and decrement ->entry_count.

I am sorry but I do not understand this much. printk() should set the
alternative implementation in the critical section by default.
Why do we need to handle this so specially?

Is it because of flushing in NMI context when panicing? I would call
vprintk_emit() directly from the flush_line() function in this case.
Then all other possible error printk's will get redirected to the
NMI buffer which is good enouh.

Best Regards,
Petr

[toc] | [prev] | [next] | [standalone]

#1493833 — Re: [RFC][PATCH 7/7] printk: new printk() recursion detection

On (09/29/16 15:19), Petr Mladek wrote:
> I am sorry but I do not understand this much. printk() should set the
> alternative implementation in the critical section by default.
> Why do we need to handle this so specially?
> 
> Is it because of flushing in NMI context when panicing? I would call
> vprintk_emit() directly from the flush_line() function in this case.
> Then all other possible error printk's will get redirected to the
> NMI buffer which is good enouh.

I'm going to re-do the entire thing. I had some cases in mind, like
WARN from vsnprintf from printk from alt_printk_flushing from panic.
or something like this. perhaps too complicated, will re-think it.

	-ss

[toc] | [prev] | [next] | [standalone]

#1493462 — Re: [RFC][PATCH 0/7] printk: use alt_printk to handle printk() recursive calls

On Tue 2016-09-27 23:22:30, Sergey Senozhatsky wrote:
> 	Hello,
> 
> 	RFC
> 
> 	This patch set extends a lock-less NMI per-cpu buffers idea to
> handle recursive printk() calls. The basic mechanism is pretty much the
> same -- at the beginning of a deadlock-prone section we switch to lock-less
> printk callback, and return back to a default printk implementation at the
> end; the messages are getting flushed to a logbuf buffer from a safer
> context.

I was skeptical but I really like this way now.

The switching of the buffers is a bit hairy in this version but I
think that we could make it much better.

Other than that it looks like a big win. It kills a lot of
printk-related pain points. And it will not be that complicated
after all.

Best Regards,
Petr

[toc] | [prev] | [next] | [standalone]

#1493856 — Re: [RFC][PATCH 0/7] printk: use alt_printk to handle printk() recursive calls

On (09/29/16 15:25), Petr Mladek wrote:
> On Tue 2016-09-27 23:22:30, Sergey Senozhatsky wrote:
> > 	Hello,
> > 
> > 	RFC
> > 
> > 	This patch set extends a lock-less NMI per-cpu buffers idea to
> > handle recursive printk() calls. The basic mechanism is pretty much the
> > same -- at the beginning of a deadlock-prone section we switch to lock-less
> > printk callback, and return back to a default printk implementation at the
> > end; the messages are getting flushed to a logbuf buffer from a safer
> > context.
> 
> I was skeptical but I really like this way now.
>
> The switching of the buffers is a bit hairy in this version but I
> think that we could make it much better.
> 
> Other than that it looks like a big win. It kills a lot of
> printk-related pain points. And it will not be that complicated
> after all.

many thanks for looking at this train wreck.

so, like I said, it addresses printk()-recursion in *ideally* quite
a minimalistic way -- just several alt_printk_enter/exit calls in
printk.c, without ever touching any other parts of the kernel.

gunning down printk deadlocks in general, however, requires much more
effort; or even a completely different approach.

a) a lock-less printk() by default
   um, `#define printk alt_printk'. but this will break printk() from irq.
   and the ordering of messages from per-cpu buffers may be far from correct.

b) combining a DEFERRED_WARN + alt_printk
   DEFERRED_WARN potentially is a never ending thing. we can add some
   lockdep annotations, perhaps, and hope that error handling branches
   that may contain WARN_ONs/printk-s will be executed with prove_locking
   enabled on someone's machine.

c) ...

	-ss

[toc] | [prev] | [next] | [standalone]

#1494031 — Re: [RFC][PATCH 0/7] printk: use alt_printk to handle printk() recursive calls

On Fri 2016-09-30 11:43:07, Sergey Senozhatsky wrote:
> On (09/29/16 15:25), Petr Mladek wrote:
> > On Tue 2016-09-27 23:22:30, Sergey Senozhatsky wrote:
> > > 	Hello,
> > > 
> > > 	RFC
> > > 
> > > 	This patch set extends a lock-less NMI per-cpu buffers idea to
> > > handle recursive printk() calls. The basic mechanism is pretty much the
> > > same -- at the beginning of a deadlock-prone section we switch to lock-less
> > > printk callback, and return back to a default printk implementation at the
> > > end; the messages are getting flushed to a logbuf buffer from a safer
> > > context.
> > 
> > I was skeptical but I really like this way now.
> >
> > The switching of the buffers is a bit hairy in this version but I
> > think that we could make it much better.
> > 
> > Other than that it looks like a big win. It kills a lot of
> > printk-related pain points. And it will not be that complicated
> > after all.
> 
> many thanks for looking at this train wreck.
> 
> so, like I said, it addresses printk()-recursion in *ideally* quite
> a minimalistic way -- just several alt_printk_enter/exit calls in
> printk.c, without ever touching any other parts of the kernel.
> 
> gunning down printk deadlocks in general, however, requires much more
> effort; or even a completely different approach.
> 
> a) a lock-less printk() by default
>    um, `#define printk alt_printk'. but this will break printk() from irq.
>    and the ordering of messages from per-cpu buffers may be far from correct.

Well, the current vprintk_nmi() is lockless. The alternative printk()
is going to use the same code, so it will be lockless as well. It
means that even this patchset is supposed to avoid all possible
deadlocks via printk() calls.

There is still a risk of an infinite recursion. But vprintk_nmi()
bails out early when the buffer is full. This should minimalize
the risk. In fact, the recursion would become rather theoretical
problem.

Best Regards,
Petr

[toc] | [prev] | [next] | [standalone]

#1494342 — Re: [RFC][PATCH 0/7] printk: use alt_printk to handle printk() recursive calls

On (09/30/16 13:27), Petr Mladek wrote:
> > > > 	This patch set extends a lock-less NMI per-cpu buffers idea to
> > > > handle recursive printk() calls. The basic mechanism is pretty much the
> > > > same -- at the beginning of a deadlock-prone section we switch to lock-less
> > > > printk callback, and return back to a default printk implementation at the
> > > > end; the messages are getting flushed to a logbuf buffer from a safer
> > > > context.
> > > 
> > > I was skeptical but I really like this way now.
> > >
> > > The switching of the buffers is a bit hairy in this version but I
> > > think that we could make it much better.
> > > 
> > > Other than that it looks like a big win. It kills a lot of
> > > printk-related pain points. And it will not be that complicated
> > > after all.
> > 
> > many thanks for looking at this train wreck.
> > 
> > so, like I said, it addresses printk()-recursion in *ideally* quite
> > a minimalistic way -- just several alt_printk_enter/exit calls in
> > printk.c, without ever touching any other parts of the kernel.
> > 
> > gunning down printk deadlocks in general, however, requires much more
> > effort; or even a completely different approach.
> > 
> > a) a lock-less printk() by default
> >    um, `#define printk alt_printk'. but this will break printk() from irq.
> >    and the ordering of messages from per-cpu buffers may be far from correct.
> 
> Well, the current vprintk_nmi() is lockless. The alternative printk()
> is going to use the same code, so it will be lockless as well. It
> means that even this patchset is supposed to avoid all possible
> deadlocks via printk() calls.

I meant that printk-recursion and printk-deadlock can be different
scenarios. deadlocks are harder to handle

 devkmsg_open()
  raw_spin_lock_irq(&logbuf_lock)
   spin_dump()
    printk()
     raw_spin_lock_irqsave(&logbuf_lock)

this one can be handled by alt_printk.

 devkmsg_open()
  local_irq_save();
  alt_printk_enter()
  raw_spin_lock(&logbuf_lock)
   spin_dump()
    printk()
     vprintk_alt()

but there are some that can't be handled solely in printk.c

	-ss

[toc] | [prev] | [next] | [standalone]

#1495375 — Re: [RFC][PATCH 0/7] printk: use alt_printk to handle printk() recursive calls

On Sat 2016-10-01 12:02:51, Sergey Senozhatsky wrote:
> On (09/30/16 13:27), Petr Mladek wrote:
> > > > > 	This patch set extends a lock-less NMI per-cpu buffers idea to
> > > > > handle recursive printk() calls. The basic mechanism is pretty much the
> > > > > same -- at the beginning of a deadlock-prone section we switch to lock-less
> > > > > printk callback, and return back to a default printk implementation at the
> > > > > end; the messages are getting flushed to a logbuf buffer from a safer
> > > > > context.
> > > > 
> > > > I was skeptical but I really like this way now.
> > > >
> > > > The switching of the buffers is a bit hairy in this version but I
> > > > think that we could make it much better.
> > > > 
> > > > Other than that it looks like a big win. It kills a lot of
> > > > printk-related pain points. And it will not be that complicated
> > > > after all.
> > > 
> > > many thanks for looking at this train wreck.
> > > 
> > > so, like I said, it addresses printk()-recursion in *ideally* quite
> > > a minimalistic way -- just several alt_printk_enter/exit calls in
> > > printk.c, without ever touching any other parts of the kernel.
> > > 
> > > gunning down printk deadlocks in general, however, requires much more
> > > effort; or even a completely different approach.
> > > 
> > > a) a lock-less printk() by default
> > >    um, `#define printk alt_printk'. but this will break printk() from irq.
> > >    and the ordering of messages from per-cpu buffers may be far from correct.
> > 
> > Well, the current vprintk_nmi() is lockless. The alternative printk()
> > is going to use the same code, so it will be lockless as well. It
> > means that even this patchset is supposed to avoid all possible
> > deadlocks via printk() calls.
> 
> I meant that printk-recursion and printk-deadlock can be different
> scenarios. deadlocks are harder to handle
> 
>  devkmsg_open()
>   raw_spin_lock_irq(&logbuf_lock)
>    spin_dump()
>     printk()
>      raw_spin_lock_irqsave(&logbuf_lock)
> 
> this one can be handled by alt_printk.
> 
>  devkmsg_open()
>   local_irq_save();
>   alt_printk_enter()
>   raw_spin_lock(&logbuf_lock)
>    spin_dump()
>     printk()
>      vprintk_alt()
> 
> but there are some that can't be handled solely in printk.c

Do you have an example of the still problematic code, please?
vprintk_alt() must be lockless because the same code is used
also in NMI context. If it takes a lock, it is a bug.
Therefore it should not cause a deadlock.

The only problem might be an infinite loop. But the loop should
break once the per-CPU buffer is full. We only need to make sure
that there is no printk() called before the check for the full
buffer. But this reduces the error-prone part of the code to
a minimum. Therefore it should be bearable.

Best Regards,
Petr

[toc] | [prev] | [standalone]

Page 2 of 2 — ← Prev page 1 [2]

Back to top | Article view | linux.kernel

csiph-web