linux-kernel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* [RFC][PATCH 1/2] printk: Introduce per-console filtering of messages by loglevel
@ 2017-04-04 23:02 Calvin Owens
  2017-04-04 23:03 ` [RFC][PATCH 2/2] printk: Add /sys/consoles/${con}/ and maxlevel attribute Calvin Owens
                   ` (2 more replies)
  0 siblings, 3 replies; 13+ messages in thread
From: Calvin Owens @ 2017-04-04 23:02 UTC (permalink / raw)
  To: Petr Mladek, Sergey Senozhatsky, Steven Rostedt
  Cc: Greg Kroah-Hartman, Jiri Slaby, Andrew Morton, Calvin Owens,
	Manuel Schölling, Hans de Goede, Paul Burton, linux-kernel,
	kernel-team

Not all consoles are created equal: depending on the actual hardware,
the latency of a printk() call can vary dramatically. The worst examples
are serial consoles, where it can spin for tens of milliseconds banging
the UART to emit a message, which can cause application-level problems
when the kernel spews onto the console.

At Facebook we use netconsole to monitor our fleet, but we still have
serial consoles attached on each host for live debugging, and the latter
has caused problems. An obvious solution is to disable the kernel
console output to ttyS0, but this makes live debugging frustrating,
since crashes become silent and opaque to the ttyS0 user. Enabling it on
the fly when needed isn't feasible, since boxes you need to debug via
serial are likely to be borked in ways that make this impossible.

This puts us between a rock and a hard place: we'd love to set
kernel.printk to KERN_INFO and get all the logs. But while netconsole is
fast enough to permit that without perturbing userspace, ttyS0 is not,
and we're forced to limit console logging to KERN_WARNING and higher.

This patch lets us have our cake and eat it too: instead of being forced
to limit all consoles verbosity based on the speed of the slowest one,
we can limit each based on its own speed. A subsequent patch will
introduce a simple sysfs interface for changing this setting.

Signed-off-by: Calvin Owens <calvinowens@fb.com>
---
 include/linux/console.h |  1 +
 kernel/printk/printk.c  | 13 ++++++++++---
 2 files changed, 11 insertions(+), 3 deletions(-)

