[PATCH] printk: Move printk_delay to separate file

[PATCH] printk: Move printk_delay to separate file

[Joe Perches]

printk.c is a huge file with too many local functions for a
human to read and easily parse.

Start to separate out bits into smaller files.

Miscellanea:

o Rename suppress_message_printing to printk_suppress_message
o Add function definitions to printk.h

Signed-off-by: Joe Perches <joe@perches.com>
---
 include/linux/printk.h |  4 +++
 kernel/printk/Makefile |  2 +-
 kernel/printk/delay.c  | 73 ++++++++++++++++++++++++++++++++++++++++++++++
 kernel/printk/printk.c | 78 +++-----------------------------------------------
 4 files changed, 82 insertions(+), 75 deletions(-)
 create mode 100644 kernel/printk/delay.c

diff --git a/include/linux/printk.h b/include/linux/printk.h
index e10f27468322..c86cb07baf83 100644
--- a/include/linux/printk.h
+++ b/include/linux/printk.h
@@ -186,7 +186,11 @@ extern int __printk_ratelimit(const char *func);
 extern bool printk_timed_ratelimit(unsigned long *caller_jiffies,
 				   unsigned int interval_msec);
 
+bool printk_suppress_message(int level);
+
 extern int printk_delay_msec;
+void printk_delay(int level);
+
 extern int dmesg_restrict;
 extern int kptr_restrict;
 
diff --git a/kernel/printk/Makefile b/kernel/printk/Makefile
index 4a2ffc39eb95..9b38d597575e 100644
--- a/kernel/printk/Makefile
+++ b/kernel/printk/Makefile
@@ -1,3 +1,3 @@
-obj-y	= printk.o
+obj-y	= printk.o delay.o
 obj-$(CONFIG_PRINTK)	+= printk_safe.o
 obj-$(CONFIG_A11Y_BRAILLE_CONSOLE)	+= braille.o
diff --git a/kernel/printk/delay.c b/kernel/printk/delay.c
new file mode 100644
index 000000000000..b8edd6d20818
--- /dev/null
+++ b/kernel/printk/delay.c
@@ -0,0 +1,73 @@
+#include <linux/kernel.h>
+#include <linux/jiffies.h>
+#include <linux/nmi.h>
+#include <linux/delay.h>
+
+#ifdef CONFIG_BOOT_PRINTK_DELAY
+
+static int boot_delay; /* msecs delay after each printk during bootup */
+static unsigned long long loops_per_msec;	/* based on boot_delay */
+
+static int __init boot_delay_setup(char *str)
+{
+	unsigned long lpj;
+
+	lpj = preset_lpj ? preset_lpj : 1000000;	/* some guess */
+	loops_per_msec = (unsigned long long)lpj / 1000 * HZ;
+
+	get_option(&str, &boot_delay);
+	if (boot_delay > 10 * 1000)
+		boot_delay = 0;
+
+	pr_debug("boot_delay: %u, preset_lpj: %ld, lpj: %lu, HZ: %d, loops_per_msec: %llu\n",
+		boot_delay, preset_lpj, lpj, HZ, loops_per_msec);
+	return 0;
+}
+early_param("boot_delay", boot_delay_setup);
+
+static void boot_delay_msec(int level)
+{
+	unsigned long long k;
+	unsigned long timeout;
+
+	if ((boot_delay == 0 || system_state >= SYSTEM_RUNNING) ||
+	    printk_suppress_message(level))
+		return;
+
+	k = (unsigned long long)loops_per_msec * boot_delay;
+
+	timeout = jiffies + msecs_to_jiffies(boot_delay);
+	while (k) {
+		k--;
+		cpu_relax();
+		/*
+		 * use (volatile) jiffies to prevent compiler reduction;
+		 * loop termination via jiffies is secondary
+		 * and may or may not happen.
+		 */
+		if (time_after(jiffies, timeout))
+			break;
+		touch_nmi_watchdog();
+	}
+}
+#else
+static inline void boot_delay_msec(int level)
+{
+}
+#endif
+
+int printk_delay_msec __read_mostly;
+
+void printk_delay(int level)
+{
+	boot_delay_msec(level);
+
+	if (unlikely(printk_delay_msec)) {
+		int m = printk_delay_msec;
+
+		while (m--) {
+			mdelay(1);
+			touch_nmi_watchdog();
+		}
+	}
+}
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index fc47863f629c..b8e63a5f1558 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -1142,66 +1142,11 @@ module_param(ignore_loglevel, bool, S_IRUGO | S_IWUSR);
 MODULE_PARM_DESC(ignore_loglevel,
 		 "ignore loglevel setting (prints all kernel messages to the console)");
 
