Re: [RFC][PATCH 0/4] printk: introduce printing kernel thread
On Mon 2017-04-03 20:53:11, Sergey Senozhatsky wrote:
> On (03/06/17 21:45), Sergey Senozhatsky wrote:
> [..]
> > printk kthread changes the behavior of printk in one _corner case_.
> > The corner case is quite interesting and actually consists of two corner
> > cases. Suppose on SMP system there is only one CPU that printk()-s a lot,
> > the rest of CPUs don't lock console_sem and don't printk(). Previously
> > that printing CPU had been throttling itself (*) because of console drivers
> > call for every printk():
> >
> > CPU0
> >
> >printk("a")
> > console_unlock()
> > call_console_drivers("a")
> >
> > ...
> >
> >printk("z")
> > console_unlock()
> > call_console_drivers("z")
> >
> > * Given that no other CPU locks the console_sem.
> >
> > With printk kthread the case turns into this one:
> >
> > CPU0 CPU1
> >
> >printk("a")
> >wake_up printk_kthread
> >... printk_kthread
> >printk("k")console_unlock()
> >... call_console_drivers("a")
> >printk("z") call_console_drivers("b")
> >call_console_drivers("c")
> >...
> >
> >
> > The second 'corner case' part here is that CPU0 may be much faster
> > than printing CPU, which may result in dropped printk messages.
> >
> > This all is absolutely possible even with out the printk-kthread.
> > A single console_lock() call from CPUx will result in exactly the
> > same condition. So it's not necessarily a regression. But there may
> > be some scenarios in the kernel that may suffer from this change.
> > From the top of my head -- sysrq backtrace dump, and, probably, OOM
> > print out and backtrace dump.
>
> there is another possibility here.
>
> being always reschedulable potentially can put us at risk of having
> unpleasant situations when printk_kthread is getting preempted too
> often (well, who knows what can happen on the system), which can slow
> down logbuf emit process (printk_kthread) up to the point when printk()
> CPUs will force log_store() to begin dropping the messages. this can
> happen.
I believe that this will be rather a corner case. If it happens, we
could do something with scheduling priority and policy. Also there
is the possibility to fallback to the old mode.
We use some variants of the printk offload on SLE for years and
I am not aware of any complains of this sort.
Best Regards,
Petr
Re: [RFC][PATCH 0/4] printk: introduce printing kernel thread
On Mon 2017-04-03 20:53:11, Sergey Senozhatsky wrote:
> On (03/06/17 21:45), Sergey Senozhatsky wrote:
> [..]
> > printk kthread changes the behavior of printk in one _corner case_.
> > The corner case is quite interesting and actually consists of two corner
> > cases. Suppose on SMP system there is only one CPU that printk()-s a lot,
> > the rest of CPUs don't lock console_sem and don't printk(). Previously
> > that printing CPU had been throttling itself (*) because of console drivers
> > call for every printk():
> >
> > CPU0
> >
> >printk("a")
> > console_unlock()
> > call_console_drivers("a")
> >
> > ...
> >
> >printk("z")
> > console_unlock()
> > call_console_drivers("z")
> >
> > * Given that no other CPU locks the console_sem.
> >
> > With printk kthread the case turns into this one:
> >
> > CPU0 CPU1
> >
> >printk("a")
> >wake_up printk_kthread
> >... printk_kthread
> >printk("k")console_unlock()
> >... call_console_drivers("a")
> >printk("z") call_console_drivers("b")
> >call_console_drivers("c")
> >...
> >
> >
> > The second 'corner case' part here is that CPU0 may be much faster
> > than printing CPU, which may result in dropped printk messages.
> >
> > This all is absolutely possible even with out the printk-kthread.
> > A single console_lock() call from CPUx will result in exactly the
> > same condition. So it's not necessarily a regression. But there may
> > be some scenarios in the kernel that may suffer from this change.
> > From the top of my head -- sysrq backtrace dump, and, probably, OOM
> > print out and backtrace dump.
>
> there is another possibility here.
>
> being always reschedulable potentially can put us at risk of having
> unpleasant situations when printk_kthread is getting preempted too
> often (well, who knows what can happen on the system), which can slow
> down logbuf emit process (printk_kthread) up to the point when printk()
> CPUs will force log_store() to begin dropping the messages. this can
> happen.
I believe that this will be rather a corner case. If it happens, we
could do something with scheduling priority and policy. Also there
is the possibility to fallback to the old mode.
We use some variants of the printk offload on SLE for years and
I am not aware of any complains of this sort.
Best Regards,
Petr
Re: [RFC][PATCH 0/4] printk: introduce printing kernel thread
On (03/06/17 21:45), Sergey Senozhatsky wrote:
[..]
> printk kthread changes the behavior of printk in one _corner case_.
> The corner case is quite interesting and actually consists of two corner
> cases. Suppose on SMP system there is only one CPU that printk()-s a lot,
> the rest of CPUs don't lock console_sem and don't printk(). Previously
> that printing CPU had been throttling itself (*) because of console drivers
> call for every printk():
>
> CPU0
>
>printk("a")
> console_unlock()
> call_console_drivers("a")
>
> ...
>
>printk("z")
> console_unlock()
> call_console_drivers("z")
>
> * Given that no other CPU locks the console_sem.
>
> With printk kthread the case turns into this one:
>
> CPU0 CPU1
>
>printk("a")
>wake_up printk_kthread
>... printk_kthread
>printk("k")console_unlock()
>... call_console_drivers("a")
>printk("z") call_console_drivers("b")
>call_console_drivers("c")
>...
>
>
> The second 'corner case' part here is that CPU0 may be much faster
> than printing CPU, which may result in dropped printk messages.
>
> This all is absolutely possible even with out the printk-kthread.
> A single console_lock() call from CPUx will result in exactly the
> same condition. So it's not necessarily a regression. But there may
> be some scenarios in the kernel that may suffer from this change.
> From the top of my head -- sysrq backtrace dump, and, probably, OOM
> print out and backtrace dump.
there is another possibility here.
being always reschedulable potentially can put us at risk of having
unpleasant situations when printk_kthread is getting preempted too
often (well, who knows what can happen on the system), which can slow
down logbuf emit process (printk_kthread) up to the point when printk()
CPUs will force log_store() to begin dropping the messages. this can
happen.
-ss
Re: [RFC][PATCH 0/4] printk: introduce printing kernel thread
On (03/06/17 21:45), Sergey Senozhatsky wrote:
[..]
> printk kthread changes the behavior of printk in one _corner case_.
> The corner case is quite interesting and actually consists of two corner
> cases. Suppose on SMP system there is only one CPU that printk()-s a lot,
> the rest of CPUs don't lock console_sem and don't printk(). Previously
> that printing CPU had been throttling itself (*) because of console drivers
> call for every printk():
>
> CPU0
>
>printk("a")
> console_unlock()
> call_console_drivers("a")
>
> ...
>
>printk("z")
> console_unlock()
> call_console_drivers("z")
>
> * Given that no other CPU locks the console_sem.
>
> With printk kthread the case turns into this one:
>
> CPU0 CPU1
>
>printk("a")
>wake_up printk_kthread
>... printk_kthread
>printk("k")console_unlock()
>... call_console_drivers("a")
>printk("z") call_console_drivers("b")
>call_console_drivers("c")
>...
>
>
> The second 'corner case' part here is that CPU0 may be much faster
> than printing CPU, which may result in dropped printk messages.
>
> This all is absolutely possible even with out the printk-kthread.
> A single console_lock() call from CPUx will result in exactly the
> same condition. So it's not necessarily a regression. But there may
> be some scenarios in the kernel that may suffer from this change.
> From the top of my head -- sysrq backtrace dump, and, probably, OOM
> print out and backtrace dump.
there is another possibility here.
being always reschedulable potentially can put us at risk of having
unpleasant situations when printk_kthread is getting preempted too
often (well, who knows what can happen on the system), which can slow
down logbuf emit process (printk_kthread) up to the point when printk()
CPUs will force log_store() to begin dropping the messages. this can
happen.
-ss
Re: [RFC][PATCH 0/4] printk: introduce printing kernel thread
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
Re: [RFC][PATCH 0/4] printk: introduce printing kernel thread
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
Re: [RFC][PATCH 0/4] printk: introduce printing kernel thread
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
Re: [RFC][PATCH 0/4] printk: introduce printing kernel thread
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
Re: [RFC][PATCH 0/4] printk: introduce printing kernel thread
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, _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
Re: [RFC][PATCH 0/4] printk: introduce printing kernel thread
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, _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
Re: [RFC][PATCH 0/4] printk: introduce printing kernel thread
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
Re: [RFC][PATCH 0/4] printk: introduce printing kernel thread
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
Re: [RFC][PATCH 0/4] printk: introduce printing kernel thread
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.oflvtfjsqfo...@i-love.sakura.ne.jp Best Regards, Petr
Re: [RFC][PATCH 0/4] printk: introduce printing kernel thread
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.oflvtfjsqfo...@i-love.sakura.ne.jp Best Regards, Petr
Re: [RFC][PATCH 0/4] printk: introduce printing kernel thread
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.
Re: [RFC][PATCH 0/4] printk: introduce printing kernel thread
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.
Re: [RFC][PATCH 0/4] printk: introduce printing kernel thread
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
#include
#include
+#include
#include
#include
@@ -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(_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
Re: [RFC][PATCH 0/4] printk: introduce printing kernel thread
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
#include
#include
+#include
#include
#include
@@ -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(_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
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.
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.