diff --git a/include/linux/console.h b/include/linux/console.h
index 5949d18..764a2c0 100644
--- a/include/linux/console.h
+++ b/include/linux/console.h
@@ -147,6 +147,7 @@ struct console {
 	int	cflag;
 	void	*data;
 	struct	 console *next;
+	int	maxlevel;
 };
 
 /*
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 2984fb0..5393928 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -1562,7 +1562,7 @@ SYSCALL_DEFINE3(syslog, int, type, char __user *, buf, int, len)
  * The console_lock must be held.
  */
 static void call_console_drivers(const char *ext_text, size_t ext_len,
-				 const char *text, size_t len)
+				 const char *text, size_t len, int level)
 {
 	struct console *con;
 
@@ -1581,6 +1581,8 @@ static void call_console_drivers(const char *ext_text, size_t ext_len,
 		if (!cpu_online(smp_processor_id()) &&
 		    !(con->flags & CON_ANYTIME))
 			continue;
+		if (level > con->maxlevel)
+			continue;
 		if (con->flags & CON_EXTENDED)
 			con->write(con, ext_text, ext_len);
 		else
@@ -1869,7 +1871,7 @@ static ssize_t msg_print_ext_body(char *buf, size_t size,
 				  char *dict, size_t dict_len,
 				  char *text, size_t text_len) { return 0; }
 static void call_console_drivers(const char *ext_text, size_t ext_len,
-				 const char *text, size_t len) {}
+				 const char *text, size_t len, int level) {}
 static size_t msg_print_text(const struct printk_log *msg,
 			     bool syslog, char *buf, size_t size) { return 0; }
 static bool suppress_message_printing(int level) { return false; }
@@ -2238,7 +2240,7 @@ void console_unlock(void)
 		raw_spin_unlock(&logbuf_lock);
 
 		stop_critical_timings();	/* don't trace print latency */
-		call_console_drivers(ext_text, ext_len, text, len);
+		call_console_drivers(ext_text, ext_len, text, len, msg->level);
 		start_critical_timings();
 		printk_safe_exit_irqrestore(flags);
 
@@ -2504,6 +2506,11 @@ void register_console(struct console *newcon)
 		newcon->flags &= ~CON_PRINTBUFFER;
 
 	/*
+	 * By default, the per-console loglevel filter permits all messages.
+	 */
+	newcon->maxlevel = LOGLEVEL_DEBUG;
+
+	/*
 	 *	Put this console in the list - keep the
 	 *	preferred driver at the head of the list.
 	 */
-- 
2.9.3

^ permalink raw reply related	[flat|nested] 13+ messages in thread

* [RFC][PATCH 2/2] printk: Add /sys/consoles/${con}/ and maxlevel attribute
  2017-04-04 23:02 [RFC][PATCH 1/2] printk: Introduce per-console filtering of messages by loglevel Calvin Owens
@ 2017-04-04 23:03 ` Calvin Owens
  2017-04-05  3:30   ` Steven Rostedt
  2017-04-05  1:51 ` [RFC][PATCH 1/2] printk: Introduce per-console filtering of messages by loglevel Joe Perches
  2017-04-05  2:08 ` Sergey Senozhatsky
  2 siblings, 1 reply; 13+ messages in thread
From: Calvin Owens @ 2017-04-04 23:03 UTC (permalink / raw)
  To: Petr Mladek, Sergey Senozhatsky, Steven Rostedt
  Cc: Greg Kroah-Hartman, Jiri Slaby, Andrew Morton, Calvin Owens,
	Manuel Schölling, Hans de Goede, Paul Burton, linux-kernel,
	kernel-team

This does the simplest possible thing: add a directory at the root of
sysfs that allows setting the "maxlevel" parameter for each console.

We can let kobject destruction race with console removal: if it does,
maxlevel_{show,store}() will safely fail with -ENODEV. This is a little
weird, but avoids embedding the kobject and therefore needing to totally
refactor the way we handle console struct lifetime.

Signed-off-by: Calvin Owens <calvinowens@fb.com>
---
 include/linux/console.h |  1 +
 kernel/printk/printk.c  | 82 +++++++++++++++++++++++++++++++++++++++++++++++++
 2 files changed, 83 insertions(+)

diff --git a/include/linux/console.h b/include/linux/console.h
index 764a2c0..c76fde0 100644
--- a/include/linux/console.h
+++ b/include/linux/console.h
@@ -148,6 +148,7 @@ struct console {
 	void	*data;
 	struct	 console *next;
 	int	maxlevel;
+	struct kobject *kobj;
 };
 
 /*
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 5393928..e9d036b 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -105,6 +105,8 @@ enum devkmsg_log_masks {
 
 static unsigned int __read_mostly devkmsg_log = DEVKMSG_LOG_MASK_DEFAULT;
 
+static struct kobject *consoles_dir_kobj;
+
 static int __control_devkmsg(char *str)
 {
 	if (!str)
@@ -2386,6 +2388,76 @@ static int __init keep_bootcon_setup(char *str)
 
 early_param("keep_bootcon", keep_bootcon_setup);
 
+static ssize_t maxlevel_show(struct kobject *kobj, struct kobj_attribute *attr,
+                             char *buf)
+{
+	struct console *con;
+	ssize_t ret = -ENODEV;
+
+	console_lock();
+	for_each_console(con) {
+		if (con->kobj == kobj) {
+			ret = sprintf(buf, "%d\n", con->maxlevel);
+			break;
+		}
+	}
+	console_unlock();
+
+	return ret;
+}
+
+static ssize_t maxlevel_store(struct kobject *kobj, struct kobj_attribute *attr,
+                              const char *buf, size_t count)
+{
+	struct console *con;
+	ssize_t ret;
+	int tmp;
+
+	ret = kstrtoint(buf, 10, &tmp);
+	if (ret < 0)
+		return ret;
+
+	if (tmp < 0 || tmp > LOGLEVEL_DEBUG)
+		return -ERANGE;
+
+	ret = -ENODEV;
+	console_lock();
+	for_each_console(con) {
+		if (con->kobj == kobj) {
+			con->maxlevel = tmp;
+			ret = count;
+			break;
+		}
+	}
+	console_unlock();
+
+	return ret;
+}
+
+static const struct kobj_attribute console_level_attr =
+	__ATTR(maxlevel, 0644, maxlevel_show, maxlevel_store);
+
+static void console_register_sysfs(struct console *newcon)
+{
+	/*
+	 * We might be called very early from register_console(): in that case,
+	 * printk_late_init() will take care of this later.
+	 */
+	if (!consoles_dir_kobj)
+		return;
+
+	newcon->kobj = kobject_create_and_add(newcon->name, consoles_dir_kobj);
+	if (WARN_ON(!newcon->kobj))
+		return;
+
+	WARN_ON(sysfs_create_file(newcon->kobj, &console_level_attr.attr));
+}
+
+static void console_unregister_sysfs(struct console *oldcon)
+{
+	kobject_put(oldcon->kobj);
+}
+
 /*
  * The console driver calls this routine during kernel initialization
  * to register the console printing procedure with printk() and to
@@ -2509,6 +2581,7 @@ void register_console(struct console *newcon)
 	 * By default, the per-console loglevel filter permits all messages.
 	 */
 	newcon->maxlevel = LOGLEVEL_DEBUG;
+	newcon->kobj = NULL;
 
 	/*
 	 *	Put this console in the list - keep the
@@ -2545,6 +2618,7 @@ void register_console(struct console *newcon)
 		 */
 		exclusive_console = newcon;
 	}
+	console_register_sysfs(newcon);
 	console_unlock();
 	console_sysfs_notify();
 
@@ -2611,6 +2685,7 @@ int unregister_console(struct console *console)
 		console_drivers->flags |= CON_CONSDEV;
 
 	console->flags &= ~CON_ENABLED;
+	console_unregister_sysfs(console);
 	console_unlock();
 	console_sysfs_notify();
 	return res;
@@ -2656,6 +2731,13 @@ static int __init printk_late_init(void)
 	ret = cpuhp_setup_state_nocalls(CPUHP_AP_ONLINE_DYN, "printk:online",
 					console_cpu_notify, NULL);
 	WARN_ON(ret < 0);
+
+	consoles_dir_kobj = kobject_create_and_add("consoles", NULL);
+	WARN_ON(!consoles_dir_kobj);
+
+	for_each_console(con)
+		console_register_sysfs(con);
+
 	return 0;
 }
 late_initcall(printk_late_init);