-static bool suppress_message_printing(int level)
+bool printk_suppress_message(int level)
 {
 	return (level >= console_loglevel && !ignore_loglevel);
 }
 
-#ifdef CONFIG_BOOT_PRINTK_DELAY
-
-static int boot_delay; /* msecs delay after each printk during bootup */
-static unsigned long long loops_per_msec;	/* based on boot_delay */
-
-static int __init boot_delay_setup(char *str)
-{
-	unsigned long lpj;
-
-	lpj = preset_lpj ? preset_lpj : 1000000;	/* some guess */
-	loops_per_msec = (unsigned long long)lpj / 1000 * HZ;
-
-	get_option(&str, &boot_delay);
-	if (boot_delay > 10 * 1000)
-		boot_delay = 0;
-
-	pr_debug("boot_delay: %u, preset_lpj: %ld, lpj: %lu, "
-		"HZ: %d, loops_per_msec: %llu\n",
-		boot_delay, preset_lpj, lpj, HZ, loops_per_msec);
-	return 0;
-}
-early_param("boot_delay", boot_delay_setup);
-
-static void boot_delay_msec(int level)
-{
-	unsigned long long k;
-	unsigned long timeout;
-
-	if ((boot_delay == 0 || system_state >= SYSTEM_RUNNING)
-		|| suppress_message_printing(level)) {
-		return;
-	}
-
-	k = (unsigned long long)loops_per_msec * boot_delay;
-
-	timeout = jiffies + msecs_to_jiffies(boot_delay);
-	while (k) {
-		k--;
-		cpu_relax();
-		/*
-		 * use (volatile) jiffies to prevent
-		 * compiler reduction; loop termination via jiffies
-		 * is secondary and may or may not happen.
-		 */
-		if (time_after(jiffies, timeout))
-			break;
-		touch_nmi_watchdog();
-	}
-}
-#else
-static inline void boot_delay_msec(int level)
-{
-}
-#endif
-
 static bool printk_time = IS_ENABLED(CONFIG_PRINTK_TIME);
 module_param_named(time, printk_time, bool, S_IRUGO | S_IWUSR);
 
@@ -1587,20 +1532,6 @@ static void call_console_drivers(const char *ext_text, size_t ext_len,
 	}
 }
 
-int printk_delay_msec __read_mostly;
-
-static inline void printk_delay(void)
-{
-	if (unlikely(printk_delay_msec)) {
-		int m = printk_delay_msec;
-
-		while (m--) {
-			mdelay(1);
-			touch_nmi_watchdog();
-		}
-	}
-}
-
 /*
  * Continuation lines are buffered, and not committed to the record buffer
  * until the line is complete, or a race forces it. The line fragments
@@ -1709,8 +1640,7 @@ asmlinkage int vprintk_emit(int facility, int level,
 		in_sched = true;
 	}
 
-	boot_delay_msec(level);
-	printk_delay();
+	printk_delay(level);
 
 	/* This stops the holder of console_sem just where we want him */
 	logbuf_lock_irqsave(flags);
@@ -1871,7 +1801,7 @@ static void call_console_drivers(const char *ext_text, size_t ext_len,
 				 const char *text, size_t len) {}
 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; }
+bool printk_suppress_message(int level) { return false; }
 
 #endif /* CONFIG_PRINTK */
 
@@ -2216,7 +2146,7 @@ void console_unlock(void)
 			break;
 
 		msg = log_from_idx(console_idx);
