Function pr_notice print max length maybe less than the command line length,
need more times to print all.
For example, arm64 has 2048 bytes command line length, but printk maximum
length is only 1024 bytes.
Signed-off-by: Chenggang Wang <[email protected]>
---
init/main.c | 12 +++++++++++-
1 file changed, 11 insertions(+), 1 deletion(-)
diff --git a/init/main.c b/init/main.c
index 03371976d387..4cf676cc3305 100644
--- a/init/main.c
+++ b/init/main.c
@@ -825,6 +825,16 @@ void __init __weak arch_call_rest_init(void)
rest_init();
}
+static void __init print_cmdline(void)
+{
+ const char *prefix = "Kernel command line: ";
+ int len = -strlen(prefix);
+
+ len += pr_notice("%s%s\n", prefix, boot_command_line);
+ while (boot_command_line[len])
+ len += pr_notice("%s\n", &boot_command_line[len]);
+}
+
asmlinkage __visible void __init start_kernel(void)
{
char *command_line;
@@ -858,7 +868,7 @@ asmlinkage __visible void __init start_kernel(void)
build_all_zonelists(NULL);
page_alloc_init();
- pr_notice("Kernel command line: %s\n", saved_command_line);
+ print_cmdline();
/* parameters may set static keys */
jump_label_init();
parse_early_param();
--
2.20.1
On Tue, 19 May 2020 11:29:46 +0800 王程刚 <[email protected]> wrote:
> Function pr_notice print max length maybe less than the command line length,
> need more times to print all.
> For example, arm64 has 2048 bytes command line length, but printk maximum
> length is only 1024 bytes.
I can see why that might be a problem!
> --- a/init/main.c
> +++ b/init/main.c
> @@ -825,6 +825,16 @@ void __init __weak arch_call_rest_init(void)
> rest_init();
> }
>
> +static void __init print_cmdline(void)
> +{
> + const char *prefix = "Kernel command line: ";
const char prefix[] = "...";
might generate slightly more efficient code.
> + int len = -strlen(prefix);
hm, tricky. What the heck does printk() actually return to the caller?
Seems that we forgot to document this, and there are so many different
paths which a printk call can take internally that I'm not confident
that they all got it right!
> + len += pr_notice("%s%s\n", prefix, boot_command_line);
> + while (boot_command_line[len])
> + len += pr_notice("%s\n", &boot_command_line[len]);
> +}
Did you really intend to insert a \n into the output every 1024'th
character?
And what effect does this additional \n have upon the code logic?
Doesn't this cause the printk() return value to be one greater than
expected each time it is called?
>
> ...
>
On Mon, 2020-05-18 at 20:44 -0700, Andrew Morton wrote:
> On Tue, 19 May 2020 11:29:46 +0800 王程刚 <[email protected]> wrote:
>
> > Function pr_notice print max length maybe less than the command line length,
> > need more times to print all.
> > For example, arm64 has 2048 bytes command line length, but printk maximum
> > length is only 1024 bytes.
>
> I can see why that might be a problem!
>
> > --- a/init/main.c
> > +++ b/init/main.c
> > @@ -825,6 +825,16 @@ void __init __weak arch_call_rest_init(void)
> > rest_init();
> > }
> >
> > +static void __init print_cmdline(void)
> > +{
> > + const char *prefix = "Kernel command line: ";
>
> const char prefix[] = "...";
>
> might generate slightly more efficient code.
>
> > + int len = -strlen(prefix);
>
> hm, tricky. What the heck does printk() actually return to the caller?
> Seems that we forgot to document this, and there are so many different
> paths which a printk call can take internally that I'm not confident
> that they all got it right!
There is no use of the return value of any pr_<level> or
dev_<level> or netdev_<level) in the kernel.
All the pr_<level> mechanisms (as functions) should return void.
https://lore.kernel.org/lkml/[email protected]/
> > + len += pr_notice("%s%s\n", prefix, boot_command_line);
> > + while (boot_command_line[len])
> > + len += pr_notice("%s\n", &boot_command_line[len]);
> > +}
More likely it'd be better to use a strlen(boot_command_line)
and perhaps do something like print multiple lines with args
using strchr(, ' ') at some largish value, say 132 or 256 chars
maximum per line.
On Mon, May 18, 2020 at 10:09:34PM -0700, Joe Perches wrote:
> On Mon, 2020-05-18 at 20:44 -0700, Andrew Morton wrote:
> > On Tue, 19 May 2020 11:29:46 +0800 王程刚 <[email protected]> wrote:
> >
> > > Function pr_notice print max length maybe less than the command line length,
> > > need more times to print all.
> > > For example, arm64 has 2048 bytes command line length, but printk maximum
> > > length is only 1024 bytes.
> >
> > I can see why that might be a problem!
> >
> > > --- a/init/main.c
> > > +++ b/init/main.c
> > > @@ -825,6 +825,16 @@ void __init __weak arch_call_rest_init(void)
> > > rest_init();
> > > }
> > >
> > > +static void __init print_cmdline(void)
> > > +{
> > > + const char *prefix = "Kernel command line: ";
> >
> > const char prefix[] = "...";
> >
> > might generate slightly more efficient code.
> >
> > > + int len = -strlen(prefix);
> >
> > hm, tricky. What the heck does printk() actually return to the caller?
> > Seems that we forgot to document this, and there are so many different
> > paths which a printk call can take internally that I'm not confident
> > that they all got it right!
>
> There is no use of the return value of any pr_<level> or
> dev_<level> or netdev_<level) in the kernel.
>
> All the pr_<level> mechanisms (as functions) should return void.
> https://lore.kernel.org/lkml/[email protected]/
>
> > > + len += pr_notice("%s%s\n", prefix, boot_command_line);
> > > + while (boot_command_line[len])
> > > + len += pr_notice("%s\n", &boot_command_line[len]);
> > > +}
>
> More likely it'd be better to use a strlen(boot_command_line)
> and perhaps do something like print multiple lines with args
> using strchr(, ' ') at some largish value, say 132 or 256 chars
> maximum per line.
>
>
>
Should it use pr_cont to print the subsequent lines?
Joe Perches (2):
printk: Move and rename maximum printk output line length defines
init: Allow multi-line output of kernel command line
include/linux/printk.h | 18 ++++++++++++++++++
init/main.c | 31 ++++++++++++++++++++++++++++++-
kernel/printk/printk.c | 28 ++++++++++------------------
3 files changed, 58 insertions(+), 19 deletions(-)
--
2.25.1
ARM may have its longest possible command line larger than the longest
possible printk.
If necessary, emit the commend line on multiple lines.
Signed-off-by: Joe Perches <[email protected]>
---
compiled, untested
init/main.c | 31 ++++++++++++++++++++++++++++++-
1 file changed, 30 insertions(+), 1 deletion(-)
diff --git a/init/main.c b/init/main.c
index b63a3c001ac4..b3ebbbc129ae 100644
--- a/init/main.c
+++ b/init/main.c
@@ -826,6 +826,34 @@ void __init __weak arch_call_rest_init(void)
rest_init();
}
+static void __init print_cmdline(char *line)
+{
+#ifdef CONFIG_PRINTK
+ const char *prefix = "Kernel command line";
+ size_t len = strlen(line);
+
+ while (len > PRINTK_LOG_LINE_MAX) {
+ char *pos = line;
+ char *last_pos = pos + PRINTK_LOG_LINE_MAX - 1;
+ char saved_char;
+ /* Find last space char within the maximum line length */
+ while ((pos = memchr(pos, ' ', len - (pos - line))) &&
+ (pos - line) < PRINTK_LOG_LINE_MAX - 1) {
+ last_pos = pos;
+ }
+ saved_char = line[last_pos - line];
+ line[last_pos - line] = 0;
+ pr_notice("%s: %s\n", prefix, line);
+ prefix = "Kernel command line (continued)";
+ line[last_pos - line] = saved_char;
+ len -= pos - line;
+ line += pos - line;
+ }
+
+ pr_notice("%s: %s\n", prefix, line);
+#endif
+}
+
asmlinkage __visible void __init start_kernel(void)
{
char *command_line;
@@ -859,7 +887,8 @@ asmlinkage __visible void __init start_kernel(void)
build_all_zonelists(NULL);
page_alloc_init();
- pr_notice("Kernel command line: %s\n", saved_command_line);
+ print_cmdline(saved_command_line);
+
/* parameters may set static keys */
jump_label_init();
parse_early_param();
--
2.25.1
Make the printk maximum line length globally available.
Miscellanea:
o Prefix the defines with PRINTK_
Signed-off-by: Joe Perches <[email protected]>
---
include/linux/printk.h | 18 ++++++++++++++++++
kernel/printk/printk.c | 28 ++++++++++------------------
2 files changed, 28 insertions(+), 18 deletions(-)
diff --git a/include/linux/printk.h b/include/linux/printk.h
index 38beb97e7018..850dc4d4356f 100644
--- a/include/linux/printk.h
+++ b/include/linux/printk.h
@@ -43,6 +43,24 @@ static inline const char *printk_skip_headers(const char *buffer)
#define CONSOLE_EXT_LOG_MAX 8192
+/* Maximum length of a single printk */
+
+#ifdef CONFIG_PRINTK
+
+#ifdef CONFIG_PRINTK_CALLER
+#define PRINTK_PREFIX_MAX 48
+#else
+#define PRINTK_PREFIX_MAX 32
+#endif
+#define PRINTK_LOG_LINE_MAX (1024 - PRINTK_PREFIX_MAX)
+
+#else
+
+#define PRINTK_PREFIX_MAX 0
+#define PRINTK_LOG_LINE_MAX 0
+
+#endif
+
/* printk's without a loglevel use this.. */
#define MESSAGE_LOGLEVEL_DEFAULT CONFIG_MESSAGE_LOGLEVEL_DEFAULT
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 4f1cc4acef41..fc22a494ef0c 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -443,13 +443,6 @@ static u64 exclusive_console_stop_seq;
static u64 clear_seq;
static u32 clear_idx;
-#ifdef CONFIG_PRINTK_CALLER
-#define PREFIX_MAX 48
-#else
-#define PREFIX_MAX 32
-#endif
-#define LOG_LINE_MAX (1024 - PREFIX_MAX)
-
#define LOG_LEVEL(v) ((v) & 0x07)
#define LOG_FACILITY(v) ((v) >> 3 & 0xff)
@@ -825,7 +818,7 @@ static ssize_t devkmsg_write(struct kiocb *iocb, struct iov_iter *from)
size_t len = iov_iter_count(from);
ssize_t ret = len;
- if (!user || len > LOG_LINE_MAX)
+ if (!user || len > PRINTK_LOG_LINE_MAX)
return -EINVAL;
/* Ignore when user logging is disabled. */
@@ -1341,7 +1334,7 @@ static size_t msg_print_text(const struct printk_log *msg, bool syslog,
const char *text = log_text(msg);
size_t text_size = msg->text_len;
size_t len = 0;
- char prefix[PREFIX_MAX];
+ char prefix[PRINTK_PREFIX_MAX];
const size_t prefix_len = print_prefix(msg, syslog, time, prefix);
do {
@@ -1382,7 +1375,7 @@ static int syslog_print(char __user *buf, int size)
struct printk_log *msg;
int len = 0;
- text = kmalloc(LOG_LINE_MAX + PREFIX_MAX, GFP_KERNEL);
+ text = kmalloc(PRINTK_LOG_LINE_MAX + PRINTK_PREFIX_MAX, GFP_KERNEL);
if (!text)
return -ENOMEM;
@@ -1412,7 +1405,7 @@ static int syslog_print(char __user *buf, int size)
skip = syslog_partial;
msg = log_from_idx(syslog_idx);
n = msg_print_text(msg, true, syslog_time, text,
- LOG_LINE_MAX + PREFIX_MAX);
+ PRINTK_LOG_LINE_MAX + PRINTK_PREFIX_MAX);
if (n - syslog_partial <= size) {
/* message fits into buffer, move forward */
syslog_idx = log_next(syslog_idx);
@@ -1454,7 +1447,7 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
u32 idx;
bool time;
- text = kmalloc(LOG_LINE_MAX + PREFIX_MAX, GFP_KERNEL);
+ text = kmalloc(PRINTK_LOG_LINE_MAX + PRINTK_PREFIX_MAX, GFP_KERNEL);
if (!text)
return -ENOMEM;
@@ -1492,7 +1485,8 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
while (len >= 0 && seq < next_seq) {
struct printk_log *msg = log_from_idx(idx);
int textlen = msg_print_text(msg, true, time, text,
- LOG_LINE_MAX + PREFIX_MAX);
+ PRINTK_LOG_LINE_MAX +
+ PRINTK_PREFIX_MAX);
idx = log_next(idx);
seq++;
@@ -1845,7 +1839,7 @@ static inline u32 printk_caller_id(void)
* reached the console in case of a kernel crash.
*/
static struct cont {
- char buf[LOG_LINE_MAX];
+ char buf[PRINTK_LOG_LINE_MAX];
size_t len; /* length == 0 means unused buffer */
u32 caller_id; /* printk_caller_id() of first print */
u64 ts_nsec; /* time of first print */
@@ -1931,7 +1925,7 @@ int vprintk_store(int facility, int level,
const char *dict, size_t dictlen,
const char *fmt, va_list args)
{
- static char textbuf[LOG_LINE_MAX];
+ static char textbuf[PRINTK_LOG_LINE_MAX];
char *text = textbuf;
size_t text_len;
enum log_flags lflags = 0;
@@ -2088,8 +2082,6 @@ EXPORT_SYMBOL(printk);
#else /* CONFIG_PRINTK */
-#define LOG_LINE_MAX 0
-#define PREFIX_MAX 0
#define printk_time false
static u64 syslog_seq;
@@ -2396,7 +2388,7 @@ static inline int can_use_console(void)
void console_unlock(void)
{
static char ext_text[CONSOLE_EXT_LOG_MAX];
- static char text[LOG_LINE_MAX + PREFIX_MAX];
+ static char text[PRINTK_LOG_LINE_MAX + PRINTK_PREFIX_MAX];
unsigned long flags;
bool do_cond_resched, retry;
--
2.25.1
On (20/05/19 12:42), Joe Perches wrote:
> +static void __init print_cmdline(char *line)
> +{
> +#ifdef CONFIG_PRINTK
> + const char *prefix = "Kernel command line";
> + size_t len = strlen(line);
> +
> + while (len > PRINTK_LOG_LINE_MAX) {
> + char *pos = line;
> + char *last_pos = pos + PRINTK_LOG_LINE_MAX - 1;
> + char saved_char;
> + /* Find last space char within the maximum line length */
> + while ((pos = memchr(pos, ' ', len - (pos - line))) &&
> + (pos - line) < PRINTK_LOG_LINE_MAX - 1) {
Don't you need to also count in the 'prefix' length?
> + last_pos = pos;
> + }
> + saved_char = line[last_pos - line];
> + line[last_pos - line] = 0;
> + pr_notice("%s: %s\n", prefix, line);
> + prefix = "Kernel command line (continued)";
> + line[last_pos - line] = saved_char;
> + len -= pos - line;
> + line += pos - line;
> + }
> +
> + pr_notice("%s: %s\n", prefix, line);
> +#endif
> +}
I like this in general. And I agree that we better handle this
externally, on the printk() caller side, so that printk() will
still have sane limits and won't print a 1G string for example.
I wonder if we need to export PRINTK_LOG_LINE_MAX. Maybe we can
use here something rather random and much shorter instead. E.g.
256 chars. Hmm. How many crash/monitoring tools can get confused
by multiple "Kernel command line" prefixes?
-ss
On Wed, 2020-05-20 at 13:41 +0900, Sergey Senozhatsky wrote:
> On (20/05/19 12:42), Joe Perches wrote:
> > +static void __init print_cmdline(char *line)
> > +{
> > +#ifdef CONFIG_PRINTK
> > + const char *prefix = "Kernel command line";
> > + size_t len = strlen(line);
> > +
> > + while (len > PRINTK_LOG_LINE_MAX) {
> > + char *pos = line;
> > + char *last_pos = pos + PRINTK_LOG_LINE_MAX - 1;
> > + char saved_char;
> > + /* Find last space char within the maximum line length */
> > + while ((pos = memchr(pos, ' ', len - (pos - line))) &&
> > + (pos - line) < PRINTK_LOG_LINE_MAX - 1) {
>
> Don't you need to also count in the 'prefix' length?
yup.
> > + last_pos = pos;
> > + }
> > + saved_char = line[last_pos - line];
> > + line[last_pos - line] = 0;
> > + pr_notice("%s: %s\n", prefix, line);
> > + prefix = "Kernel command line (continued)";
> > + line[last_pos - line] = saved_char;
> > + len -= pos - line;
> > + line += pos - line;
> > + }
> > +
> > + pr_notice("%s: %s\n", prefix, line);
> > +#endif
> > +}
>
> I like this in general. And I agree that we better handle this
> externally, on the printk() caller side, so that printk() will
> still have sane limits and won't print a 1G string for example.
>
> I wonder if we need to export PRINTK_LOG_LINE_MAX.
I think a #define works well enough.(
> Maybe we can
> use here something rather random and much shorter instead. E.g.
> 256 chars. Hmm. How
min(some_max like 132/256, PRINTK_LOG_LINE_MAX)
would work.
> many crash/monitoring tools can get confused
> by multiple "Kernel command line" prefixes?
I doubt any as it's an init only function.
On (20/05/19 21:58), Joe Perches wrote:
[..]
> > Maybe we can
> > use here something rather random and much shorter instead. E.g.
> > 256 chars. Hmm. How
>
> min(some_max like 132/256, PRINTK_LOG_LINE_MAX)
>
> would work.
An alternative approach would be to do what we do in the
print_modules() (the list of modules which can definitely
be longer than 1K chars).
We can split command line in a loop - memchr(pos, ' ') - and
pr_cont() parts of the command line. pr_cont() has overflow
control and it flushes cont buffer before it overflows, so
we should not lose anything.
-ss
On Tue, 19 May 2020 11:29:46 +0800
王程刚 <[email protected]> wrote:
> Function pr_notice print max length maybe less than the command line length,
> need more times to print all.
> For example, arm64 has 2048 bytes command line length, but printk maximum
> length is only 1024 bytes.
Good catch, and if you use bootconfig, you can expand it longer than that.
>
> Signed-off-by: Chenggang Wang <[email protected]>
> ---
> init/main.c | 12 +++++++++++-
> 1 file changed, 11 insertions(+), 1 deletion(-)
>
> diff --git a/init/main.c b/init/main.c
> index 03371976d387..4cf676cc3305 100644
> --- a/init/main.c
> +++ b/init/main.c
> @@ -825,6 +825,16 @@ void __init __weak arch_call_rest_init(void)
> rest_init();
> }
>
> +static void __init print_cmdline(void)
> +{
> + const char *prefix = "Kernel command line: ";
> + int len = -strlen(prefix);
> +
> + len += pr_notice("%s%s\n", prefix, boot_command_line);
Why don't you use saved_command_line here? Those can be different
and the effective one is saved_command_line.
> + while (boot_command_line[len])
> + len += pr_notice("%s\n", &boot_command_line[len]);
Also, don't append "\n" unless you are sure there is an actual
option separator (not a space, because the option can be quoted.)
Thank you,
--
Masami Hiramatsu <[email protected]>
On Wed, 2020-05-20 at 21:10 +0900, Sergey Senozhatsky wrote:
> On (20/05/19 21:58), Joe Perches wrote:
> [..]
> > > Maybe we can
> > > use here something rather random and much shorter instead. E.g.
> > > 256 chars. Hmm. How
> >
> > min(some_max like 132/256, PRINTK_LOG_LINE_MAX)
> >
> > would work.
>
> An alternative approach would be to do what we do in the
> print_modules() (the list of modules which can definitely
> be longer than 1K chars).
>
> We can split command line in a loop - memchr(pos, ' ') - and
> pr_cont() parts of the command line. pr_cont() has overflow
> control and it flushes cont buffer before it overflows, so
> we should not lose anything.
It doesn't matter much here, but I believe
there's an 8k max buffer for pr_cont output.
include/linux/printk.h:#define CONSOLE_EXT_LOG_MAX 8192
Anyway, no worries, it simplifies the loop if
done that way.
On Wed, 20 May 2020 13:36:45 -0700 Joe Perches <[email protected]> wrote:
> On Wed, 2020-05-20 at 21:10 +0900, Sergey Senozhatsky wrote:
> > On (20/05/19 21:58), Joe Perches wrote:
> > [..]
> > > > Maybe we can
> > > > use here something rather random and much shorter instead. E.g.
> > > > 256 chars. Hmm. How
> > >
> > > min(some_max like 132/256, PRINTK_LOG_LINE_MAX)
> > >
> > > would work.
> >
> > An alternative approach would be to do what we do in the
> > print_modules() (the list of modules which can definitely
> > be longer than 1K chars).
> >
> > We can split command line in a loop - memchr(pos, ' ') - and
> > pr_cont() parts of the command line. pr_cont() has overflow
> > control and it flushes cont buffer before it overflows, so
> > we should not lose anything.
>
> It doesn't matter much here, but I believe
> there's an 8k max buffer for pr_cont output.
>
> include/linux/printk.h:#define CONSOLE_EXT_LOG_MAX 8192
>
> Anyway, no worries, it simplifies the loop if
> done that way.
I'm wondering if we shold add a kernel puts() (putsk()? yuk) which can
puts() a string of any length.
I'm counting around 150 instances of printk("%s", ...) and pr_foo("%s",
...) which could perhaps be converted, thus saving an argument.
On Wed, 2020-05-20 at 18:00 -0700, Andrew Morton wrote:
> On Wed, 20 May 2020 13:36:45 -0700 Joe Perches <[email protected]> wrote:
>
> > On Wed, 2020-05-20 at 21:10 +0900, Sergey Senozhatsky wrote:
> > > On (20/05/19 21:58), Joe Perches wrote:
> > > [..]
> > > > > Maybe we can
> > > > > use here something rather random and much shorter instead. E.g.
> > > > > 256 chars. Hmm. How
> > > >
> > > > min(some_max like 132/256, PRINTK_LOG_LINE_MAX)
> > > >
> > > > would work.
> > >
> > > An alternative approach would be to do what we do in the
> > > print_modules() (the list of modules which can definitely
> > > be longer than 1K chars).
> > >
> > > We can split command line in a loop - memchr(pos, ' ') - and
> > > pr_cont() parts of the command line. pr_cont() has overflow
> > > control and it flushes cont buffer before it overflows, so
> > > we should not lose anything.
> >
> > It doesn't matter much here, but I believe
> > there's an 8k max buffer for pr_cont output.
> >
> > include/linux/printk.h:#define CONSOLE_EXT_LOG_MAX 8192
> >
> > Anyway, no worries, it simplifies the loop if
> > done that way.
>
> I'm wondering if we shold add a kernel puts() (putsk()? yuk) which can
> puts() a string of any length.
>
> I'm counting around 150 instances of printk("%s", ...) and pr_foo("%s",
> ...) which could perhaps be converted, thus saving an argument.
I'd expect that it hardly matters.
printk(KERN_CONT "string") works.
On (20/05/20 13:36), Joe Perches wrote:
> > We can split command line in a loop - memchr(pos, ' ') - and
> > pr_cont() parts of the command line. pr_cont() has overflow
> > control and it flushes cont buffer before it overflows, so
> > we should not lose anything.
>
> It doesn't matter much here, but I believe
> there's an 8k max buffer for pr_cont output.
>
> include/linux/printk.h:#define CONSOLE_EXT_LOG_MAX 8192
This is for extended payload - the key:value dictionaries
which device core appends to normal printk() messages. We
don't have that many consoles that handle extended output
(netcon and, maybe, a few more).
-ss
On (20/05/20 18:00), Andrew Morton wrote:
[..]
> I'm wondering if we shold add a kernel puts() (putsk()? yuk) which can
> puts() a string of any length.
>
> I'm counting around 150 instances of printk("%s", ...) and pr_foo("%s",
> ...) which could perhaps be converted, thus saving an argument.
Can you point me at some examples?
-ss
On Thu, 21 May 2020 13:36:28 +0900 Sergey Senozhatsky <[email protected]> wrote:
> On (20/05/20 18:00), Andrew Morton wrote:
> [..]
> > I'm wondering if we shold add a kernel puts() (putsk()? yuk) which can
> > puts() a string of any length.
> >
> > I'm counting around 150 instances of printk("%s", ...) and pr_foo("%s",
> > ...) which could perhaps be converted, thus saving an argument.
>
> Can you point me at some examples?
>
./arch/powerpc/kernel/udbg.c: printk("%s", s);
./arch/powerpc/xmon/nonstdio.c: printk("%s", xmon_outbuf);
./arch/um/os-Linux/drivers/ethertap_user.c: printk("%s", output);
./arch/um/os-Linux/drivers/ethertap_user.c: printk("%s", output);
./arch/um/os-Linux/drivers/tuntap_user.c: printk("%s", out
etc.
My point is, if we created a length-unlimited puts() function for printing the
kernel command line, it could be reused in such places, resulting in a
smaller kernel.
On Wed 2020-05-20 21:40:07, Andrew Morton wrote:
> On Thu, 21 May 2020 13:36:28 +0900 Sergey Senozhatsky <[email protected]> wrote:
>
> > On (20/05/20 18:00), Andrew Morton wrote:
> > [..]
> > > I'm wondering if we shold add a kernel puts() (putsk()? yuk) which can
> > > puts() a string of any length.
> > >
> > > I'm counting around 150 instances of printk("%s", ...) and pr_foo("%s",
> > > ...) which could perhaps be converted, thus saving an argument.
> >
> > Can you point me at some examples?
> >
>
> ./arch/powerpc/kernel/udbg.c: printk("%s", s);
> ./arch/powerpc/xmon/nonstdio.c: printk("%s", xmon_outbuf);
> ./arch/um/os-Linux/drivers/ethertap_user.c: printk("%s", output);
> ./arch/um/os-Linux/drivers/ethertap_user.c: printk("%s", output);
> ./arch/um/os-Linux/drivers/tuntap_user.c: printk("%s", out
>
> etc.
>
> My point is, if we created a length-unlimited puts() function for printing the
> kernel command line, it could be reused in such places, resulting in a
> smaller kernel.
Interesting idea. Well, such a generic function would need to be safe
and do not modify the original string. We would need to implement
printk() variant that would support strigs limited by size instead
of the trailing '\0'. I am not sure if it is worth it.
Best Regards,
Petr
On (20/05/20 21:40), Andrew Morton wrote:
> > On (20/05/20 18:00), Andrew Morton wrote:
> > [..]
> > > I'm wondering if we shold add a kernel puts() (putsk()? yuk) which can
> > > puts() a string of any length.
> > >
> > > I'm counting around 150 instances of printk("%s", ...) and pr_foo("%s",
> > > ...) which could perhaps be converted, thus saving an argument.
> >
> > Can you point me at some examples?
> >
>
> ./arch/powerpc/kernel/udbg.c: printk("%s", s);
> ./arch/powerpc/xmon/nonstdio.c: printk("%s", xmon_outbuf);
> ./arch/um/os-Linux/drivers/ethertap_user.c: printk("%s", output);
> ./arch/um/os-Linux/drivers/ethertap_user.c: printk("%s", output);
> ./arch/um/os-Linux/drivers/tuntap_user.c: printk("%s", out
Hmm, interesting.
output = uml_kmalloc(UM_KERN_PAGE_SIZE, UM_GFP_KERNEL);
read_output(fd, output, UM_KERN_PAGE_SIZE);
printk("%s", output);
kfree(output);
> etc.
>
> My point is, if we created a length-unlimited puts() function for printing the
> kernel command line, it could be reused in such places
A function that prints the kernel command line is a bit different
in the way that we can split command line arguments - they are
space separated, which is very convenient - so we would pr_cont()
parts of command line individually. This has an advantage that we
won't \r\n in the middle of the parameter.
Looking at examples, it seems that most of them simply do a single
printk() with arbitrary sized buffers that contain random data,
not necessarily space separated. So same problem - we truncate
messages (maybe?), but needs a slightly different solution (?).
-ss
On Tue 2020-05-19 12:42:35, Joe Perches wrote:
> ARM may have its longest possible command line larger than the longest
> possible printk.
>
> If necessary, emit the commend line on multiple lines.
>
> Signed-off-by: Joe Perches <[email protected]>
> ---
>
> compiled, untested
>
> init/main.c | 31 ++++++++++++++++++++++++++++++-
> 1 file changed, 30 insertions(+), 1 deletion(-)
>
> diff --git a/init/main.c b/init/main.c
> index b63a3c001ac4..b3ebbbc129ae 100644
> --- a/init/main.c
> +++ b/init/main.c
> @@ -826,6 +826,34 @@ void __init __weak arch_call_rest_init(void)
> rest_init();
> }
>
> +static void __init print_cmdline(char *line)
> +{
> +#ifdef CONFIG_PRINTK
> + const char *prefix = "Kernel command line";
> + size_t len = strlen(line);
> +
> + while (len > PRINTK_LOG_LINE_MAX) {
> + char *pos = line;
> + char *last_pos = pos + PRINTK_LOG_LINE_MAX - 1;
> + char saved_char;
> + /* Find last space char within the maximum line length */
> + while ((pos = memchr(pos, ' ', len - (pos - line))) &&
> + (pos - line) < PRINTK_LOG_LINE_MAX - 1) {
> + last_pos = pos;
> + }
strchr() would safe the length calculation:
while ((pos = strchr(pos, ' ')) &&
(pos - line) < PRINTK_LOG_LINE_MAX - 1) {
last_pos = pos;
}
> + saved_char = line[last_pos - line];
> + line[last_pos - line] = 0;
This looks less cryptic:
saved_char = *last_pos;
*last_pos = '\0';
> + pr_notice("%s: %s\n", prefix, line);
> + prefix = "Kernel command line (continued)";
> + line[last_pos - line] = saved_char;
> + len -= pos - line;
> + line += pos - line;
'pos' might be NULL when there is no ' ' in the string. What about?
len -= last_pos - line;
line = last_pos;
> + }
> +
> + pr_notice("%s: %s\n", prefix, line);
> +#endif
> +}
Plus, the code should count the prefix length when splitting the line as
reported by Sergey.
Best Regards,
Petr
On Tue 2020-05-19 12:42:34, Joe Perches wrote:
> Make the printk maximum line length globally available.
Please, mention the reason that it will be used to split too long
kernel command lines.
> Miscellanea:
>
> o Prefix the defines with PRINTK_
>
> Signed-off-by: Joe Perches <[email protected]>
Otherwise, I am fine with it:
Acked-by: Petr Mladek <[email protected]>
Best Regards,
Petr
On Thu, May 21, 2020 at 02:31:17PM +0200, Petr Mladek wrote:
> On Wed 2020-05-20 21:40:07, Andrew Morton wrote:
> > On Thu, 21 May 2020 13:36:28 +0900 Sergey Senozhatsky <[email protected]> wrote:
> >
> > > On (20/05/20 18:00), Andrew Morton wrote:
> > > [..]
> > > > I'm wondering if we shold add a kernel puts() (putsk()? yuk) which can
> > > > puts() a string of any length.
> > > >
> > > > I'm counting around 150 instances of printk("%s", ...) and pr_foo("%s",
> > > > ...) which could perhaps be converted, thus saving an argument.
> > >
> > > Can you point me at some examples?
> > >
> >
> > ./arch/powerpc/kernel/udbg.c: printk("%s", s);
> > ./arch/powerpc/xmon/nonstdio.c: printk("%s", xmon_outbuf);
> > ./arch/um/os-Linux/drivers/ethertap_user.c: printk("%s", output);
> > ./arch/um/os-Linux/drivers/ethertap_user.c: printk("%s", output);
> > ./arch/um/os-Linux/drivers/tuntap_user.c: printk("%s", out
> >
> > etc.
> >
> > My point is, if we created a length-unlimited puts() function for printing the
> > kernel command line, it could be reused in such places, resulting in a
> > smaller kernel.
>
> Interesting idea. Well, such a generic function would need to be safe
> and do not modify the original string. We would need to implement
> printk() variant that would support strigs limited by size instead
> of the trailing '\0'. I am not sure if it is worth it.
>
> Best Regards,
> Petr
You don't need a printk variant for strings -- you'd only need one if
you wanted formatted output of unlimited length. Using printk("%.*s",
chunk_size, str) should print at most chunk_size characters from str.
The puts could then just be a loop around that.
Something like:
do {
printed = printk("%.*s", chunk_size, str);
str += printed;
} while (printed >= chunk_size);
On Tue, May 19, 2020 at 12:42:35PM -0700, Joe Perches wrote:
> ARM may have its longest possible command line larger than the longest
> possible printk.
>
> If necessary, emit the commend line on multiple lines.
>
> Signed-off-by: Joe Perches <[email protected]>
> ---
>
> compiled, untested
>
> init/main.c | 31 ++++++++++++++++++++++++++++++-
> 1 file changed, 30 insertions(+), 1 deletion(-)
>
> diff --git a/init/main.c b/init/main.c
> index b63a3c001ac4..b3ebbbc129ae 100644
> --- a/init/main.c
> +++ b/init/main.c
> @@ -826,6 +826,34 @@ void __init __weak arch_call_rest_init(void)
> rest_init();
> }
>
> +static void __init print_cmdline(char *line)
> +{
> +#ifdef CONFIG_PRINTK
> + const char *prefix = "Kernel command line";
> + size_t len = strlen(line);
> +
> + while (len > PRINTK_LOG_LINE_MAX) {
> + char *pos = line;
> + char *last_pos = pos + PRINTK_LOG_LINE_MAX - 1;
> + char saved_char;
> + /* Find last space char within the maximum line length */
> + while ((pos = memchr(pos, ' ', len - (pos - line))) &&
> + (pos - line) < PRINTK_LOG_LINE_MAX - 1) {
> + last_pos = pos;
> + }
> + saved_char = line[last_pos - line];
> + line[last_pos - line] = 0;
> + pr_notice("%s: %s\n", prefix, line);
> + prefix = "Kernel command line (continued)";
> + line[last_pos - line] = saved_char;
> + len -= pos - line;
> + line += pos - line;
> + }
> +
> + pr_notice("%s: %s\n", prefix, line);
> +#endif
I might be missing something, but this seems broken:
(1) If there is a ' ', the memchr will set pos to the ' ' the first time
through the inner loop, and then go into an infinite loop? You want
memrchr here but the kernel doesn't seem to have one.
(2) If there are no remaining ' 's pos will be NULL and the last two
lines in the outer loop use it -- those should be last_pos instead?
(3) Once those are fixed, you need to ensure you make progress: if
there's exactly one ' ' remaining, at the very beginning of the
remaining line, you need to print upto the PRINTK_LOG_LINE_MAX, not 0
bytes.
On Thu, 2020-05-21 at 11:59 -0400, Arvind Sankar wrote:
> On Tue, May 19, 2020 at 12:42:35PM -0700, Joe Perches wrote:
> > ARM may have its longest possible command line larger than the longest
> > possible printk.
[]
> I might be missing something, but this seems broken:
probably, note the "untested" bit.
> (1) If there is a ' ', the memchr will set pos to the ' ' the first time
> through the inner loop, and then go into an infinite loop? You want
> memrchr here but the kernel doesn't seem to have one.
Right. I did look and didn't find one and didn't
want to add it just for this use.
Make the printk output maximum line length globally available.
This can be used to emit logging messages lines that exceed
the single printk maximum length line.
e.g.: the kernel boot command on ARM can be up to 2048 chars
Miscellanea:
o Prefix the defines with PRINTK_
Signed-off-by: Joe Perches <[email protected]>
Acked-by: Petr Mladek <[email protected]>
---
include/linux/printk.h | 18 ++++++++++++++++++
kernel/printk/printk.c | 28 ++++++++++------------------
2 files changed, 28 insertions(+), 18 deletions(-)
diff --git a/include/linux/printk.h b/include/linux/printk.h
index 38beb97e7018..850dc4d4356f 100644
--- a/include/linux/printk.h
+++ b/include/linux/printk.h
@@ -43,6 +43,24 @@ static inline const char *printk_skip_headers(const char *buffer)
#define CONSOLE_EXT_LOG_MAX 8192
+/* Maximum length of a single printk */
+
+#ifdef CONFIG_PRINTK
+
+#ifdef CONFIG_PRINTK_CALLER
+#define PRINTK_PREFIX_MAX 48
+#else
+#define PRINTK_PREFIX_MAX 32
+#endif
+#define PRINTK_LOG_LINE_MAX (1024 - PRINTK_PREFIX_MAX)
+
+#else
+
+#define PRINTK_PREFIX_MAX 0
+#define PRINTK_LOG_LINE_MAX 0
+
+#endif
+
/* printk's without a loglevel use this.. */
#define MESSAGE_LOGLEVEL_DEFAULT CONFIG_MESSAGE_LOGLEVEL_DEFAULT
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 4f1cc4acef41..fc22a494ef0c 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -443,13 +443,6 @@ static u64 exclusive_console_stop_seq;
static u64 clear_seq;
static u32 clear_idx;
-#ifdef CONFIG_PRINTK_CALLER
-#define PREFIX_MAX 48
-#else
-#define PREFIX_MAX 32
-#endif
-#define LOG_LINE_MAX (1024 - PREFIX_MAX)
-
#define LOG_LEVEL(v) ((v) & 0x07)
#define LOG_FACILITY(v) ((v) >> 3 & 0xff)
@@ -825,7 +818,7 @@ static ssize_t devkmsg_write(struct kiocb *iocb, struct iov_iter *from)
size_t len = iov_iter_count(from);
ssize_t ret = len;
- if (!user || len > LOG_LINE_MAX)
+ if (!user || len > PRINTK_LOG_LINE_MAX)
return -EINVAL;
/* Ignore when user logging is disabled. */
@@ -1341,7 +1334,7 @@ static size_t msg_print_text(const struct printk_log *msg, bool syslog,
const char *text = log_text(msg);
size_t text_size = msg->text_len;
size_t len = 0;
- char prefix[PREFIX_MAX];
+ char prefix[PRINTK_PREFIX_MAX];
const size_t prefix_len = print_prefix(msg, syslog, time, prefix);
do {
@@ -1382,7 +1375,7 @@ static int syslog_print(char __user *buf, int size)
struct printk_log *msg;
int len = 0;
- text = kmalloc(LOG_LINE_MAX + PREFIX_MAX, GFP_KERNEL);
+ text = kmalloc(PRINTK_LOG_LINE_MAX + PRINTK_PREFIX_MAX, GFP_KERNEL);
if (!text)
return -ENOMEM;
@@ -1412,7 +1405,7 @@ static int syslog_print(char __user *buf, int size)
skip = syslog_partial;
msg = log_from_idx(syslog_idx);
n = msg_print_text(msg, true, syslog_time, text,
- LOG_LINE_MAX + PREFIX_MAX);
+ PRINTK_LOG_LINE_MAX + PRINTK_PREFIX_MAX);
if (n - syslog_partial <= size) {
/* message fits into buffer, move forward */
syslog_idx = log_next(syslog_idx);
@@ -1454,7 +1447,7 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
u32 idx;
bool time;
- text = kmalloc(LOG_LINE_MAX + PREFIX_MAX, GFP_KERNEL);
+ text = kmalloc(PRINTK_LOG_LINE_MAX + PRINTK_PREFIX_MAX, GFP_KERNEL);
if (!text)
return -ENOMEM;
@@ -1492,7 +1485,8 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
while (len >= 0 && seq < next_seq) {
struct printk_log *msg = log_from_idx(idx);
int textlen = msg_print_text(msg, true, time, text,
- LOG_LINE_MAX + PREFIX_MAX);
+ PRINTK_LOG_LINE_MAX +
+ PRINTK_PREFIX_MAX);
idx = log_next(idx);
seq++;
@@ -1845,7 +1839,7 @@ static inline u32 printk_caller_id(void)
* reached the console in case of a kernel crash.
*/
static struct cont {
- char buf[LOG_LINE_MAX];
+ char buf[PRINTK_LOG_LINE_MAX];
size_t len; /* length == 0 means unused buffer */
u32 caller_id; /* printk_caller_id() of first print */
u64 ts_nsec; /* time of first print */
@@ -1931,7 +1925,7 @@ int vprintk_store(int facility, int level,
const char *dict, size_t dictlen,
const char *fmt, va_list args)
{
- static char textbuf[LOG_LINE_MAX];
+ static char textbuf[PRINTK_LOG_LINE_MAX];
char *text = textbuf;
size_t text_len;
enum log_flags lflags = 0;
@@ -2088,8 +2082,6 @@ EXPORT_SYMBOL(printk);
#else /* CONFIG_PRINTK */
-#define LOG_LINE_MAX 0
-#define PREFIX_MAX 0
#define printk_time false
static u64 syslog_seq;
@@ -2396,7 +2388,7 @@ static inline int can_use_console(void)
void console_unlock(void)
{
static char ext_text[CONSOLE_EXT_LOG_MAX];
- static char text[LOG_LINE_MAX + PREFIX_MAX];
+ static char text[PRINTK_LOG_LINE_MAX + PRINTK_PREFIX_MAX];
unsigned long flags;
bool do_cond_resched, retry;
On (20/05/21 11:40), Joe Perches wrote:
> Make the printk output maximum line length globally available.
>
> This can be used to emit logging messages lines that exceed
> the single printk maximum length line.
>
> e.g.: the kernel boot command on ARM can be up to 2048 chars
Speaking of the kernel boot command I still think that we can use
the existing approach here - split the command line and feed it
token by token to pr_cont(). printk() will handle everything
internally without exposing any implementation details (different
prefix sizes which depend on .config, etc. etc.) and requiring less
code.
> +/* Maximum length of a single printk */
> +
> +#ifdef CONFIG_PRINTK
> +
> +#ifdef CONFIG_PRINTK_CALLER
> +#define PRINTK_PREFIX_MAX 48
> +#else
> +#define PRINTK_PREFIX_MAX 32
> +#endif
> +#define PRINTK_LOG_LINE_MAX (1024 - PRINTK_PREFIX_MAX)
> +
> +#else
> +
> +#define PRINTK_PREFIX_MAX 0
> +#define PRINTK_LOG_LINE_MAX 0
> +
> +#endif
!CONFIG_PRINTK case is concerning.
We depend on correct zero-sized LOG_LINE handling, otherwise things
like "p + PRINTK_LOG_LINE_MAX - 1" or "(p - line) < PRINTK_LOG_LINE_MAX - 1)"
are ticking bombs, waiting for !PRINTK config and off-by-one writes/reads.
Unless the code in question does more checks or is wrapped into
'#ifdef CONFIG_PRINTK', like you did in your print_cmdline() patch.
We may do a counter measure here, and simply undefine PRINTK_LOG_LINE_MAX
for !PRINTK config, thus forcing any code which uses PRINTK_LOG_LINE_MAX
to be wrapped into `#ifdef CONFIG_PRINTK`. But I think that pr_cont()-based
loop is safer and is easier to code.
If we set to implement "print any random very large string", then I'd
prefer to do it on the printk() side, just like was suggested by Andrew,
rather than forcing people to implement similar loops in various parts
of the kernel.
-ss
Greeting,
FYI, we noticed the following commit (built with gcc-7):
commit: d0bcc26c0dbe6ac00f0d2ecaaf1312a6de57aaba ("[RFC PATCH 2/2] init: Allow multi-line output of kernel command line")
url: https://github.com/0day-ci/linux/commits/Joe-Perches/printk-init-multi-line-kernel-command-line-logging/20200520-034430
in testcase: boot
on test machine: qemu-system-i386 -enable-kvm -cpu SandyBridge -smp 2 -m 16G
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+-----------------------------------------------------------------------------+------------+------------+
| | 33d52c37a7 | d0bcc26c0d |
+-----------------------------------------------------------------------------+------------+------------+
| BUG:kernel_hang_in_early-boot_stage,last_printk:early_console_in_setup_code | 0 | 12 |
+-----------------------------------------------------------------------------+------------+------------+
If you fix the issue, kindly add following tag
Reported-by: kernel test robot <[email protected]>
early console in setup code
<--- kernel actually hang here, below is helper information, please refer to
attached dmesg.xz
BUG: kernel hang in early-boot stage, last printk: early console in setup code
Linux version 5.7.0-rc6-00012-gd0bcc26c0dbe6 #2
Command line: ip=::::vm-snb-i386-8::dhcp root=/dev/ram0 user=lkp job=/lkp/jobs/scheduled/vm-snb-i386-8/boot-1-quantal-i386-core-20190426.cgz-d0bcc26c0dbe6ac00f0d2ecaaf1312a6de57aaba-20200522-12855-1j2fvp6-2.yaml ARCH=i386 kconfig=i386-randconfig-r011-20200520 branch=linux-devel/devel-hourly-2020052109 commit=d0bcc26c0dbe6ac00f0d2ecaaf1312a6de57aaba BOOT_IMAGE=/pkg/linux/i386-randconfig-r011-20200520/gcc-7/d0bcc26c0dbe6ac00f0d2ecaaf1312a6de57aaba/vmlinuz-5.7.0-rc6-00012-gd0bcc26c0dbe6 max_uptime=600 RESULT_ROOT=/result/boot/1/vm-snb-i386/quantal-i386-core-20190426.cgz/i386-randconfig-r011-20200520/gcc-7/d0bcc26c0dbe6ac00f0d2ecaaf1312a6de57aaba/3 LKP_SERVER=inn selinux=0 debug apic=debug sysrq_always_enabled rcupdate.rcu_cpu_stall_timeout=100 net.ifnames=0 printk.devkmsg=on panic=-1 softlockup_panic=1 nmi_watchdog=panic oops=panic load_ramdisk=2 prompt_ramdisk=0 drbd.minor_count=8 systemd.log_level=err ignore_loglevel console=tty0 earlyprintk=ttyS0,115200 console=ttyS0,115200 vga=normal rw rcuperf.shutdown=0 watchdog_thresh=60
Elapsed time: 480
for parent commit, the dmesg will look like below (also attached as dmesg-33d52c37a7.xz)
========================================================================================
early console in setup code
[ 0.000000] Linux version 5.7.0-rc6-00011-g33d52c37a7c3e (kbuild@e4179002dd1b) (gcc version 7.5.0 (Ubuntu 7.5.0-6ubuntu2), GNU ld (GNU Binutils for
Debian) 2.34) #1 PREEMPT Fri May 22 11:35:58 CST 2020
[ 0.000000] KERNEL supported cpus:
...
[ 0.063341] Built 1 zonelists, mobility grouping on. Total pages: 225452
[ 0.063361] Kernel command line: ip=::::vm-snb-i386-29::dhcp root=/dev/ram0 user=lkp job=/lkp/jobs/scheduled/vm-snb-i386-29/boot-1-quantal-i386-core
-20190426.cgz-33d52c37a7c3eb4543234a9dd0faf1c80a462f99-20200522-12645-1yvq3z6-0.yaml ARCH=i386 kconfig=i386-randconfig-r011-20200520 branch=linux-devel
/devel-hourly-2020052109 commit=33d52c37a7c3eb4543234a9dd0faf1c80a462f99 BOOT_IMAGE=/pkg/linux/i386-randconfig-r011-20200520/gcc-7/33d52c37a7c3eb454323
4a9dd0faf1c80a462f99/vmlinuz-5.7.0-rc6-00011-g33d52c37a7c3e max_uptime=600 RESULT_ROOT=/result/boot/1/vm-snb-i386/quantal-i386-core-20190426.cgz/i386-r
andconfig-r011-20200520/gcc-7/33d52c37a7c3eb4543234a9dd0faf1c80a462f99/0 LKP_SERVER=inn selinux=0 debug apic=debug sysrq_always_enabled rcupdate.rcu_cp
u_stall_timeout=100 net.ifnames=0 printk.devkmsg=on panic=-1 softlockup_panic=1 nmi_watchdog=panic oops=panic load_ramdisk=2 prompt_ramdisk=0 drbd.mino
r_count=8 systemd.log_level=err ignore_loglevel console=tty0 earlyprintk=ttyS0,115200 console=ttyS
[ 0.064514] sysrq: sysrq always enabled.
========================================================================================
To reproduce:
# build kernel
cd linux
cp config-5.7.0-rc6-00012-gd0bcc26c0dbe6 .config
make HOSTCC=gcc-7 CC=gcc-7 ARCH=i386 olddefconfig prepare modules_prepare bzImage
git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp qemu -k <bzImage> job-script # job-script is attached in this email
Thanks,
Oliver Sang