-- 
2.9.3

^ permalink raw reply related	[flat|nested] 13+ messages in thread

* Re: [RFC][PATCH 1/2] printk: Introduce per-console filtering of messages by loglevel
  2017-04-04 23:02 [RFC][PATCH 1/2] printk: Introduce per-console filtering of messages by loglevel Calvin Owens
  2017-04-04 23:03 ` [RFC][PATCH 2/2] printk: Add /sys/consoles/${con}/ and maxlevel attribute Calvin Owens
@ 2017-04-05  1:51 ` Joe Perches
  2017-04-05  2:08 ` Sergey Senozhatsky
  2 siblings, 0 replies; 13+ messages in thread
From: Joe Perches @ 2017-04-05  1:51 UTC (permalink / raw)
  To: Calvin Owens, Petr Mladek, Sergey Senozhatsky, Steven Rostedt
  Cc: Greg Kroah-Hartman, Jiri Slaby, Andrew Morton,
	Manuel Schölling, Hans de Goede, Paul Burton, linux-kernel,
	kernel-team

On Tue, 2017-04-04 at 16:02 -0700, Calvin Owens wrote:
> instead of being forced
> to limit all consoles verbosity based on the speed of the slowest one,
> we can limit each based on its own speed.

Seems sensible, thanks.

^ permalink raw reply	[flat|nested] 13+ messages in thread

* Re: [RFC][PATCH 1/2] printk: Introduce per-console filtering of messages by loglevel
  2017-04-04 23:02 [RFC][PATCH 1/2] printk: Introduce per-console filtering of messages by loglevel Calvin Owens
  2017-04-04 23:03 ` [RFC][PATCH 2/2] printk: Add /sys/consoles/${con}/ and maxlevel attribute Calvin Owens
  2017-04-05  1:51 ` [RFC][PATCH 1/2] printk: Introduce per-console filtering of messages by loglevel Joe Perches
@ 2017-04-05  2:08 ` Sergey Senozhatsky
  2017-04-05  2:16   ` Sergey Senozhatsky
  2 siblings, 1 reply; 13+ messages in thread
From: Sergey Senozhatsky @ 2017-04-05  2:08 UTC (permalink / raw)
  To: Calvin Owens
  Cc: Petr Mladek, Sergey Senozhatsky, Steven Rostedt,
	Greg Kroah-Hartman, Jiri Slaby, Andrew Morton,
	Manuel Schölling, Hans de Goede, Paul Burton, linux-kernel,
	kernel-team

On (04/04/17 16:02), Calvin Owens wrote:
[..]
>  static void call_console_drivers(const char *ext_text, size_t ext_len,
> -				 const char *text, size_t len)
> +				 const char *text, size_t len, int level)
>  {
>  	struct console *con;
>  
> @@ -1581,6 +1581,8 @@ static void call_console_drivers(const char *ext_text, size_t ext_len,
>  		if (!cpu_online(smp_processor_id()) &&
>  		    !(con->flags & CON_ANYTIME))
>  			continue;
> +		if (level > con->maxlevel)
> +			continue;
>  		if (con->flags & CON_EXTENDED)
>  			con->write(con, ext_text, ext_len);
>  		else
> @@ -1869,7 +1871,7 @@ static ssize_t msg_print_ext_body(char *buf, size_t size,
>  				  char *dict, size_t dict_len,
>  				  char *text, size_t text_len) { return 0; }
>  static void call_console_drivers(const char *ext_text, size_t ext_len,
> -				 const char *text, size_t len) {}
> +				 const char *text, size_t len, int level) {}
>  static size_t msg_print_text(const struct printk_log *msg,
>  			     bool syslog, char *buf, size_t size) { return 0; }
>  static bool suppress_message_printing(int level) { return false; }
> @@ -2238,7 +2240,7 @@ void console_unlock(void)
>  		raw_spin_unlock(&logbuf_lock);
>  
>  		stop_critical_timings();	/* don't trace print latency */
> -		call_console_drivers(ext_text, ext_len, text, len);
> +		call_console_drivers(ext_text, ext_len, text, len, msg->level);
>  		start_critical_timings();
>  		printk_safe_exit_irqrestore(flags);

ok, so the idea is quite clear and reasonable.


some thoughts,
we have a system-wide suppress_message_printing() loglevel filtering
in console_unlock() loop, which sets a limit on loglevel for all of
the messages - we don't even msg_print_text() if the message has
suppressible loglevel. and this implicitly restricts per-console
maxlevels.

console_unlock()
{
	for (;;) {
		...
skip:

		if (suppress_message_printing(msg->level))	// console_loglevel
			goto skip;

		call_console_drivers(msg->level)
			{
				if (level > con->maxlevel)	// con loglevel
					continue;
				...
			}
	}
}

this can be slightly confusing. what do you think?

	-ss

^ permalink raw reply	[flat|nested] 13+ messages in thread

* Re: [RFC][PATCH 1/2] printk: Introduce per-console filtering of messages by loglevel
  2017-04-05  2:08 ` Sergey Senozhatsky