-		if (suppress_message_printing(msg->level)) {
+		if (printk_suppress_message(msg->level)) {
 			/*
 			 * Skip record we have buffered and already printed
 			 * directly to the console when we received it, and
-- 
2.10.0.rc2.1.g053435c

Re: [PATCH] printk: Move printk_delay to separate file

[Sergey Senozhatsky]

On (07/07/17 11:08), Joe Perches wrote:
> printk.c is a huge file with too many local functions for a
> human to read and easily parse.
> 
> Start to separate out bits into smaller files.
> 
> Miscellanea:
> 
> o Rename suppress_message_printing to printk_suppress_message
> o Add function definitions to printk.h

I don't mind, in general, but I'm a bit hesitant. we want to have
automatic printk throttling (printk delay basically) and we need
some of those printk-internal *_seq numbers to see how far consoles
are behind the logbuf. so either we need to 'un-static' those *_seq
and extern them in delay.c or simply keep printk-delay machinery in
printk.c and add the new function.

// p.s. I'll take a look at the patch a bit later. I'm on a sick leave now.

	-ss

Re: [PATCH] printk: Move printk_delay to separate file

[Joe Perches]

On Sat, 2017-07-08 at 14:24 +0900, Sergey Senozhatsky wrote:
> On (07/07/17 11:08), Joe Perches wrote:
> > printk.c is a huge file with too many local functions for a
> > human to read and easily parse.
> > 
> > Start to separate out bits into smaller files.
> > 
> > Miscellanea:
> > 
> > o Rename suppress_message_printing to printk_suppress_message
> > o Add function definitions to printk.h
> 
> I don't mind, in general, but I'm a bit hesitant. we want to have
> automatic printk throttling (printk delay basically) and we need
> some of those printk-internal *_seq numbers to see how far consoles
> are behind the logbuf. so either we need to 'un-static' those *_seq
> and extern them in delay.c or simply keep printk-delay machinery in
> printk.c and add the new function.
> 
> // p.s. I'll take a look at the patch a bit later. I'm on a sick leave now.

Hey Sergey.

Basically, this is a simple trial patch.

printk is getting nothing but more complex.

I believe printk is in real need of logical separation
into multiple parts to isolate the various logic bits.

o console
o kmsg/devkmsg
o logbuf
o syslog

etc...

Re: [PATCH] printk: Move printk_delay to separate file

[Petr Mladek]

On Fri 2017-07-07 22:44:19, Joe Perches wrote:
> On Sat, 2017-07-08 at 14:24 +0900, Sergey Senozhatsky wrote:
> > On (07/07/17 11:08), Joe Perches wrote:
> > > printk.c is a huge file with too many local functions for a
> > > human to read and easily parse.
> > > 
> > > Start to separate out bits into smaller files.
> > > 
> > > Miscellanea:
> > > 
> > > o Rename suppress_message_printing to printk_suppress_message
> > > o Add function definitions to printk.h
> > 
> > I don't mind, in general, but I'm a bit hesitant. we want to have
> > automatic printk throttling (printk delay basically) and we need
> > some of those printk-internal *_seq numbers to see how far consoles
> > are behind the logbuf. so either we need to 'un-static' those *_seq
> > and extern them in delay.c or simply keep printk-delay machinery in
> > printk.c and add the new function.

I agree with Sergey here. Some split would make sense but I would
prefer to keep the delay stuff as is for now. It is not a big win.
And there is some demand to extent the throttling capabilities.
It would fit together with the delay stuff. But we did not think
much about it yet.
 
> > // p.s. I'll take a look at the patch a bit later. I'm on a sick leave now.
> 
> Hey Sergey.
> 
> Basically, this is a simple trial patch.
> 
> printk is getting nothing but more complex.
> 
> I believe printk is in real need of logical separation
> into multiple parts to isolate the various logic bits.
> 
> o console

I think that this might be the biggest win. IMHO, one confusing
thing is that big parts of printk.c are compiled only when
CONFIG_PRINTK is defined. There there are some small parts
that are always compiled. These are mostly console related.
I am sometimes not sure what is in what section and it is
"hard" to find.

> o kmsg/devkmsg

Sounds good. Well, I wonder how much code is shared with
syslog. It might make sense to join this stuff. But let's
see how it would look.

In each case, there are some functions (msg_print_text, ...)
that are shared between console, kmsg, and syslog. We would
need to put this somewhere and share.

> o logbuf

I do not have a strong opinion about this. I would leave this
for later when we see what has left in printk.c

I am going to comment some details in the existing patch.

Best Regards,
Petr

Re: [PATCH] printk: Move printk_delay to separate file

[Joe Perches]

On Fri, 2017-07-14 at 17:17 +0200, Petr Mladek wrote:
> On Fri 2017-07-07 22:44:19, Joe Perches wrote:
> > On Sat, 2017-07-08 at 14:24 +0900, Sergey Senozhatsky wrote:
> > > On (07/07/17 11:08), Joe Perches wrote:
> > > > printk.c is a huge file with too many local functions for a
> > > > human to read and easily parse.
> > > > 
> > > > Start to separate out bits into smaller files.
> > > > 
> > > > Miscellanea:
> > > > 
> > > > o Rename suppress_message_printing to printk_suppress_message
> > > > o Add function definitions to printk.h
> > > 
> > > I don't mind, in general, but I'm a bit hesitant. we want to have
> > > automatic printk throttling (printk delay basically) and we need
> > > some of those printk-internal *_seq numbers to see how far consoles
> > > are behind the logbuf. so either we need to 'un-static' those *_seq
> > > and extern them in delay.c or simply keep printk-delay machinery in
> > > printk.c and add the new function.
> 
> I agree with Sergey here. Some split would make sense but I would
> prefer to keep the delay stuff as is for now. It is not a big win.
> And there is some demand to extent the throttling capabilities.
> It would fit together with the delay stuff. But we did not think
> much about it yet.
>  
> > > // p.s. I'll take a look at the patch a bit later. I'm on a sick leave now.
> > 
> > Hey Sergey.
> > 
> > Basically, this is a simple trial patch.
> > 
> > printk is getting nothing but more complex.
> > 
> > I believe printk is in real need of logical separation
> > into multiple parts to isolate the various logic bits.
> > 
> > o console
> 
> I think that this might be the biggest win. IMHO, one confusing
> thing is that big parts of printk.c are compiled only when
> CONFIG_PRINTK is defined. There there are some small parts
> that are always compiled. These are mostly console related.
> I am sometimes not sure what is in what section and it is
> "hard" to find.

Start somewhere without regard to whatever new
stuff you have future
dreams to add.

The concept of logical separation is a big win.

Moving delay into a separate file is trivial and
making the symbols required to support whatever
symbols are required for additional throttling
is also trivial.

> > o kmsg/devkmsg
> 
> Sounds good. Well, I wonder how much code is shared with
> syslog. It might make sense to join this stuff. But let's
> see how it would look.
> 
> In each case, there are some functions (msg_print_text, ...)
> that are shared between console, kmsg, and syslog. We would
> need to put this somewhere and share.

It's relatively simple to prefix the various
bits that have to become shared with printk_
and make them global symbols in separate files
in the kernel/printk/ directory.

It's also unfortunately tedious.

I did all of that several years ago.

https://lkml.org/lkml/2012/10/17/41

Re: [PATCH] printk: Move printk_delay to separate file

[Petr Mladek]

On Fri 2017-07-07 11:08:59, Joe Perches wrote:
> printk.c is a huge file with too many local functions for a
> human to read and easily parse.
> 
> Start to separate out bits into smaller files.
> 
> Miscellanea:
> 
> o Rename suppress_message_printing to printk_suppress_message

Some renaming might make sense. But please, do it in a separate patch.
It will make the changes much easier to review.

Some existing names are ugly. But there should be a good reason
to rename them, for example, that the existing one causes confusion.
We should be careful here. Otherwise, it will be a nightmare to
search the history or backport important fixes.

Also note that some variables are exported a strange way for
external utilities line crash, makedumpfile, see
log_buf_vmcoreinfo_setup(). Renaming such variables would
require fixing all the external applications.


> o Add function definitions to printk.h

We should not declare functions in a global header without a reason.
It would allow to use them anywhere and it is not always intended
or even safe.

If we want to make some function available in global, we should
do so in a separate patch with a reasonable explanation.

If we want to share them between kernel/printk/*.c sources,
we should declare them in a local header, e.g.
kernel/printk/internal.h


> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index fc47863f629c..b8e63a5f1558 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -1709,8 +1640,7 @@ asmlinkage int vprintk_emit(int facility, int level,
>  		in_sched = true;
>  	}
>  
> -	boot_delay_msec(level);
> -	printk_delay();
> +	printk_delay(level);

This makes me nervous. It is not even documented. Please, do not do
any hidden changes in general! The patch that splits the sources
should only shuffle the code. It might do only some minimal
necessary changes like removing "static" for functions that
newly need to be accessed from other source file.

Best Regards,
Petr

PS: Please, split only the console stuff as a start. It will be
the most helpful thing. Also we are still maintainers beginners.
I would like to start slowly, preferably get some feedback from
more experienced developers, and get one such change into the
mainline before we do many more changes.

Re: [PATCH] printk: Move printk_delay to separate file

[Joe Perches]

On Fri, 2017-07-14 at 17:57 +0200, Petr Mladek wrote:
> On Fri 2017-07-07 11:08:59, Joe Perches wrote:
> > printk.c is a huge file with too many local functions for a
> > human to read and easily parse.
> > 
> > Start to separate out bits into smaller files.
> > 
> > Miscellanea:
> > 
> > o Rename suppress_message_printing to printk_suppress_message
> 
> Some renaming might make sense. But please, do it in a separate patch.
> It will make the changes much easier to review.

> Some existing names are ugly. But there should be a good reason
> to rename them, for example, that the existing one causes confusion.
> We should be careful here. Otherwise, it will be a nightmare to
> search the history or backport important fixes.

Disagree.


> Also note that some variables are exported a strange way for
> external utilities line crash, makedumpfile, see
> log_buf_vmcoreinfo_setup(). Renaming such variables would
> require fixing all the external applications.

I believe the only ones that matters are the
log_buf_vmcore<foo>

I already renamed those once before without a
single peep from anyone.

> > o Add function definitions to printk.h
> 
> We should not declare functions in a global header without a reason.
> It would allow to use them anywhere and it is not always intended
> or even safe.

IMO: printk.h isn't really a global header.

I argued against calling it a global header
when I created it.

There needs to be some mechanism, even if
perhaps it's local to kernel/printk/, to share
these symbols.

> If we want to make some function available in global, we should
> do so in a separate patch with a reasonable explanation.
> 
> If we want to share them between kernel/printk/*.c sources,
> we should declare them in a local header, e.g.
> kernel/printk/internal.h

internal.h would be a terrible name.

Specify what each bit is used for not
how it's used.

> > diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> > index fc47863f629c..b8e63a5f1558 100644
> > --- a/kernel/printk/printk.c
> > +++ b/kernel/printk/printk.c
> > @@ -1709,8 +1640,7 @@ asmlinkage int vprintk_emit(int facility, int level,
> >  		in_sched = true;
> >  	}
> >  
> > -	boot_delay_msec(level);
> > -	printk_delay();
> > +	printk_delay(level);
> 
> This makes me nervous.

It shouldn't.  It's trivial.

The boot delay is a detail that
shouldn't even be exposed anywhere
let alone in the vprintk path.

> It is not even documented.

printk is completely undocumented.
Think about how long it took you to even
partially understand it and how often you
add defects and need rework to the existing
bits.

> Please, do not do
> any hidden changes in general! The patch that splits the sources
> should only shuffle the code.

That's not possible.

>  It might do only some minimal
> necessary changes like removing "static" for functions that
> newly need to be accessed from other source file.
> 
> Best Regards,
> Petr
> 
> PS: Please, split only the console stuff as a start. It will be
> the most helpful thing. Also we are still maintainers beginners.

No.  There's far too many symbols that would need to be
renamed for that as a start.  You're already objecting
to trivial stuff.  console is complex and involved.

> I would like to start slowly, preferably get some feedback from
> more experienced developers, and get one such change into the
> mainline before we do many more changes.

I believe I am one such experienced developer.