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

Groups > linux.kernel > #1606904 > unrolled thread

Re: [RFC][PATCH 0/4] printk: introduce printing kernel thread

Back to article view | Back to linux.kernel

This discussion starts older than the indexed window; earlier articles aren't shown. The article labeled Started by below is the oldest one visible, not the original post.

Contents

  Re: [RFC][PATCH 0/4] printk: introduce printing kernel thread Peter Zijlstra <peterz@infradead.org> - 2017-03-22 19:50 +0100
    Re: [RFC][PATCH 0/4] printk: introduce printing kernel thread Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> - 2017-03-23 05:20 +0100
      Re: [RFC][PATCH 0/4] printk: introduce printing kernel thread Peter Zijlstra <peterz@infradead.org> - 2017-03-23 10:00 +0100
        Re: [RFC][PATCH 0/4] printk: introduce printing kernel thread Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> - 2017-03-24 03:00 +0100
          Re: [RFC][PATCH 0/4] printk: introduce printing kernel thread Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> - 2017-03-24 05:50 +0100
          Re: [RFC][PATCH 0/4] printk: introduce printing kernel thread Petr Mladek <pmladek@suse.com> - 2017-03-24 15:50 +0100
            Re: [RFC][PATCH 0/4] printk: introduce printing kernel thread Sergey Senozhatsky <sergey.senozhatsky@gmail.com> - 2017-03-25 01:30 +0100
    Re: [RFC][PATCH 0/4] printk: introduce printing kernel thread Petr Mladek <pmladek@suse.com> - 2017-03-23 13:10 +0100

#1606904 — Re: [RFC][PATCH 0/4] printk: introduce printing kernel thread

On Mon, Mar 06, 2017 at 09:45:50PM +0900, Sergey Senozhatsky wrote:
>  sysrq is potentially even trickier. can we always wake_up() kernel
>  thread from sysrq? there probably might be cases when we can't rely
>  on the scheduler.

sysrq runs from interrupt context, right? Should be able to do wakeups.

[toc] | [next] | [standalone]

#1607170

Hello Peter,

thanks for taking a look.

On (03/22/17 18:59), Peter Zijlstra wrote:
> On Mon, Mar 06, 2017 at 09:45:50PM +0900, Sergey Senozhatsky wrote:
> >  sysrq is potentially even trickier. can we always wake_up() kernel
> >  thread from sysrq? there probably might be cases when we can't rely
> >  on the scheduler.
> 
> sysrq runs from interrupt context, right? Should be able to do wakeups.

what I though about was -
	what if there are 'misbehaving' higher prio tasks all the time?
	the existing sysrq would attempt to do printing from irq context
	so it doesn't care about run queues.

does it make sense to you?

so what I have currently is something like this:
(not so sure about sysrq_handle_showstate_blocked())

---
 drivers/tty/sysrq.c | 7 +++++++
 1 file changed, 7 insertions(+)

diff --git a/drivers/tty/sysrq.c b/drivers/tty/sysrq.c
index c6fc7141d7b2..f0d2684fa99c 100644
--- a/drivers/tty/sysrq.c
+++ b/drivers/tty/sysrq.c
@@ -49,6 +49,7 @@
 #include <linux/syscalls.h>
 #include <linux/of.h>
 #include <linux/rcupdate.h>
+#include <linux/console.h>
 
 #include <asm/ptrace.h>
 #include <asm/irq_regs.h>