@ 2017-04-05  2:16   ` Sergey Senozhatsky
  2017-04-05  3:27     ` Steven Rostedt
  2017-04-05 15:22     ` Petr Mladek
  0 siblings, 2 replies; 13+ messages in thread
From: Sergey Senozhatsky @ 2017-04-05  2:16 UTC (permalink / raw)
  To: Calvin Owens
  Cc: Petr Mladek, Steven Rostedt, Greg Kroah-Hartman, Jiri Slaby,
	Andrew Morton, Manuel Schölling, Hans de Goede, Paul Burton,
	linux-kernel, kernel-team, Sergey Senozhatsky,
	Sergey Senozhatsky

On (04/05/17 11:08), Sergey Senozhatsky wrote:
[..]
> >  		stop_critical_timings();	/* don't trace print latency */
> > -		call_console_drivers(ext_text, ext_len, text, len);
> > +		call_console_drivers(ext_text, ext_len, text, len, msg->level);
> >  		start_critical_timings();
> >  		printk_safe_exit_irqrestore(flags);
> 
> ok, so the idea is quite clear and reasonable.
> 
> 
> some thoughts,
> we have a system-wide suppress_message_printing() loglevel filtering
> in console_unlock() loop, which sets a limit on loglevel for all of
> the messages - we don't even msg_print_text() if the message has
> suppressible loglevel. and this implicitly restricts per-console
> maxlevels.
> 
> console_unlock()
> {
> 	for (;;) {
> 		...
> skip:
> 
> 		if (suppress_message_printing(msg->level))	// console_loglevel
> 			goto skip;
> 
> 		call_console_drivers(msg->level)
> 			{
> 				if (level > con->maxlevel)	// con loglevel
> 					continue;
> 				...
> 			}
> 	}
> }
> 
> this can be slightly confusing. what do you think?

one more thing.

this per-console filtering ignores... the "ignore_loglevel" param.

early_param("ignore_loglevel", ignore_loglevel_setup);
module_param(ignore_loglevel, bool, S_IRUGO | S_IWUSR);
MODULE_PARM_DESC(ignore_loglevel,
		 "ignore loglevel setting (prints all kernel messages to the console)");


my preference would be preserve "ignore_loglevel" behaviour. if
we are forced to 'ignore all loglevel filtering' then we should
do so.

	-ss

^ permalink raw reply	[flat|nested] 13+ messages in thread

* Re: [RFC][PATCH 1/2] printk: Introduce per-console filtering of messages by loglevel
  2017-04-05  2:16   ` Sergey Senozhatsky
@ 2017-04-05  3:27     ` Steven Rostedt
  2017-04-05 23:53       ` Calvin Owens
  2017-04-05 15:22     ` Petr Mladek
  1 sibling, 1 reply; 13+ messages in thread
From: Steven Rostedt @ 2017-04-05  3:27 UTC (permalink / raw)
  To: Sergey Senozhatsky
  Cc: Calvin Owens, Petr Mladek, Greg Kroah-Hartman, Jiri Slaby,
	Andrew Morton, Manuel Schölling, Hans de Goede, Paul Burton,
	linux-kernel, kernel-team, Sergey Senozhatsky

On Wed, 5 Apr 2017 11:16:28 +0900
Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> wrote:


> one more thing.
> 
> this per-console filtering ignores... the "ignore_loglevel" param.
> 
> early_param("ignore_loglevel", ignore_loglevel_setup);
> module_param(ignore_loglevel, bool, S_IRUGO | S_IWUSR);
> MODULE_PARM_DESC(ignore_loglevel,
> 		 "ignore loglevel setting (prints all kernel messages to the console)");
> 
> 
> my preference would be preserve "ignore_loglevel" behaviour. if
> we are forced to 'ignore all loglevel filtering' then we should
> do so.

Agreed.

-- Steve

^ permalink raw reply	[flat|nested] 13+ messages in thread

* Re: [RFC][PATCH 2/2] printk: Add /sys/consoles/${con}/ and maxlevel attribute
  2017-04-04 23:03 ` [RFC][PATCH 2/2] printk: Add /sys/consoles/${con}/ and maxlevel attribute Calvin Owens
@ 2017-04-05  3:30   ` Steven Rostedt
  2017-04-05 23:55     ` Calvin Owens
  0 siblings, 1 reply; 13+ messages in thread
From: Steven Rostedt @ 2017-04-05  3:30 UTC (permalink / raw)
  To: Calvin Owens
  Cc: Petr Mladek, Sergey Senozhatsky, Greg Kroah-Hartman, Jiri Slaby,
	Andrew Morton, Manuel Schölling, Hans de Goede, Paul Burton,
	linux-kernel, kernel-team

On Tue, 4 Apr 2017 16:03:20 -0700
Calvin Owens <calvinowens@fb.com> wrote:

> This does the simplest possible thing: add a directory at the root of
> sysfs that allows setting the "maxlevel" parameter for each console.
> 
> We can let kobject destruction race with console removal: if it does,
> maxlevel_{show,store}() will safely fail with -ENODEV. This is a little
> weird, but avoids embedding the kobject and therefore needing to totally
> refactor the way we handle console struct lifetime.

Can you also add a patch that allows this to be set on the kernel
command line, when the consoles are defined.

-- Steve

> 
> Signed-off-by: Calvin Owens <calvinowens@fb.com>

^ permalink raw reply	[flat|nested] 13+ messages in thread

* Re: [RFC][PATCH 1/2] printk: Introduce per-console filtering of messages by loglevel
  2017-04-05  2:16   ` Sergey Senozhatsky
  2017-04-05  3:27     ` Steven Rostedt
@ 2017-04-05 15:22     ` Petr Mladek
  2017-04-06  0:38       ` Calvin Owens
  1 sibling, 1 reply; 13+ messages in thread
From: Petr Mladek @ 2017-04-05 15:22 UTC (permalink / raw)
  To: Sergey Senozhatsky
  Cc: Calvin Owens, Steven Rostedt, Greg Kroah-Hartman, Jiri Slaby,
	Andrew Morton, Manuel Schölling, Hans de Goede, Paul Burton,
	linux-kernel, kernel-team, Sergey Senozhatsky

On Wed 2017-04-05 11:16:28, Sergey Senozhatsky wrote:
> On (04/05/17 11:08), Sergey Senozhatsky wrote:
> [..]
> > >  		stop_critical_timings();	/* don't trace print latency */
> > > -		call_console_drivers(ext_text, ext_len, text, len);
> > > +		call_console_drivers(ext_text, ext_len, text, len, msg->level);
> > >  		start_critical_timings();
> > >  		printk_safe_exit_irqrestore(flags);
> > 
> > ok, so the idea is quite clear and reasonable.
> > 
> > 
> > some thoughts,
> > we have a system-wide suppress_message_printing() loglevel filtering
> > in console_unlock() loop, which sets a limit on loglevel for all of
> > the messages - we don't even msg_print_text() if the message has
> > suppressible loglevel. and this implicitly restricts per-console
> > maxlevels.
> > 
> > console_unlock()
> > {
> > 	for (;;) {
> > 		...
> > skip:
> > 
> > 		if (suppress_message_printing(msg->level))	// console_loglevel
> > 			goto skip;
> > 
> > 		call_console_drivers(msg->level)
> > 			{
> > 				if (level > con->maxlevel)	// con loglevel
> > 					continue;
> > 				...
> > 			}
> > 	}
> > }
> > 
> > this can be slightly confusing. what do you think?
> 
> one more thing.
> 
> this per-console filtering ignores... the "ignore_loglevel" param.
> 
> early_param("ignore_loglevel", ignore_loglevel_setup);
> module_param(ignore_loglevel, bool, S_IRUGO | S_IWUSR);
> MODULE_PARM_DESC(ignore_loglevel,
> 		 "ignore loglevel setting (prints all kernel messages to the console)");
> 
> 
> my preference would be preserve "ignore_loglevel" behaviour. if
> we are forced to 'ignore all loglevel filtering' then we should
> do so.

I think about a reasonable behavior. There seems to be three variables
that are related and are in use:

     console_level
     minimum_console_loglevel
     ignore_loglevel

The functions seems to be the following:

  + console_level defines the current maximum level of
    messages that appear on all enabled consoles; it
    allows to filter out less important ones

  + minimum_console_loglevel defines the minimum
    console_loglevel that might be set by userspace
    via syslog interface; it prevents userspace from
    hiding emergency messages

  + ignore_loglevel allows to see all messages
    easily; it is used for debugging

IMPORTANT: console_level is increased in some special
situations to see everything, e.g. in panic(), oops_begin(),
__handle_sysrq().

I guess that people want to see all messages even on the slow
console during panic(), oops(), with ignore_loglevel. It means
that the new per-console setting must not limit it. Also
any console must not go below minimum_console_level.

What about doing it the other way and define min_loglevel
for each console. It might be used to make selected consoles
always more verbose (above current console_level) but it
will not limit the more verbose modes.

Best Regards,
Petr

^ permalink raw reply	[flat|nested] 13+ messages in thread

* Re: [RFC][PATCH 1/2] printk: Introduce per-console filtering of messages by loglevel
  2017-04-05  3:27     ` Steven Rostedt
@ 2017-04-05 23:53       ` Calvin Owens
  0 siblings, 0 replies; 13+ messages in thread
From: Calvin Owens @ 2017-04-05 23:53 UTC (permalink / raw)
  To: Steven Rostedt
  Cc: Sergey Senozhatsky, Petr Mladek, Greg Kroah-Hartman, Jiri Slaby,
	Andrew Morton, Manuel Schölling, Hans de Goede, Paul Burton,
	linux-kernel, kernel-team, Sergey Senozhatsky

On Tuesday 04/04 at 23:27 -0400, Steven Rostedt wrote:
> On Wed, 5 Apr 2017 11:16:28 +0900
> Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> wrote:
> 
> 
> > one more thing.
> > 
> > this per-console filtering ignores... the "ignore_loglevel" param.
> > 
> > early_param("ignore_loglevel", ignore_loglevel_setup);
> > module_param(ignore_loglevel, bool, S_IRUGO | S_IWUSR);
> > MODULE_PARM_DESC(ignore_loglevel,
> > 		 "ignore loglevel setting (prints all kernel messages to the console)");
> > 
> > 
> > my preference would be preserve "ignore_loglevel" behaviour. if
> > we are forced to 'ignore all loglevel filtering' then we should
> > do so.
> 
> Agreed.

Makes sense, I'll add then when I resend.

Thanks,
Calvin
 
> -- Steve
> 

^ permalink raw reply	[flat|nested] 13+ messages in thread

* Re: [RFC][PATCH 2/2] printk: Add /sys/consoles/${con}/ and maxlevel attribute
  2017-04-05  3:30   ` Steven Rostedt
@ 2017-04-05 23:55     ` Calvin Owens
  0 siblings, 0 replies; 13+ messages in thread