@@ -239,6 +240,7 @@ static DECLARE_WORK(sysrq_showallcpus, sysrq_showregs_othercpus);
 
 static void sysrq_handle_showallcpus(int key)
 {
+	console_printing_thread_off();
 	/*
 	 * Fall back to the workqueue based printing if the
 	 * backtrace printing did not succeed or the
@@ -253,6 +255,7 @@ static void sysrq_handle_showallcpus(int key)
 		}
 		schedule_work(&sysrq_showallcpus);
 	}
+	console_printing_thread_on();
 }
 
 static struct sysrq_key_op sysrq_showallcpus_op = {
@@ -279,8 +282,10 @@ static struct sysrq_key_op sysrq_showregs_op = {
 
 static void sysrq_handle_showstate(int key)
 {
+	console_printing_thread_off();
 	show_state();
 	show_workqueue_state();
+	console_printing_thread_on();
 }
 static struct sysrq_key_op sysrq_showstate_op = {
 	.handler	= sysrq_handle_showstate,
@@ -291,7 +296,9 @@ static struct sysrq_key_op sysrq_showstate_op = {
 
 static void sysrq_handle_showstate_blocked(int key)
 {
+	console_printing_thread_off();
 	show_state_filter(TASK_UNINTERRUPTIBLE);
+	console_printing_thread_on();
 }
 static struct sysrq_key_op sysrq_showstate_blocked_op = {
 	.handler	= sysrq_handle_showstate_blocked,
-- 
2.12.1

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

#1607263

On Thu, Mar 23, 2017 at 01:09:58PM +0900, Sergey Senozhatsky wrote:
> Hello Peter,
> 
> thanks for taking a look.
> 
> On (03/22/17 18:59), Peter Zijlstra wrote:
> > On Mon, Mar 06, 2017 at 09:45:50PM +0900, Sergey Senozhatsky wrote:
> > >  sysrq is potentially even trickier. can we always wake_up() kernel
> > >  thread from sysrq? there probably might be cases when we can't rely
> > >  on the scheduler.
> > 
> > sysrq runs from interrupt context, right? Should be able to do wakeups.
> 
> what I though about was -
> 	what if there are 'misbehaving' higher prio tasks all the time?
> 	the existing sysrq would attempt to do printing from irq context
> 	so it doesn't care about run queues.
> 
> does it make sense to you?

Ah, that's what you meant. Yeah, dunno, I'm still unconvinced about the
whole printk thread thing. Also those function names are horrifically
long.

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

#1608070

On (03/23/17 09:51), Peter Zijlstra wrote:
[..]
> > > sysrq runs from interrupt context, right? Should be able to do wakeups.
> > 
> > what I though about was -
> > 	what if there are 'misbehaving' higher prio tasks all the time?
> > 	the existing sysrq would attempt to do printing from irq context
> > 	so it doesn't care about run queues.
> > 
> > does it make sense to you?
> 
> Ah, that's what you meant. Yeah, dunno, I'm still unconvinced about the
> whole printk thread thing.

I see your point.
but I can't think of alternatives that would fix all those lockups and
stalls and at the same time have better guarantees than printk_kthread.


> Also those function names are horrifically long.

right. not happy with the naming either.

so what I'm thinking about right now is:

we have that thing which we call "old printk" mode, which is not
really informative. and my proposal is rename "old" mode and use
"printk rescue" mode instead. because we switch to that mode when
we are trying to "rescue" kernel logs. so the API can be something
like
		printk_rescue_on()
		printk_rescue_off()

opinions?



--- random thoughts ---

another thing that bothers me a bit is that we need to place those
printk_rescue_on/printk_rescue_off switches all over the kernel.
sort of a root cause [in some of the cases] here is the fact that
we don't have any feedback from printk_kthread in vprintk_emit():
	does printk_kthread make any progress?
	do we flush messages to the serial console?
	etc.

and we've got everything we need to have such a feedback in
vprintk_emit():

	a) console is not suspended so console_unlock() can call console drivers
	b) printk_kthread != NULL
	c) we are not in enforced rescue/emergency mode
	d) `log_next_seq' moves forward (always `true', we are in vprintk_emit())
	e) `console_seq' stands still

so we can have an automatic rescue mode fallback in vprintk_emit().
if (a)-(e) are true then we give up on waking up printk_kthread,
switch to rescue mode and attempt to console_trylock() directly from
vprintk_emit(). the part that sucks here is that we need to give
printk_kthread some time to catch up. for instance, if (e) is true
for the past 50 invocations of vprintk_emit(), IOW:

	- we added 50 lines to printk
	- none have been printed on the serial console

then we
	- declare rescue
	- do console_trylock() instead of wake_up() //unless in deferred vprintk_emit()


50 is completely made up. can be 100, or 10, or anything else.


and we can jump between rescue-normal printk modes, so this should
also return back the throttling of tasks which printk() a lot (item
(2) in patch set cover letter) that we used to have.


thoughts?

	-ss

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

#1608121

On (03/24/17 10:59), Sergey Senozhatsky wrote:
[..]
> and we can jump between rescue-normal printk modes, so this should
> also return back the throttling of tasks which printk() a lot (item
> (2) in patch set cover letter) that we used to have.

ok, I obviously lied here "this should also return back the throttling".
throttling is a bit hard to implement properly.


automatic printk rescue mode on console output stall [when we can't
wake_up printk_kthread] is not so difficult. something like below.

may be it's too simple minded. // it does not handle throttling.


---
 kernel/printk/printk.c | 15 ++++++++++++++-
 1 file changed, 14 insertions(+), 1 deletion(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index e84b9fbb298f..005741486376 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -447,6 +447,12 @@ static char __log_buf[__LOG_BUF_LEN] __aligned(LOG_ALIGN);
 static char *log_buf = __log_buf;
 static u32 log_buf_len = __LOG_BUF_LEN;
 
+/*
+ * How many pending messages we can have in the logbuf before we
+ * switch to printk rescue mode (stop waking up printk_kthread).
+ */
+#define CONSOLE_STALL_MESSAGES_LIMIT	50
+
 static struct task_struct *printk_kthread __read_mostly;
 /*
  * We can't call into the scheduler (wake_up() printk kthread) during
@@ -1739,6 +1745,11 @@ static size_t log_output(int facility, int level, enum log_flags lflags, const c
 	return log_store(facility, level, lflags, 0, dict, dictlen, text, text_len);
 }
 
+static bool console_output_stall(void)
+{
+	return (log_next_seq - console_seq) > CONSOLE_STALL_MESSAGES_LIMIT;
+}
+
 asmlinkage int vprintk_emit(int facility, int level,
 			    const char *dict, size_t dictlen,
 			    const char *fmt, va_list args)
@@ -1750,6 +1761,7 @@ asmlinkage int vprintk_emit(int facility, int level,
 	unsigned long flags;
 	int printed_len = 0;
 	bool in_sched = false;
+	bool printk_stall;
 
 	if (level == LOGLEVEL_SCHED) {
 		level = LOGLEVEL_DEFAULT;
@@ -1811,6 +1823,7 @@ asmlinkage int vprintk_emit(int facility, int level,
 
 	printed_len += log_output(facility, level, lflags, dict, dictlen, text, text_len);
 
+	printk_stall = console_output_stall();
 	set_bit(PRINTK_PENDING_OUTPUT, &printk_pending);
 	logbuf_unlock_irqrestore(flags);
 
@@ -1824,7 +1837,7 @@ asmlinkage int vprintk_emit(int facility, int level,
 		 * from a dedicated printk_kthread, which always runs in
 		 * schedulable context.
 		 */
-		if (printk_kthread_enabled()) {
+		if (!printk_stall && printk_kthread_enabled()) {
 			printk_safe_enter_irqsave(flags);
 			wake_up_process(printk_kthread);
 			printk_safe_exit_irqrestore(flags);
-- 
2.12.1

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

#1608507

On Fri 2017-03-24 10:59:36, Sergey Senozhatsky wrote:
> On (03/23/17 09:51), Peter Zijlstra wrote:
> [..]
> > > > sysrq runs from interrupt context, right? Should be able to do wakeups.
> > > 
> > > what I though about was -
> > > 	what if there are 'misbehaving' higher prio tasks all the time?
> > > 	the existing sysrq would attempt to do printing from irq context
> > > 	so it doesn't care about run queues.
> > > 
> > > does it make sense to you?
> > 
> > Ah, that's what you meant. Yeah, dunno, I'm still unconvinced about the
> > whole printk thread thing.
> 
> I see your point.
> but I can't think of alternatives that would fix all those lockups and
> stalls and at the same time have better guarantees than printk_kthread.
> 
> 
> > Also those function names are horrifically long.
> 
> right. not happy with the naming either.
> 
> so what I'm thinking about right now is:
> 
> we have that thing which we call "old printk" mode, which is not
> really informative. and my proposal is rename "old" mode and use
> "printk rescue" mode instead. because we switch to that mode when
> we are trying to "rescue" kernel logs. so the API can be something
> like
> 		printk_rescue_on()
> 		printk_rescue_off()

Sounds good to me. Slight problem is that off() does not cause
stopping the mode if we are nested.

Just one more attempt inspired by this:

		printk_emergency_begin()
		printk_emergency_end()

Note that we actually start this mode automatically also
with pr_emerg() message.

But I am fine with whatever from the mentioned generic names.

> 
> --- random thoughts ---
> 
> another thing that bothers me a bit is that we need to place those
> printk_rescue_on/printk_rescue_off switches all over the kernel.
> sort of a root cause [in some of the cases] here is the fact that
> we don't have any feedback from printk_kthread in vprintk_emit():
> 	does printk_kthread make any progress?
> 	do we flush messages to the serial console?
> 	etc.
> 
> and we've got everything we need to have such a feedback in
> vprintk_emit():
> 
> 	a) console is not suspended so console_unlock() can call console drivers
> 	b) printk_kthread != NULL
> 	c) we are not in enforced rescue/emergency mode
> 	d) `log_next_seq' moves forward (always `true', we are in vprintk_emit())
> 	e) `console_seq' stands still
> 
> so we can have an automatic rescue mode fallback in vprintk_emit().
> if (a)-(e) are true then we give up on waking up printk_kthread,
> switch to rescue mode and attempt to console_trylock() directly from
> vprintk_emit(). the part that sucks here is that we need to give
> printk_kthread some time to catch up. for instance, if (e) is true
> for the past 50 invocations of vprintk_emit(), IOW:
> 
> 	- we added 50 lines to printk
> 	- none have been printed on the serial console
>
> then we
> 	- declare rescue
> 	- do console_trylock() instead of wake_up() //unless in deferred vprintk_emit()

I am not sure if we are able to distinguish a flood of messages
from a real emergency situation.

If we start flushing messages directly when there is a flood
of messages, we will put back the original problem with soft
lookups.

Well, there is a handful of annotated locations at the moment.
I would start thinking of an automatic detection once we have
more of them and have more data for a good heuristic.

I still would like to see the kernel parameter/sysfs knob
that would allow to force the rescue/emergency mode all
the time ;-)

Best Regards,
Petr

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

#1609042

On (03/24/17 15:43), Petr Mladek wrote:
[..]
> > we have that thing which we call "old printk" mode, which is not
> > really informative. and my proposal is rename "old" mode and use
> > "printk rescue" mode instead. because we switch to that mode when
> > we are trying to "rescue" kernel logs. so the API can be something
> > like
> > 		printk_rescue_on()
> > 		printk_rescue_off()
> 
> Sounds good to me. Slight problem is that off() does not cause
> stopping the mode if we are nested.
> 
> Just one more attempt inspired by this:
> 
> 		printk_emergency_begin()
> 		printk_emergency_end()
> 
> Note that we actually start this mode automatically also
> with pr_emerg() message.

good. printk_emergency sounds OK to me.

[..]
> > and we've got everything we need to have such a feedback in
> > vprintk_emit():
> > 
> > 	a) console is not suspended so console_unlock() can call console drivers
> > 	b) printk_kthread != NULL
> > 	c) we are not in enforced rescue/emergency mode
> > 	d) `log_next_seq' moves forward (always `true', we are in vprintk_emit())
> > 	e) `console_seq' stands still
> > 
> > so we can have an automatic rescue mode fallback in vprintk_emit().
> > if (a)-(e) are true then we give up on waking up printk_kthread,
> > switch to rescue mode and attempt to console_trylock() directly from
> > vprintk_emit(). the part that sucks here is that we need to give
> > printk_kthread some time to catch up. for instance, if (e) is true
> > for the past 50 invocations of vprintk_emit(), IOW:
> > 
> > 	- we added 50 lines to printk
> > 	- none have been printed on the serial console
> >
> > then we
> > 	- declare rescue
> > 	- do console_trylock() instead of wake_up() //unless in deferred vprintk_emit()
> 
> I am not sure if we are able to distinguish a flood of messages
> from a real emergency situation.

that's one of problems. yes.


> Well, there is a handful of annotated locations at the moment.
> I would start thinking of an automatic detection once we have
> more of them and have more data for a good heuristic.

so my 'automatic emergency' switch is for another case. when we
wake_up() printk_kthread, but it never prints anything. could be
caused by a missing printk_emergency annotation, or something else.


> I still would like to see the kernel parameter/sysfs knob
> that would allow to force the rescue/emergency mode all
> the time ;-)

sure.

	-ss

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

#1607412

On Wed 2017-03-22 18:59:20, Peter Zijlstra wrote:
> On Mon, Mar 06, 2017 at 09:45:50PM +0900, Sergey Senozhatsky wrote:
> >  sysrq is potentially even trickier. can we always wake_up() kernel
> >  thread from sysrq? there probably might be cases when we can't rely
> >  on the scheduler.
> 
> sysrq runs from interrupt context, right? Should be able to do wakeups.

It would make sense to actually switch to the old mode when
handling sysrq. At least for some requests that are used
for debugging when the system is not responsible.

It is pity that it is the irq context that is prone to
softlocks. But this might be the only way to actually
see the messages.

Tetsuo already suggested to use the old mode for SysRq-t, see
https://lkml.kernel.org/r/201612261954.FJE69201.OFLVtFJSQFOHMO@I-love.SAKURA.ne.jp

Best Regards,
Petr

[toc] | [prev] | [standalone]

Back to top | Article view | linux.kernel

csiph-web