From: Calvin Owens @ 2017-04-05 23:55 UTC (permalink / raw)
  To: Steven Rostedt
  Cc: Petr Mladek, Sergey Senozhatsky, Greg Kroah-Hartman, Jiri Slaby,
	Andrew Morton, Manuel Schölling, Hans de Goede, Paul Burton,
	linux-kernel, kernel-team

On Tuesday 04/04 at 23:30 -0400, Steven Rostedt wrote:
> On Tue, 4 Apr 2017 16:03:20 -0700
> Calvin Owens <calvinowens@fb.com> wrote:
> 
> > This does the simplest possible thing: add a directory at the root of
> > sysfs that allows setting the "maxlevel" parameter for each console.
> > 
> > We can let kobject destruction race with console removal: if it does,
> > maxlevel_{show,store}() will safely fail with -ENODEV. This is a little
> > weird, but avoids embedding the kobject and therefore needing to totally
> > refactor the way we handle console struct lifetime.
> 
> Can you also add a patch that allows this to be set on the kernel
> command line, when the consoles are defined.

Absolutely :)

Thanks,
Calvin

 
> -- Steve
> 
> > 
> > Signed-off-by: Calvin Owens <calvinowens@fb.com>

^ permalink raw reply	[flat|nested] 13+ messages in thread

* Re: [RFC][PATCH 1/2] printk: Introduce per-console filtering of messages by loglevel
  2017-04-05 15:22     ` Petr Mladek
@ 2017-04-06  0:38       ` Calvin Owens
  2017-04-06 14:02         ` Petr Mladek
  0 siblings, 1 reply; 13+ messages in thread
From: Calvin Owens @ 2017-04-06  0:38 UTC (permalink / raw)
  To: Petr Mladek
  Cc: Sergey Senozhatsky, Steven Rostedt, Greg Kroah-Hartman,
	Jiri Slaby, Andrew Morton, Manuel Schölling, Hans de Goede,
	Paul Burton, linux-kernel, kernel-team, Sergey Senozhatsky

On Wednesday 04/05 at 17:22 +0200, Petr Mladek wrote:
> On Wed 2017-04-05 11:16:28, Sergey Senozhatsky wrote:
> > On (04/05/17 11:08), Sergey Senozhatsky wrote:
> > [..]
> > > >  		stop_critical_timings();	/* don't trace print latency */
> > > > -		call_console_drivers(ext_text, ext_len, text, len);
> > > > +		call_console_drivers(ext_text, ext_len, text, len, msg->level);
> > > >  		start_critical_timings();
> > > >  		printk_safe_exit_irqrestore(flags);
> > > 
> > > ok, so the idea is quite clear and reasonable.
> > > 
> > > 
> > > some thoughts,
> > > we have a system-wide suppress_message_printing() loglevel filtering
> > > in console_unlock() loop, which sets a limit on loglevel for all of
> > > the messages - we don't even msg_print_text() if the message has
> > > suppressible loglevel. and this implicitly restricts per-console
> > > maxlevels.
> > > 
> > > console_unlock()
> > > {
> > > 	for (;;) {
> > > 		...
> > > skip:
> > > 
> > > 		if (suppress_message_printing(msg->level))	// console_loglevel
> > > 			goto skip;
> > > 
> > > 		call_console_drivers(msg->level)
> > > 			{
> > > 				if (level > con->maxlevel)	// con loglevel
> > > 					continue;
> > > 				...
> > > 			}
> > > 	}
> > > }
> > > 
> > > this can be slightly confusing. what do you think?

I think it makes sense as long as we're clear about the semantics: if a
message would normally be printed to the console according to the global
settings, this allows you to limit the loglevel a specific console will
print.

Petr suggested the opposite approach, I'll address that below.
 
> I think about a reasonable behavior. There seems to be three variables
> that are related and are in use:
> 
>      console_level
>      minimum_console_loglevel
>      ignore_loglevel
> 
> The functions seems to be the following:
> 
>   + console_level defines the current maximum level of
>     messages that appear on all enabled consoles; it
>     allows to filter out less important ones
> 
>   + minimum_console_loglevel defines the minimum
>     console_loglevel that might be set by userspace
>     via syslog interface; it prevents userspace from
>     hiding emergency messages
> 
>   + ignore_loglevel allows to see all messages
>     easily; it is used for debugging
> 
> IMPORTANT: console_level is increased in some special
> situations to see everything, e.g. in panic(), oops_begin(),
> __handle_sysrq().
> 
> I guess that people want to see all messages even on the slow
> console during panic(), oops(), with ignore_loglevel. It means
> that the new per-console setting must not limit it. Also any
> console must not go below minimum_console_level.

I can definitely take oops_in_progress and minimum_console_level into
account in the drop condition. I can also send a patch to make the sysrq
handler reset all the maxlevels to LOGLEVEL_DEBUG if you like.

> What about doing it the other way and define min_loglevel
> for each console. It might be used to make selected consoles
> always more verbose (above current console_level) but it
> will not limit the more verbose modes.

I think it's more intuitive to let the global sysctl behave as it always
has, and allow additional filtering of higher levels downstream. I can
definitely see why users might find this a bit confusing, but IMHO
stacking two "filters" is more intuitive than a "filter" and a "bypass".

How about a read-only "functional_loglevel" attribute for each console
that displays:

	max(min(console_level, con->maxlevel), minimum_console_level)

Would that make the semantics more obvious? I'll obviously also send
patches for Documentation once there's consensus about the interface.

Thanks,
Calvin

> Best Regards,
> Petr

^ permalink raw reply	[flat|nested] 13+ messages in thread

* Re: [RFC][PATCH 1/2] printk: Introduce per-console filtering of messages by loglevel
  2017-04-06  0:38       ` Calvin Owens
@ 2017-04-06 14:02         ` Petr Mladek
  2017-04-06 22:52           ` Calvin Owens
  0 siblings, 1 reply; 13+ messages in thread
From: Petr Mladek @ 2017-04-06 14:02 UTC (permalink / raw)
  To: Calvin Owens
  Cc: Sergey Senozhatsky, Steven Rostedt, Greg Kroah-Hartman,
	Jiri Slaby, Andrew Morton, Manuel Schölling, Hans de Goede,
	Paul Burton, linux-kernel, kernel-team, Sergey Senozhatsky

On Wed 2017-04-05 17:38:19, Calvin Owens wrote:
> On Wednesday 04/05 at 17:22 +0200, Petr Mladek wrote:
> > I think about a reasonable behavior. There seems to be three variables
> > that are related and are in use:
> > 
> >      console_level
> >      minimum_console_loglevel
> >      ignore_loglevel
> > 
> > The functions seems to be the following:
> > 
> >   + console_level defines the current maximum level of
> >     messages that appear on all enabled consoles; it
> >     allows to filter out less important ones
> > 
> >   + minimum_console_loglevel defines the minimum
> >     console_loglevel that might be set by userspace
> >     via syslog interface; it prevents userspace from
> >     hiding emergency messages
> > 
> >   + ignore_loglevel allows to see all messages
> >     easily; it is used for debugging
> > 
> > IMPORTANT: console_level is increased in some special
> > situations to see everything, e.g. in panic(), oops_begin(),
> > __handle_sysrq().
> > 
> > I guess that people want to see all messages even on the slow
> > console during panic(), oops(), with ignore_loglevel. It means
> > that the new per-console setting must not limit it. Also any
> > console must not go below minimum_console_level.
> 
> I can definitely take oops_in_progress and minimum_console_level into
> account in the drop condition. I can also send a patch to make the sysrq
> handler reset all the maxlevels to LOGLEVEL_DEBUG if you like.

Please note that you must not call console_lock() in the sysrq
handler. The function might sleep and it is irq context.
By other words, you could not manipulate the console structures
there.


> > What about doing it the other way and define min_loglevel
> > for each console. It might be used to make selected consoles
> > always more verbose (above current console_level) but it
> > will not limit the more verbose modes.
> 
> I think it's more intuitive to let the global sysctl behave as it always
> has, and allow additional filtering of higher levels downstream. I can
> definitely see why users might find this a bit confusing, but IMHO
> stacking two "filters" is more intuitive than a "filter" and a "bypass".

I do not have strong opinion here. I like the idea of this patch.
Sadly, the console setting already is pretty confusing.

I know that many people, including me, have troubles to understand
the meaning of the 4 numbers in /proc/sys/kernel/printk. They set

	console_loglevel
	default_message_loglevel
	minimum_console_loglevel
	default_console_loglevel

And we are going to add another complexity :-(


> How about a read-only "functional_loglevel" attribute for each console
> that displays:
> 
> 	max(min(console_level, con->maxlevel), minimum_console_level)

I like this idea and it inspired me. What about creating the following
structure under /sys

  /sys/consoles/<name1>/loglevel
		       /minimum_loglevel
	       /<name2>/loglevel
		       /minimum_loglevel
	       /loglevel
	       /minimum_loglevel

The semantic would be:

   + global loglevel will show the current default console_loglevel,
     it must be above the global minimum_console_loglevel

   + the per-console loglevel will show the loglevel specific
     for the given console; it must be above the per-console
     minimum_loglevel while

   + the per-console minimum_loglevel must be above the global
     minimum_console_loglevel

   The setting of the global values would affect the per-console
   values but it must respect the above rules.

   It is still the "filter" and "bypass" logic. But we will just
   repeat the existing terms and logic. Also note that
   "ignore_loglevel" and the special modes in sysrq, panic, oops
   use the "bypass" logic as well.


> Would that make the semantics more obvious? I'll obviously also send
> patches for Documentation once there's consensus about the interface.

Please add also linux-api@vger.kernel.org, especially for the
patch adding the new toplevel directory under /sys.

Best Regards,
Petr

^ permalink raw reply	[flat|nested] 13+ messages in thread

* Re: [RFC][PATCH 1/2] printk: Introduce per-console filtering of messages by loglevel
  2017-04-06 14:02         ` Petr Mladek
@ 2017-04-06 22:52           ` Calvin Owens
  0 siblings, 0 replies; 13+ messages in thread
From: Calvin Owens @ 2017-04-06 22:52 UTC (permalink / raw)
  To: Petr Mladek
  Cc: Sergey Senozhatsky, Steven Rostedt, Greg Kroah-Hartman,
	Jiri Slaby, Andrew Morton, Manuel Schölling, Hans de Goede,
	Paul Burton, linux-kernel, kernel-team, Sergey Senozhatsky

On Thursday 04/06 at 16:02 +0200, Petr Mladek wrote:
> On Wed 2017-04-05 17:38:19, Calvin Owens wrote:
> > On Wednesday 04/05 at 17:22 +0200, Petr Mladek wrote:
> > > I think about a reasonable behavior. There seems to be three variables
> > > that are related and are in use:
> > > 
> > >      console_level
> > >      minimum_console_loglevel
> > >      ignore_loglevel
> > > 
> > > The functions seems to be the following:
> > > 
> > >   + console_level defines the current maximum level of
> > >     messages that appear on all enabled consoles; it
> > >     allows to filter out less important ones
> > > 
> > >   + minimum_console_loglevel defines the minimum
> > >     console_loglevel that might be set by userspace
> > >     via syslog interface; it prevents userspace from
> > >     hiding emergency messages
> > > 
> > >   + ignore_loglevel allows to see all messages
> > >     easily; it is used for debugging
> > > 
> > > IMPORTANT: console_level is increased in some special
> > > situations to see everything, e.g. in panic(), oops_begin(),
> > > __handle_sysrq().
> > > 
> > > I guess that people want to see all messages even on the slow
> > > console during panic(), oops(), with ignore_loglevel. It means
> > > that the new per-console setting must not limit it. Also any
> > > console must not go below minimum_console_level.
> > 
> > I can definitely take oops_in_progress and minimum_console_level into
> > account in the drop condition. I can also send a patch to make the sysrq
> > handler reset all the maxlevels to LOGLEVEL_DEBUG if you like.
> 
> Please note that you must not call console_lock() in the sysrq
> handler. The function might sleep and it is irq context.
> By other words, you could not manipulate the console structures
> there.

Sure, I'd punt it to process context somehow.
 
> > > What about doing it the other way and define min_loglevel
> > > for each console. It might be used to make selected consoles
> > > always more verbose (above current console_level) but it
> > > will not limit the more verbose modes.
> > 
> > I think it's more intuitive to let the global sysctl behave as it always
> > has, and allow additional filtering of higher levels downstream. I can
> > definitely see why users might find this a bit confusing, but IMHO
> > stacking two "filters" is more intuitive than a "filter" and a "bypass".
> 
> I do not have strong opinion here. I like the idea of this patch.
> Sadly, the console setting already is pretty confusing.
> 
> I know that many people, including me, have troubles to understand
> the meaning of the 4 numbers in /proc/sys/kernel/printk. They set
> 
> 	console_loglevel
> 	default_message_loglevel
> 	minimum_console_loglevel
> 	default_console_loglevel
> 
> And we are going to add another complexity :-(
> 
> 
> > How about a read-only "functional_loglevel" attribute for each console
> > that displays:
> > 
> > 	max(min(console_level, con->maxlevel), minimum_console_level)
> 
> I like this idea and it inspired me. What about creating the following
> structure under /sys
> 
>   /sys/consoles/<name1>/loglevel
> 		       /minimum_loglevel
> 	       /<name2>/loglevel
> 		       /minimum_loglevel
> 	       /loglevel
> 	       /minimum_loglevel
> 
> The semantic would be:
> 
>    + global loglevel will show the current default console_loglevel,
>      it must be above the global minimum_console_loglevel
> 
>    + the per-console loglevel will show the loglevel specific
>      for the given console; it must be above the per-console
>      minimum_loglevel while
> 
>    + the per-console minimum_loglevel must be above the global
>      minimum_console_loglevel
> 
>    The setting of the global values would affect the per-console
>    values but it must respect the above rules.
> 
>    It is still the "filter" and "bypass" logic. But we will just
>    repeat the existing terms and logic. Also note that
>    "ignore_loglevel" and the special modes in sysrq, panic, oops
>    use the "bypass" logic as well.

Okay, I see where you're coming from. Let me play with this a bit, I'll
send something concrete in the next day or two.

> > Would that make the semantics more obvious? I'll obviously also send
> > patches for Documentation once there's consensus about the interface.
> 
> Please add also linux-api@vger.kernel.org, especially for the
> patch adding the new toplevel directory under /sys.

Will do.

Thanks,
Calvin

> Best Regards,
> Petr

^ permalink raw reply	[flat|nested] 13+ messages in thread

end of thread, other threads:[~2017-04-06 22:53 UTC | newest]

Thread overview: 13+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2017-04-04 23:02 [RFC][PATCH 1/2] printk: Introduce per-console filtering of messages by loglevel Calvin Owens
2017-04-04 23:03 ` [RFC][PATCH 2/2] printk: Add /sys/consoles/${con}/ and maxlevel attribute Calvin Owens
2017-04-05  3:30   ` Steven Rostedt
2017-04-05 23:55     ` Calvin Owens
2017-04-05  1:51 ` [RFC][PATCH 1/2] printk: Introduce per-console filtering of messages by loglevel Joe Perches
2017-04-05  2:08 ` Sergey Senozhatsky
2017-04-05  2:16   ` Sergey Senozhatsky
2017-04-05  3:27     ` Steven Rostedt
2017-04-05 23:53       ` Calvin Owens
2017-04-05 15:22     ` Petr Mladek
2017-04-06  0:38       ` Calvin Owens
2017-04-06 14:02         ` Petr Mladek
2017-04-06 22:52           ` Calvin Owens

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).