2017-03-15 10:33:17

by Aleksey Makarov

[permalink] [raw]
Subject: [PATCH v5 0/3] printk: fix double printing with earlycon

If a console was specified by ACPI SPCR table _and_ command line parameters like
"console=ttyAMA0" _and_ "earlycon" were specified, then log messages
appear twice.

This issue was addressed in the patch [1] but the approach was wrong and
a revert [2] was suggested.

First two patches "printk: fix name/type/scope of preferred_console var" and
"printk: rename selected_console -> preferred_console" were sent some
time ago as one patch "printk: fix name and type of some variables" [3].
They fix name/type/scope of some variables without changing the logic.

The real fix is in the second patch. The root cause is that the code traverses
the list of specified consoles (the `console_cmdline` array) and stops at the
first match. But it may happen that the same console is referred by
the elements of this array twice:

pl011,mmio,0x87e024000000,115200 -- from SPCR
ttyAMA0 -- from command line

but in this case `preferred_console` points to the second entry and
the flag CON_CONSDEV is not set, so bootconsole is not deregistered.

To fix that, introduce an invariant "The last non-braille console is always the
preferred one" on the entries of the console_cmdline array and don't try to
check for double entries. Then traverse it in reverse order to be sure that if
the console is preferred then it will be the first matching entry.

v5:
- rewrite 3/3. Insetead of rearranging the loop, introduce an invariant
"The last non-braille console is always the preferred one" on the
entries of the console_cmdline array and don't try to check for double
entries. Then traverse it in reverse order to be sure that if the console
is preferred then it will be the first matching entry.
- add a better explanation from Petr Mladek for 2/3.

v4:
It was not sent upstream due to some problems in implementation of 3/3.
- add some Acked-by: and Reviewed-by: to 1/3 and 2/3
- v2 was closer to the original logic, even though v3 looked simpler.
The problem is that newcon->setup() is called twice, firstly
from newcon->match(), then explicitly. And it could be called third time
later in another call to newcon->match(). Implement correct sequence:
1) try to match against preferred_console,
2) if that fails check other entries of console_cmdline.
Also move braille console matching/registration to a separate pass to simplify
the code.

v3 (only for 3/3):
https://lkml.kernel.org/r/[email protected]
- v2 still changes the logic of the code and calls newcon->match() several
times. V3 fixes that. It initially matches the console against
the preferred_console entry, and then if that fails, against other entries.

v2:
https://lkml.kernel.org/r/[email protected]
- split the patch that renames `selected_console` and `preferred_console`
into two patches (Steven Rostedt)
- add a comment explaining why we need a separate match to check for
preferred_console (Steven Rostedt)
- v1 of this patchset changed the logic of console initialization a bit.
That could lead to bugs/incompatibilities. Use the exactly the same
logic as in the original code.

v1:
https://lkml.kernel.org/r/[email protected]

[1] https://lkml.kernel.org/r/[email protected]
commit aea9a80ba98a ("tty: serial: pl011: add ttyAMA for matching pl011 console")
[2] https://lkml.kernel.org/r/[email protected]
[3] https://lkml.kernel.org/r/[email protected]

Aleksey Makarov (3):
printk: fix name/type/scope of preferred_console var
printk: rename selected_console -> preferred_console
printk: fix double printing with earlycon

kernel/printk/printk.c | 61 ++++++++++++++++++++++++++++++--------------------
1 file changed, 37 insertions(+), 24 deletions(-)

--
2.12.0


2017-03-15 10:33:26

by Aleksey Makarov

[permalink] [raw]
Subject: [PATCH v5 1/3] printk: fix name/type/scope of preferred_console var

The variable preferred_console is used only inside register_console()
and its semantics is boolean. It is negative when no console has been
made preferred.

Make it static bool and rename to has_preferred.

Renaming was suggested by Peter Hurley

Acked-by: Petr Mladek <[email protected]>
Reviewed-by: Steven Rostedt (VMware) <[email protected]>
Reviewed-by: Sergey Senozhatsky <[email protected]>
Signed-off-by: Aleksey Makarov <[email protected]>
---
kernel/printk/printk.c | 12 ++++++------
1 file changed, 6 insertions(+), 6 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 2984fb0f0257..80bc1b72d03d 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -271,7 +271,6 @@ static struct console *exclusive_console;
static struct console_cmdline console_cmdline[MAX_CMDLINECONSOLES];

static int selected_console = -1;
-static int preferred_console = -1;
int console_set_on_cmdline;
EXPORT_SYMBOL(console_set_on_cmdline);

@@ -2409,6 +2408,7 @@ void register_console(struct console *newcon)
unsigned long flags;
struct console *bcon = NULL;
struct console_cmdline *c;
+ static bool has_preferred;

if (console_drivers)
for_each_console(bcon)
@@ -2435,15 +2435,15 @@ void register_console(struct console *newcon)
if (console_drivers && console_drivers->flags & CON_BOOT)
bcon = console_drivers;

- if (preferred_console < 0 || bcon || !console_drivers)
- preferred_console = selected_console;
+ if (!has_preferred || bcon || !console_drivers)
+ has_preferred = selected_console >= 0;

/*
* See if we want to use this console driver. If we
* didn't select a console we take the first one
* that registers here.
*/
- if (preferred_console < 0) {
+ if (!has_preferred) {
if (newcon->index < 0)
newcon->index = 0;
if (newcon->setup == NULL ||
@@ -2451,7 +2451,7 @@ void register_console(struct console *newcon)
newcon->flags |= CON_ENABLED;
if (newcon->device) {
newcon->flags |= CON_CONSDEV;
- preferred_console = 0;
+ has_preferred = true;
}
}
}
@@ -2486,7 +2486,7 @@ void register_console(struct console *newcon)
newcon->flags |= CON_ENABLED;
if (i == selected_console) {
newcon->flags |= CON_CONSDEV;
- preferred_console = selected_console;
+ has_preferred = true;
}
break;
}
--
2.12.0

2017-03-15 10:33:39

by Aleksey Makarov

[permalink] [raw]
Subject: [PATCH v5 2/3] printk: rename selected_console -> preferred_console

The variable selected_console is set in __add_preferred_console()
to point to the last console parameter that was added to the
console_cmdline array.

Rename it to preferred_console so that the name reflects the usage.

Petr Mladek:
"[..] the selected_console/preferred_console
value is used to keep the console first in the console_drivers list.
IMHO, the main effect is that each line will first appear on this
console, see call_console_drivers(). But the message will still
appear also on all other enabled consoles. From this point,
the name "preferred" sounds better to me. More consoles
are selected (enabled) and only one is preferred (first)."

Acked-by: Steven Rostedt (VMware) <[email protected]>
Acked-by: Petr Mladek <[email protected]>
Reviewed-by: Sergey Senozhatsky <[email protected]>
Suggested-by: Peter Hurley <[email protected]>
Signed-off-by: Aleksey Makarov <[email protected]>
---
kernel/printk/printk.c | 10 +++++-----
1 file changed, 5 insertions(+), 5 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 80bc1b72d03d..fd752f0c8ef1 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -270,7 +270,7 @@ static struct console *exclusive_console;

static struct console_cmdline console_cmdline[MAX_CMDLINECONSOLES];

-static int selected_console = -1;
+static int preferred_console = -1;
int console_set_on_cmdline;
EXPORT_SYMBOL(console_set_on_cmdline);

@@ -1910,14 +1910,14 @@ static int __add_preferred_console(char *name, int idx, char *options,
i++, c++) {
if (strcmp(c->name, name) == 0 && c->index == idx) {
if (!brl_options)
- selected_console = i;
+ preferred_console = i;
return 0;
}
}
if (i == MAX_CMDLINECONSOLES)
return -E2BIG;
if (!brl_options)
- selected_console = i;
+ preferred_console = i;
strlcpy(c->name, name, sizeof(c->name));
c->options = options;
braille_set_options(c, brl_options);
@@ -2436,7 +2436,7 @@ void register_console(struct console *newcon)
bcon = console_drivers;

if (!has_preferred || bcon || !console_drivers)
- has_preferred = selected_console >= 0;
+ has_preferred = preferred_console >= 0;

/*
* See if we want to use this console driver. If we
@@ -2484,7 +2484,7 @@ void register_console(struct console *newcon)
}

newcon->flags |= CON_ENABLED;
- if (i == selected_console) {
+ if (i == preferred_console) {
newcon->flags |= CON_CONSDEV;
has_preferred = true;
}
--
2.12.0

2017-03-15 10:33:30

by Aleksey Makarov

[permalink] [raw]
Subject: [PATCH v5 3/3] printk: fix double printing with earlycon

If a console was specified by ACPI SPCR table _and_ command line
parameters like "console=ttyAMA0" _and_ "earlycon" were specified,
then log messages appear twice.

The root cause is that the code traverses the list of specified
consoles (the `console_cmdline` array) and stops at the first match.
But it may happen that the same console is referred by the elements
of this array twice:

pl011,mmio,0x87e024000000,115200 -- from SPCR
ttyAMA0 -- from command line

but in this case `preferred_console` points to the second entry and
the flag CON_CONSDEV is not set, so bootconsole is not deregistered.

To fix that, introduce an invariant "The last non-braille console
is always the preferred one" on the entries of the console_cmdline
array and don't try to check for double entries. Then traverse it
in reverse order to be sure that if the console is preferred then
it will be the first matching entry.

Reported-by: Sudeep Holla <[email protected]>
Signed-off-by: Aleksey Makarov <[email protected]>
---
kernel/printk/printk.c | 45 +++++++++++++++++++++++++++++----------------
1 file changed, 29 insertions(+), 16 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index fd752f0c8ef1..7dc53b2831fb 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -1902,20 +1902,25 @@ static int __add_preferred_console(char *name, int idx, char *options,
int i;

/*
- * See if this tty is not yet registered, and
- * if we have a slot free.
+ * Don't check if the console has already been registered, because it is
+ * pointless. After all, we can not check if two entries refer to
+ * the same console if one is matched with console->match(), and another
+ * by name/index:
+ *
+ * pl011,mmio,0x87e024000000,115200 -- added from SPCR
+ * ttyAMA0 -- added from command line
+ *
+ * Also this allows to maintain an invariant that will help to find if
+ * the matching console is preferred, see register_console():
+ *
+ * The last non-braille console is always the preferred one.
*/
- for (i = 0, c = console_cmdline;
- i < MAX_CMDLINECONSOLES && c->name[0];
- i++, c++) {
- if (strcmp(c->name, name) == 0 && c->index == idx) {
- if (!brl_options)
- preferred_console = i;
- return 0;
- }
- }
+ for (i = 0; i < MAX_CMDLINECONSOLES; i++)
+ if (!console_cmdline[i].name[0])
+ break;
if (i == MAX_CMDLINECONSOLES)
return -E2BIG;
+ c = console_cmdline + i;
if (!brl_options)
preferred_console = i;
strlcpy(c->name, name, sizeof(c->name));
@@ -2457,12 +2462,20 @@ void register_console(struct console *newcon)
}

/*
- * See if this console matches one we selected on
- * the command line.
+ * See if this console matches one we selected on the command line.
+ *
+ * The console_cmdline array is traversed in the reverse order because
+ * we want to be sure that if this console is preferred then it will be
+ * the first matching entry. We use the invariant that is maintained in
+ * __add_preferred_console().
*/
- for (i = 0, c = console_cmdline;
- i < MAX_CMDLINECONSOLES && c->name[0];
- i++, c++) {
+ for (i = MAX_CMDLINECONSOLES - 1; i >= 0; i--) {
+
+ if (!console_cmdline[i].name[0])
+ continue;
+
+ c = console_cmdline + i;
+
if (!newcon->match ||
newcon->match(newcon, c->name, c->index, c->options) != 0) {
/* default matching */
--
2.12.0

2017-03-15 16:59:22

by Petr Mladek

[permalink] [raw]
Subject: Re: [PATCH v5 3/3] printk: fix double printing with earlycon

On Wed 2017-03-15 13:28:52, Aleksey Makarov wrote:
> If a console was specified by ACPI SPCR table _and_ command line
> parameters like "console=ttyAMA0" _and_ "earlycon" were specified,
> then log messages appear twice.
>
> The root cause is that the code traverses the list of specified
> consoles (the `console_cmdline` array) and stops at the first match.
> But it may happen that the same console is referred by the elements
> of this array twice:
>
> pl011,mmio,0x87e024000000,115200 -- from SPCR
> ttyAMA0 -- from command line
>
> but in this case `preferred_console` points to the second entry and
> the flag CON_CONSDEV is not set, so bootconsole is not deregistered.
>
> To fix that, introduce an invariant "The last non-braille console
> is always the preferred one" on the entries of the console_cmdline
> array and don't try to check for double entries. Then traverse it
> in reverse order to be sure that if the console is preferred then
> it will be the first matching entry.
>
> Reported-by: Sudeep Holla <[email protected]>
> Signed-off-by: Aleksey Makarov <[email protected]>
> ---
> kernel/printk/printk.c | 45 +++++++++++++++++++++++++++++----------------
> 1 file changed, 29 insertions(+), 16 deletions(-)
>
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index fd752f0c8ef1..7dc53b2831fb 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -1902,20 +1902,25 @@ static int __add_preferred_console(char *name, int idx, char *options,
> int i;
>
> /*
> - * See if this tty is not yet registered, and
> - * if we have a slot free.
> + * Don't check if the console has already been registered, because it is
> + * pointless. After all, we can not check if two entries refer to
> + * the same console if one is matched with console->match(), and another
> + * by name/index:
> + *
> + * pl011,mmio,0x87e024000000,115200 -- added from SPCR
> + * ttyAMA0 -- added from command line
> + *
> + * Also this allows to maintain an invariant that will help to find if
> + * the matching console is preferred, see register_console():

It is an interesting idea.

I just wonder if the check for duplicates was there for a serious
reason. It is hard to say because it was already in the initial git
commit. In each case, MAX_CMDLINECONSOLES is 8. There is not much
space for duplicates.

Note that add_preferred_console() is called also from _probe() calls,
see

uart_add_one_port() -> of_console_check()
sunserial_console_match() -> add_preferred_console()

I wonder they might be called repeatedly, for example because
of suspend/restore, hotplug, module load/unload.

I would feel more comfortable if we keep the check for
duplicates here.

It is a pity that the console->match() calls have side effects.
I still wonder if the 4th version might be more safe. The
newcon->setup() call is called only when the console matches.
AFAIK, there is only one braille console. We should be on
the safe side if this one does not implement the match()
callback. Or is it even more complicated?

To be honest, I am not much familiar with the console registration
code. I am still trying to get a better picture. It is pity that
many function have unexpected side effects.

Best Regards,
Petr

2017-03-16 07:32:28

by Sergey Senozhatsky

[permalink] [raw]
Subject: Re: [PATCH v5 3/3] printk: fix double printing with earlycon

On (03/15/17 17:58), Petr Mladek wrote:
[..]
> On Wed 2017-03-15 13:28:52, Aleksey Makarov wrote:
> > If a console was specified by ACPI SPCR table _and_ command line
> > parameters like "console=ttyAMA0" _and_ "earlycon" were specified,
> > then log messages appear twice.
> >
> > The root cause is that the code traverses the list of specified
> > consoles (the `console_cmdline` array) and stops at the first match.
> > But it may happen that the same console is referred by the elements
> > of this array twice:
> >
> > pl011,mmio,0x87e024000000,115200 -- from SPCR
> > ttyAMA0 -- from command line
> >
> > but in this case `preferred_console` points to the second entry and
> > the flag CON_CONSDEV is not set, so bootconsole is not deregistered.
> >
> > To fix that, introduce an invariant "The last non-braille console
> > is always the preferred one" on the entries of the console_cmdline
> > array and don't try to check for double entries. Then traverse it
> > in reverse order to be sure that if the console is preferred then
> > it will be the first matching entry.

overall this approach looks interesting. but I need to look more at
this, since I'm not really familiar with this console registration thing.

your reverse traversal, Aleksey, makes sense to me, but there might be
things I'm missing.

> > @@ -1902,20 +1902,25 @@ static int __add_preferred_console(char *name, int idx, char *options,
> > int i;
> >
> > /*
> > - * See if this tty is not yet registered, and
> > - * if we have a slot free.
> > + * Don't check if the console has already been registered, because it is
> > + * pointless. After all, we can not check if two entries refer to
> > + * the same console if one is matched with console->match(), and another
> > + * by name/index:
> > + *
> > + * pl011,mmio,0x87e024000000,115200 -- added from SPCR
> > + * ttyAMA0 -- added from command line
> > + *
> > + * Also this allows to maintain an invariant that will help to find if
> > + * the matching console is preferred, see register_console():
>
> It is an interesting idea.
>
> I just wonder if the check for duplicates was there for a serious
> reason. It is hard to say because it was already in the initial git
> commit. In each case, MAX_CMDLINECONSOLES is 8. There is not much
> space for duplicates.

hm. as Petr mentioned, device tree may have its own console preferences
specified via stdout-path or linux,stdout-path. which ends up in
of_console_check()->add_preferred_console().
so we may look at a mix of command line, ACPI port redirection and DT.
DT may have aliases, etc. but I still suspect that that strcmp() is
probably not be completely pointless. some drivers call add_preferred_console()
directly, passing entries that might present in command line. e.g.
add_preferred_console("ttyS", 2, "115200");



by the way.
we might have a memory leak there.

drivers/of/base.c

bool of_console_check(struct device_node *dn, char *name, int index)
{
if (!dn || dn != of_stdout || console_set_on_cmdline)
return false;
return !add_preferred_console(name, index,
kstrdup(of_stdout_options, GFP_KERNEL));
}

printk/printk.c

static int __add_preferred_console(char *name, int idx, char *options,
char *brl_options)
{
struct console_cmdline *c;
int i;

/*
* See if this tty is not yet registered, and
* if we have a slot free.
*/
for (i = 0, c = console_cmdline;
i < MAX_CMDLINECONSOLES && c->name[0];
i++, c++) {
if (strcmp(c->name, name) == 0 && c->index == idx) {
if (!brl_options)
selected_console = i;
return 0;
}
}
if (i == MAX_CMDLINECONSOLES)
return -E2BIG;
if (!brl_options)
selected_console = i;
strlcpy(c->name, name, sizeof(c->name));
c->options = options;
braille_set_options(c, brl_options);

c->index = idx;
return 0;
}

int add_preferred_console(char *name, int idx, char *options)
{
return __add_preferred_console(name, idx, options, NULL);
}



kstrdup()-ed stdout options passed from of_console_check() are getting
lost when:

a) __add_preferred_console() returns -E2BIG
b) __add_preferred_console() finds a duplicate entry in console_cmdline


> I would feel more comfortable if we keep the check for
> duplicates here.

I would agree.

-ss

2017-03-16 10:41:17

by Aleksey Makarov

[permalink] [raw]
Subject: Re: [PATCH v5 3/3] printk: fix double printing with earlycon



On 03/15/2017 07:58 PM, Petr Mladek wrote:
> On Wed 2017-03-15 13:28:52, Aleksey Makarov wrote:
>> If a console was specified by ACPI SPCR table _and_ command line
>> parameters like "console=ttyAMA0" _and_ "earlycon" were specified,
>> then log messages appear twice.
>>
>> The root cause is that the code traverses the list of specified
>> consoles (the `console_cmdline` array) and stops at the first match.
>> But it may happen that the same console is referred by the elements
>> of this array twice:
>>
>> pl011,mmio,0x87e024000000,115200 -- from SPCR
>> ttyAMA0 -- from command line
>>
>> but in this case `preferred_console` points to the second entry and
>> the flag CON_CONSDEV is not set, so bootconsole is not deregistered.
>>
>> To fix that, introduce an invariant "The last non-braille console
>> is always the preferred one" on the entries of the console_cmdline
>> array and don't try to check for double entries. Then traverse it
>> in reverse order to be sure that if the console is preferred then
>> it will be the first matching entry.
>>
>> Reported-by: Sudeep Holla <[email protected]>
>> Signed-off-by: Aleksey Makarov <[email protected]>
>> ---
>> kernel/printk/printk.c | 45 +++++++++++++++++++++++++++++----------------
>> 1 file changed, 29 insertions(+), 16 deletions(-)
>>
>> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
>> index fd752f0c8ef1..7dc53b2831fb 100644
>> --- a/kernel/printk/printk.c
>> +++ b/kernel/printk/printk.c
>> @@ -1902,20 +1902,25 @@ static int __add_preferred_console(char *name, int idx, char *options,
>> int i;
>>
>> /*
>> - * See if this tty is not yet registered, and
>> - * if we have a slot free.
>> + * Don't check if the console has already been registered, because it is
>> + * pointless. After all, we can not check if two entries refer to
>> + * the same console if one is matched with console->match(), and another
>> + * by name/index:
>> + *
>> + * pl011,mmio,0x87e024000000,115200 -- added from SPCR
>> + * ttyAMA0 -- added from command line
>> + *
>> + * Also this allows to maintain an invariant that will help to find if
>> + * the matching console is preferred, see register_console():
>
> It is an interesting idea.
>
> I just wonder if the check for duplicates was there for a serious
> reason. It is hard to say because it was already in the initial git
> commit. In each case, MAX_CMDLINECONSOLES is 8. There is not much
> space for duplicates.
>
> Note that add_preferred_console() is called also from _probe() calls,
> see
>
> uart_add_one_port() -> of_console_check()
> sunserial_console_match() -> add_preferred_console()
>
> I wonder they might be called repeatedly, for example because
> of suspend/restore, hotplug, module load/unload.
>
> I would feel more comfortable if we keep the check for
> duplicates here.

Now I see the problem, thank you.

> It is a pity that the console->match() calls have side effects.
> I still wonder if the 4th version might be more safe.

I pushed v4 to the linaro git server:

https://git.linaro.org/people/aleksey.makarov/linux.git/commit/?h=amakarov/console2.19.v4&id=47a8227e37ca54d9cc7051abe9b3c2d072f4f75f

The problem with that approach is again a side effect.
Function match_console_name() can change newcon->index.
But it can be called in the very first pass that looks for braille console
and if the call to _braille_register_console() fails,
this newcon with changed index is passed to newcon->match().

This can be fixed by introducing a predicate that checks if the
console_cmdline entry has braille options and calling match_console_name()
only for such consoles, but I think that the code is too convoluted
and the v5 approach is better.

I am going to fix v5 preserving both the check for duplicates
and the invariant, but tell me please if you prefer the v4 approach.

> The
> newcon->setup() call is called only when the console matches.
> AFAIK, there is only one braille console. We should be on
> the safe side if this one does not implement the match()
> callback. Or is it even more complicated?

As you can see from the original code, the check for braille console
was performed in that branch of code where we missed newcon->match(),
so yes, it looks like braille console(s) does not have the match() method.
I used that in v4 to factor out matching for braille from the loop.

Thank you
Aleksey Makarov

> To be honest, I am not much familiar with the console registration
> code. I am still trying to get a better picture. It is pity that
> many function have unexpected side effects.
>
> Best Regards,
> Petr
> --
> To unsubscribe from this list: send the line "unsubscribe linux-serial" in
> the body of a message to [email protected]
> More majordomo info at http://vger.kernel.org/majordomo-info.html
>


2017-03-16 13:54:34

by Petr Mladek

[permalink] [raw]
Subject: Re: [PATCH v5 3/3] printk: fix double printing with earlycon

On Thu 2017-03-16 13:36:35, Aleksey Makarov wrote:
>
>
> On 03/15/2017 07:58 PM, Petr Mladek wrote:
> > On Wed 2017-03-15 13:28:52, Aleksey Makarov wrote:
> >> If a console was specified by ACPI SPCR table _and_ command line
> >> parameters like "console=ttyAMA0" _and_ "earlycon" were specified,
> >> then log messages appear twice.
> >>
> >> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> >> index fd752f0c8ef1..7dc53b2831fb 100644
> >> --- a/kernel/printk/printk.c
> >> +++ b/kernel/printk/printk.c
> >> @@ -1902,20 +1902,25 @@ static int __add_preferred_console(char *name, int idx, char *options,
> >> int i;
> >>
> >> /*
> >> - * See if this tty is not yet registered, and
> >> - * if we have a slot free.
> >> + * Don't check if the console has already been registered, because it is
> >> + * pointless. After all, we can not check if two entries refer to
> >> + * the same console if one is matched with console->match(), and another
> >> + * by name/index:
> >> + *
> >> + * pl011,mmio,0x87e024000000,115200 -- added from SPCR
> >> + * ttyAMA0 -- added from command line
> >> + *
> >> + * Also this allows to maintain an invariant that will help to find if
> >> + * the matching console is preferred, see register_console():
> >
> > It is an interesting idea.
> >
> > I just wonder if the check for duplicates was there for a serious
> > reason. It is hard to say because it was already in the initial git
> > commit. In each case, MAX_CMDLINECONSOLES is 8. There is not much
> > space for duplicates.
> >
> > Note that add_preferred_console() is called also from _probe() calls,
> > see
> >
> > uart_add_one_port() -> of_console_check()
> > sunserial_console_match() -> add_preferred_console()
> >
> > I wonder they might be called repeatedly, for example because
> > of suspend/restore, hotplug, module load/unload.
> >
> > I would feel more comfortable if we keep the check for
> > duplicates here.
>
> Now I see the problem, thank you.
>
> > It is a pity that the console->match() calls have side effects.
> > I still wonder if the 4th version might be more safe.
>
> I pushed v4 to the linaro git server:
>
> https://git.linaro.org/people/aleksey.makarov/linux.git/commit/?h=amakarov/console2.19.v4&id=47a8227e37ca54d9cc7051abe9b3c2d072f4f75f
>
> The problem with that approach is again a side effect.
> Function match_console_name() can change newcon->index.
> But it can be called in the very first pass that looks for braille console
> and if the call to _braille_register_console() fails,
> this newcon with changed index is passed to newcon->match().

I see. We need to make sure that newcon->match() will not get called
when checking for the braille console.


> This can be fixed by introducing a predicate that checks if the
> console_cmdline entry has braille options and calling match_console_name()
> only for such consoles, but I think that the code is too convoluted
> and the v5 approach is better.

I personally prefer v4. The braille console adds an unexpected
twist into the code because it skips the rest of the function.
IMHO, it is better when it is is tested separately with clear
conditions and comments.

I would personally add the following into
kernel/printk/console_cmdline.h

#define for_each_console_cmdline(c, i) \
for (i = 0, c = console_cmdline; \
i < MAX_CMDLINECONSOLES && c->name[0]; \
i++, c++)

It can be used in both __add_preferred_console()
and register_console().

Also I would add the following into kernel/printk/braille.h

static inline bool
is_braille_console(struct console_cmdline *c)
{
return !!c->brl_options;
}

Then the braille-specific code in register_console() might
look like:

/*
* Braille console is handled a very special way.
* Is is not listed in the console_drivers list.
* Instead it registers its own keyboard and vt notifiers.
*
* Be careful and avoid calling c->match() here
* because it might have side effects!
*/
if (is_braille_console(c) &&
match_console_name(newcon, c) &&
_braille_register_console(newcon, c))
return;


Finally, I would prefer to move

newcon->flags |= CON_ENABLED;

outside the match_console() function. The function will still
have side effects because of the c->match() calls. But we should
not make it worse. In fact, it would be great to remove side effects
from the c->match() functions in the long term (not in this patch set).

> I am going to fix v5 preserving both the check for duplicates
> and the invariant, but tell me please if you prefer the v4 approach.

I guess that you planed to shuffle console_cmdline entries to keep
the preferred console first/last. I am afraid that it won't be
a nice code either. But I might be wrong.


> > The
> > newcon->setup() call is called only when the console matches.
> > AFAIK, there is only one braille console. We should be on
> > the safe side if this one does not implement the match()
> > callback. Or is it even more complicated?
>
> As you can see from the original code, the check for braille console
> was performed in that branch of code where we missed newcon->match(),
> so yes, it looks like braille console(s) does not have the match() method.
> I used that in v4 to factor out matching for braille from the loop.

The check for blr_options is sufficient and better.

I suggest to wait at least two days until you spend to much time
on reshuffling the code. It is possible that others would prefer
v5 or suggest even other solution.

Best Regards,
Petr

2017-03-17 10:43:21

by Aleksey Makarov

[permalink] [raw]
Subject: Re: [PATCH v5 3/3] printk: fix double printing with earlycon



On 03/16/2017 04:54 PM, Petr Mladek wrote:
> On Thu 2017-03-16 13:36:35, Aleksey Makarov wrote:
>>
>>
>> On 03/15/2017 07:58 PM, Petr Mladek wrote:
>>> On Wed 2017-03-15 13:28:52, Aleksey Makarov wrote:

[..]

> I personally prefer v4. The braille console adds an unexpected
> twist into the code because it skips the rest of the function.
> IMHO, it is better when it is is tested separately with clear
> conditions and comments.
>
> I would personally add the following into
> kernel/printk/console_cmdline.h
>
> #define for_each_console_cmdline(c, i) \
> for (i = 0, c = console_cmdline; \
> i < MAX_CMDLINECONSOLES && c->name[0]; \
> i++, c++)
>
> It can be used in both __add_preferred_console()
> and register_console().

Ok

> Also I would add the following into kernel/printk/braille.h
>
> static inline bool
> is_braille_console(struct console_cmdline *c)
> {
> return !!c->brl_options;
> }
>
> Then the braille-specific code in register_console() might
> look like:
>
> /*
> * Braille console is handled a very special way.
> * Is is not listed in the console_drivers list.
> * Instead it registers its own keyboard and vt notifiers.
> *
> * Be careful and avoid calling c->match() here
> * because it might have side effects!
> */
> if (is_braille_console(c) &&
> match_console_name(newcon, c) &&
> _braille_register_console(newcon, c))
> return;

Yes, this is exactly what I was going to do.

> Finally, I would prefer to move
>
> newcon->flags |= CON_ENABLED;
>
> outside the match_console() function. The function will still
> have side effects because of the c->match() calls. But we should
> not make it worse. In fact, it would be great to remove side effects
> from the c->match() functions in the long term (not in this patch set).

I see the motivation but I am afraid this is not possible until
side effects are removed from newcon->match() and match_console().
The point is that match_console() also calls newcon->setup() (side effect)
and this CON_ENABLED flag indicates if this call was successful.

>> I am going to fix v5 preserving both the check for duplicates
>> and the invariant, but tell me please if you prefer the v4 approach.
>
> I guess that you planed to shuffle console_cmdline entries to keep
> the preferred console first/last. I am afraid that it won't be
> a nice code either. But I might be wrong.

You are right, I tried that, the code was awful.

Thank you
Aleksey Makarov

>>> The
>>> newcon->setup() call is called only when the console matches.
>>> AFAIK, there is only one braille console. We should be on
>>> the safe side if this one does not implement the match()
>>> callback. Or is it even more complicated?
>>
>> As you can see from the original code, the check for braille console
>> was performed in that branch of code where we missed newcon->match(),
>> so yes, it looks like braille console(s) does not have the match() method.
>> I used that in v4 to factor out matching for braille from the loop.
>
> The check for blr_options is sufficient and better.
>
> I suggest to wait at least two days until you spend to much time
> on reshuffling the code. It is possible that others would prefer
> v5 or suggest even other solution.
>
> Best Regards,
> Petr
> --
> To unsubscribe from this list: send the line "unsubscribe linux-serial" in
> the body of a message to [email protected]
> More majordomo info at http://vger.kernel.org/majordomo-info.html
>

2017-03-17 11:48:19

by Aleksey Makarov

[permalink] [raw]
Subject: [PATCH v6 3/3] printk: fix double printing with earlycon

If a console was specified by ACPI SPCR table _and_ command line
parameters like "console=ttyAMA0" _and_ "earlycon" were specified,
then log messages appear twice.

The root cause is that the code traverses the list of specified
consoles (the `console_cmdline` array) and stops at the first match.
But it may happen that the same console is referred by the elements
of this array twice:

pl011,mmio,0x87e024000000,115200 -- from SPCR
ttyAMA0 -- from command line

but in this case `preferred_console` points to the second entry and
the flag CON_CONSDEV is not set, so bootconsole is not deregistered.

To fix that, split the loop where we search for matching entry of
console_cmdline into three parts that do not intersect:
1) search for braille console
2) check for preferred_console
3) match other entries so that these three parts do not

To to that introduce predicate _braille_is_braille_console() that checks if
its argument is an entry describing a braille console.

Also introduce a macro for_each_console_cmdline() to traverse
the console_cmdline array.

Reported-by: Sudeep Holla <[email protected]>
Signed-off-by: Aleksey Makarov <[email protected]>
---

v5 -> v6:
- drop v5 and continue to work on v4:
- introduce _braille_is_braille_console(). It helps to split original loop
into three parts: 1) search for braille console, 2) check for
preferred_console, 3) match other entries so that these three parts do not
intersect.
- introduce for_each_console_cmdline() macros to traverse console_cmdline
(Petr Mladek)

kernel/printk/braille.h | 12 ++++++
kernel/printk/printk.c | 104 ++++++++++++++++++++++++++++++++++--------------
2 files changed, 86 insertions(+), 30 deletions(-)

diff --git a/kernel/printk/braille.h b/kernel/printk/braille.h
index 769d771145c8..183aebf6e1dc 100644
--- a/kernel/printk/braille.h
+++ b/kernel/printk/braille.h
@@ -18,6 +18,12 @@ _braille_register_console(struct console *console, struct console_cmdline *c);
int
_braille_unregister_console(struct console *console);

+static inline int
+_braille_is_braille_console(struct console_cmdline *c)
+{
+ return !!c->brl_options;
+}
+
#else

static inline void
@@ -43,6 +49,12 @@ _braille_unregister_console(struct console *console)
return 0;
}

+static inline int
+_braille_is_braille_console(struct console_cmdline *c)
+{
+ return 0;
+}
+
#endif

#endif
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index fd752f0c8ef1..ab2433681ca5 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -270,6 +270,11 @@ static struct console *exclusive_console;

static struct console_cmdline console_cmdline[MAX_CMDLINECONSOLES];

+#define for_each_console_cmdline(i, c) \
+ for (i = 0, c = console_cmdline; \
+ i < MAX_CMDLINECONSOLES && c->name[0]; \
+ i++, c++)
+
static int preferred_console = -1;
int console_set_on_cmdline;
EXPORT_SYMBOL(console_set_on_cmdline);
@@ -1905,9 +1910,7 @@ static int __add_preferred_console(char *name, int idx, char *options,
* See if this tty is not yet registered, and
* if we have a slot free.
*/
- for (i = 0, c = console_cmdline;
- i < MAX_CMDLINECONSOLES && c->name[0];
- i++, c++) {
+ for_each_console_cmdline(i, c) {
if (strcmp(c->name, name) == 0 && c->index == idx) {
if (!brl_options)
preferred_console = i;
@@ -2383,6 +2386,37 @@ static int __init keep_bootcon_setup(char *str)

early_param("keep_bootcon", keep_bootcon_setup);

+static bool match_console_name(struct console *newcon,
+ struct console_cmdline *c)
+{
+ BUILD_BUG_ON(sizeof(c->name) != sizeof(newcon->name));
+ if (strcmp(c->name, newcon->name) != 0)
+ return false;
+ if (newcon->index >= 0 && newcon->index != c->index)
+ return false;
+ if (newcon->index < 0)
+ newcon->index = c->index;
+ return true;
+}
+
+static bool match_console(struct console *newcon, struct console_cmdline *c)
+{
+ if (newcon->match &&
+ newcon->match(newcon, c->name, c->index, c->options) == 0) {
+ newcon->flags |= CON_ENABLED;
+ return true;
+ }
+
+ if (match_console_name(newcon, c)) {
+ if (!newcon->setup || newcon->setup(newcon, c->options) == 0)
+ newcon->flags |= CON_ENABLED;
+
+ return true;
+ }
+
+ return false;
+}
+
/*
* The console driver calls this routine during kernel initialization
* to register the console printing procedure with printk() and to
@@ -2457,40 +2491,50 @@ void register_console(struct console *newcon)
}

/*
- * See if this console matches one we selected on
- * the command line.
+ * See if this console matches one we selected on the command line.
+ * Do it in three steps:
+ *
+ * 1) check if it is a braille console..
*/
- for (i = 0, c = console_cmdline;
- i < MAX_CMDLINECONSOLES && c->name[0];
- i++, c++) {
- if (!newcon->match ||
- newcon->match(newcon, c->name, c->index, c->options) != 0) {
- /* default matching */
- BUILD_BUG_ON(sizeof(c->name) != sizeof(newcon->name));
- if (strcmp(c->name, newcon->name) != 0)
- continue;
- if (newcon->index >= 0 &&
- newcon->index != c->index)
- continue;
- if (newcon->index < 0)
- newcon->index = c->index;
-
- if (_braille_register_console(newcon, c))
- return;
-
- if (newcon->setup &&
- newcon->setup(newcon, c->options) != 0)
- break;
- }
+ for_each_console_cmdline(i, c)
+ if (_braille_is_braille_console(c) &&
+ match_console_name(newcon, c) &&
+ _braille_register_console(newcon, c))
+ return;

- newcon->flags |= CON_ENABLED;
- if (i == preferred_console) {
+ /*
+ * 2) check if this console was set as preferred by command line
+ * parameters or by call to add_preferred_console(). There may be
+ * several entries in the console_cmdline array matching with the same
+ * console, one with newcon->match(), another by name/index:
+ *
+ * pl011,mmio,0x87e024000000,115200 -- added from SPCR
+ * ttyAMA0 -- added from command line
+ *
+ * so we can not use the first match. Instead check the
+ * entry pointed by preferred_console and then all other entries.
+ */
+ if (preferred_console >= 0 &&
+ match_console(newcon, console_cmdline + preferred_console)) {
+ if (newcon->flags & CON_ENABLED) {
newcon->flags |= CON_CONSDEV;
has_preferred = true;
}
- break;
+ goto match;
+ }
+
+ /*
+ * 3) check other entries
+ */
+ for_each_console_cmdline(i, c) {
+ if (preferred_console == i || _braille_is_braille_console(c))
+ continue;
+
+ if (match_console(newcon, c))
+ goto match;
}

+match:
if (!(newcon->flags & CON_ENABLED))
return;

--
2.12.0

2017-03-17 13:40:52

by Aleksey Makarov

[permalink] [raw]
Subject: Re: [PATCH v6 3/3] printk: fix double printing with earlycon



On 03/17/2017 02:43 PM, Aleksey Makarov wrote:

[..]

> @@ -2457,40 +2491,50 @@ void register_console(struct console *newcon)
> }
>
> /*
> - * See if this console matches one we selected on
> - * the command line.
> + * See if this console matches one we selected on the command line.
> + * Do it in three steps:
> + *
> + * 1) check if it is a braille console..
> */
> - for (i = 0, c = console_cmdline;
> - i < MAX_CMDLINECONSOLES && c->name[0];
> - i++, c++) {
> - if (!newcon->match ||
> - newcon->match(newcon, c->name, c->index, c->options) != 0) {
> - /* default matching */
> - BUILD_BUG_ON(sizeof(c->name) != sizeof(newcon->name));
> - if (strcmp(c->name, newcon->name) != 0)
> - continue;
> - if (newcon->index >= 0 &&
> - newcon->index != c->index)
> - continue;
> - if (newcon->index < 0)
> - newcon->index = c->index;
> -
> - if (_braille_register_console(newcon, c))
> - return;
> -
> - if (newcon->setup &&
> - newcon->setup(newcon, c->options) != 0)
> - break;
> - }
> + for_each_console_cmdline(i, c)
> + if (_braille_is_braille_console(c) &&
> + match_console_name(newcon, c) &&
> + _braille_register_console(newcon, c))
> + return;

I am sorry to say that, but it looks like this does not work either.
newcon->index still can be changed here in match_console_name(),
but (correctly implemented) _braille_register_console() may refuse
to register it, and the changed newcon is passed to newcon->match() below.

I tried the shuffle (i. e. v5) approach again and it seems I managed to
write quite nice code. I am going to send it in a minute.

Thank you
Aleksey Makarov

> - newcon->flags |= CON_ENABLED;
> - if (i == preferred_console) {
> + /*
> + * 2) check if this console was set as preferred by command line
> + * parameters or by call to add_preferred_console(). There may be
> + * several entries in the console_cmdline array matching with the same
> + * console, one with newcon->match(), another by name/index:
> + *
> + * pl011,mmio,0x87e024000000,115200 -- added from SPCR
> + * ttyAMA0 -- added from command line
> + *
> + * so we can not use the first match. Instead check the
> + * entry pointed by preferred_console and then all other entries.
> + */
> + if (preferred_console >= 0 &&
> + match_console(newcon, console_cmdline + preferred_console)) {
> + if (newcon->flags & CON_ENABLED) {
> newcon->flags |= CON_CONSDEV;
> has_preferred = true;
> }
> - break;
> + goto match;
> + }
> +
> + /*
> + * 3) check other entries
> + */
> + for_each_console_cmdline(i, c) {
> + if (preferred_console == i || _braille_is_braille_console(c))
> + continue;
> +
> + if (match_console(newcon, c))
> + goto match;
> }
>
> +match:
> if (!(newcon->flags & CON_ENABLED))
> return;
>
>

2017-03-17 13:49:09

by Aleksey Makarov

[permalink] [raw]
Subject: [PATCH v7 3/3] printk: fix double printing with earlycon

If a console was specified by ACPI SPCR table _and_ command line
parameters like "console=ttyAMA0" _and_ "earlycon" were specified,
then log messages appear twice.

The root cause is that the code traverses the list of specified
consoles (the `console_cmdline` array) and stops at the first match.
But it may happen that the same console is referred by the elements
of this array twice:

pl011,mmio,0x87e024000000,115200 -- from SPCR
ttyAMA0 -- from command line

but in this case `preferred_console` points to the second entry and
the flag CON_CONSDEV is not set, so bootconsole is not deregistered.

To fix that, introduce an invariant "The last non-braille console
is always the preferred one" on the entries of the console_cmdline
array. Then traverse it in reverse order to be sure that if
the console is preferred then it will be the first matching entry.

Reported-by: Sudeep Holla <[email protected]>
Signed-off-by: Aleksey Makarov <[email protected]>
---

v6 -> v7:
- return back to v5 :)
- leave the check for already registered entries and add a function that
maintains the invariant.

v5 -> v6:
- drop v5 and continue to work on v4:
- introduce _braille_is_braille_console(). It helps to split original loop
into three parts: 1) search for braille console, 2) check for
preferred_console, 3) match other entries so that these three parts do not
intersect.
- introduce for_each_console_cmdline() macros to traverse console_cmdline
(Petr Mladek)

kernel/printk/printk.c | 48 ++++++++++++++++++++++++++++++++++++++++++------
1 file changed, 42 insertions(+), 6 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index fd752f0c8ef1..88f86fb23bc4 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -1895,6 +1895,34 @@ asmlinkage __visible void early_printk(const char *fmt, ...)
}
#endif

+/*
+ * This function maintains an invariant that will help to find if
+ * the matching console is preferred, see register_console():
+ *
+ * The last non-braille console is always the preferred one.
+ */
+static void ensure_preferred_is_last(int i)
+{
+ int last;
+
+ for (last = MAX_CMDLINECONSOLES - 1;
+ last >= 0 && !console_cmdline[last].name[0];
+ last--)
+ ;
+
+ BUG_ON(last < 0);
+
+ if (i != last) {
+ struct console_cmdline t;
+
+ t = console_cmdline[i];
+ console_cmdline[i] = console_cmdline[last];
+ console_cmdline[last] = t;
+ }
+
+ preferred_console = last;
+}
+
static int __add_preferred_console(char *name, int idx, char *options,
char *brl_options)
{
@@ -1910,7 +1938,7 @@ static int __add_preferred_console(char *name, int idx, char *options,
i++, c++) {
if (strcmp(c->name, name) == 0 && c->index == idx) {
if (!brl_options)
- preferred_console = i;
+ ensure_preferred_is_last(i);
return 0;
}
}
@@ -2457,12 +2485,20 @@ void register_console(struct console *newcon)
}

/*
- * See if this console matches one we selected on
- * the command line.
+ * See if this console matches one we selected on the command line.
+ *
+ * The console_cmdline array is traversed in the reverse order because
+ * we want to be sure that if this console is preferred then it will be
+ * the first matching entry. We use the invariant that is maintained in
+ * __add_preferred_console().
*/
- for (i = 0, c = console_cmdline;
- i < MAX_CMDLINECONSOLES && c->name[0];
- i++, c++) {
+ for (i = MAX_CMDLINECONSOLES - 1; i >= 0; i--) {
+
+ if (!console_cmdline[i].name[0])
+ continue;
+
+ c = console_cmdline + i;
+
if (!newcon->match ||
newcon->match(newcon, c->name, c->index, c->options) != 0) {
/* default matching */
--
2.12.0

2017-03-20 06:17:05

by Sergey Senozhatsky

[permalink] [raw]
Subject: Re: [PATCH v7 3/3] printk: fix double printing with earlycon

Hello,

On (03/17/17 16:43), Aleksey Makarov wrote:
[..]
> +static void ensure_preferred_is_last(int i)
> +{
> + int last;
> +
> + for (last = MAX_CMDLINECONSOLES - 1;
> + last >= 0 && !console_cmdline[last].name[0];
> + last--)
> + ;
> +
> + BUG_ON(last < 0);

let's not panic().


a nitpick, console swap can be done as

if (i != last)
swap(console_cmdline[i], console_cmdline[last]);
preferred_console = last;


-ss

2017-03-20 10:08:42

by Aleksey Makarov

[permalink] [raw]
Subject: [PATCH v8 3/3] printk: fix double printing with earlycon

If a console was specified by ACPI SPCR table _and_ command line
parameters like "console=ttyAMA0" _and_ "earlycon" were specified,
then log messages appear twice.

The root cause is that the code traverses the list of specified
consoles (the `console_cmdline` array) and stops at the first match.
But it may happen that the same console is referred by the elements
of this array twice:

pl011,mmio,0x87e024000000,115200 -- from SPCR
ttyAMA0 -- from command line

but in this case `preferred_console` points to the second entry and
the flag CON_CONSDEV is not set, so bootconsole is not deregistered.

To fix that, introduce an invariant "The last non-braille console
is always the preferred one" on the entries of the console_cmdline
array. Then traverse it in reverse order to be sure that if
the console is preferred then it will be the first matching entry.

Reported-by: Sudeep Holla <[email protected]>
Signed-off-by: Aleksey Makarov <[email protected]>
---

v7 -> v8:
- add an explanation to the comment how console_cmdline can contain entries
referring to the same console
- move the body of the function introduced in the previous version to cycle
- don't panic() (Sergey Senozhatsky). Don't check this condition because
the loop condition guarantees that it holds.
- use swap() (Sergey Senozhatsky)

v6 -> v7:
- return back to v5
- leave the check for already registered entries and add a function that
maintains the invariant.

v5 -> v6:
- drop v5 and continue to work on v4:
- introduce _braille_is_braille_console(). It helps to split original loop
into three parts: 1) search for braille console, 2) check for
preferred_console, 3) match other entries so that these three parts do not
intersect.
- introduce for_each_console_cmdline() macros to traverse console_cmdline
(Petr Mladek)

kernel/printk/printk.c | 49 ++++++++++++++++++++++++++++++++++++++++++-------
1 file changed, 42 insertions(+), 7 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index fd752f0c8ef1..462036e7a767 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -1909,8 +1909,28 @@ static int __add_preferred_console(char *name, int idx, char *options,
i < MAX_CMDLINECONSOLES && c->name[0];
i++, c++) {
if (strcmp(c->name, name) == 0 && c->index == idx) {
- if (!brl_options)
- preferred_console = i;
+ int last;
+
+ if (brl_options)
+ return 0;
+
+ /*
+ * Maintain an invariant that will help to find if
+ * the matching console is preferred, see
+ * register_console():
+ *
+ * The last non-braille console is always
+ * the preferred one.
+ */
+ for (last = MAX_CMDLINECONSOLES - 1;
+ last >= 0 && !console_cmdline[last].name[0];
+ last--)
+ ;
+
+ if (i != last)
+ swap(console_cmdline[i], console_cmdline[last]);
+
+ preferred_console = last;
return 0;
}
}
@@ -2457,12 +2477,27 @@ void register_console(struct console *newcon)
}

/*
- * See if this console matches one we selected on
- * the command line.
+ * See if this console matches one we selected on the command line.
+ *
+ * There may be several entries in the console_cmdline array matching
+ * with the same console, one with newcon->match(), another by
+ * name/index:
+ *
+ * pl011,mmio,0x87e024000000,115200 -- added from SPCR
+ * ttyAMA0 -- added from command line
+ *
+ * Traverse the console_cmdline array in reverse order to be
+ * sure that if this console is preferred then it will be the first
+ * matching entry. We use the invariant that is maintained in
+ * __add_preferred_console().
*/
- for (i = 0, c = console_cmdline;
- i < MAX_CMDLINECONSOLES && c->name[0];
- i++, c++) {
+ for (i = MAX_CMDLINECONSOLES - 1; i >= 0; i--) {
+
+ if (!console_cmdline[i].name[0])
+ continue;
+
+ c = console_cmdline + i;
+
if (!newcon->match ||
newcon->match(newcon, c->name, c->index, c->options) != 0) {
/* default matching */
--
2.12.0

2017-03-27 14:15:08

by Petr Mladek

[permalink] [raw]
Subject: Re: [PATCH v8 3/3] printk: fix double printing with earlycon

On Mon 2017-03-20 13:03:00, Aleksey Makarov wrote:
> If a console was specified by ACPI SPCR table _and_ command line
> parameters like "console=ttyAMA0" _and_ "earlycon" were specified,
> then log messages appear twice.
>
> The root cause is that the code traverses the list of specified
> consoles (the `console_cmdline` array) and stops at the first match.
> But it may happen that the same console is referred by the elements
> of this array twice:
>
> pl011,mmio,0x87e024000000,115200 -- from SPCR
> ttyAMA0 -- from command line
>
> but in this case `preferred_console` points to the second entry and
> the flag CON_CONSDEV is not set, so bootconsole is not deregistered.
>
> To fix that, introduce an invariant "The last non-braille console
> is always the preferred one" on the entries of the console_cmdline
> array. Then traverse it in reverse order to be sure that if
> the console is preferred then it will be the first matching entry.

Sigh, I am afraid that we need to go this way. I hate the side
effects of the match() functions. It would be great to get
rid of them. But it is non-trivial and out of scope for this fix.


> Reported-by: Sudeep Holla <[email protected]>
> Signed-off-by: Aleksey Makarov <[email protected]>

> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index fd752f0c8ef1..462036e7a767 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -1909,8 +1909,28 @@ static int __add_preferred_console(char *name, int idx, char *options,
> i < MAX_CMDLINECONSOLES && c->name[0];
> i++, c++) {
> if (strcmp(c->name, name) == 0 && c->index == idx) {
> - if (!brl_options)
> - preferred_console = i;
> + int last;
> +
> + if (brl_options)
> + return 0;
> +
> + /*
> + * Maintain an invariant that will help to find if
> + * the matching console is preferred, see
> + * register_console():
> + *
> + * The last non-braille console is always
> + * the preferred one.
> + */
> + for (last = MAX_CMDLINECONSOLES - 1;
> + last >= 0 && !console_cmdline[last].name[0];
> + last--)
> + ;

This is a rather non-trivial code to find the last element.
I might make sense to count it in a global variable.
Then we might remove the check for console_cmdline[i].name[0]
also in the other for cycles and make them better readable.

> +
> + if (i != last)
> + swap(console_cmdline[i], console_cmdline[last]);

I was not aware of the swap() function. It is great to know ;-)

Otherwise, I am find with this approach.

Best Regards,
Petr

2017-03-27 16:28:58

by Aleksey Makarov

[permalink] [raw]
Subject: Re: [PATCH v8 3/3] printk: fix double printing with earlycon



On 03/27/2017 05:14 PM, Petr Mladek wrote:
> On Mon 2017-03-20 13:03:00, Aleksey Makarov wrote:

[..]

>> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
>> index fd752f0c8ef1..462036e7a767 100644
>> --- a/kernel/printk/printk.c
>> +++ b/kernel/printk/printk.c
>> @@ -1909,8 +1909,28 @@ static int __add_preferred_console(char *name, int idx, char *options,
>> i < MAX_CMDLINECONSOLES && c->name[0];
>> i++, c++) {
>> if (strcmp(c->name, name) == 0 && c->index == idx) {
>> - if (!brl_options)
>> - preferred_console = i;
>> + int last;
>> +
>> + if (brl_options)
>> + return 0;
>> +
>> + /*
>> + * Maintain an invariant that will help to find if
>> + * the matching console is preferred, see
>> + * register_console():
>> + *
>> + * The last non-braille console is always
>> + * the preferred one.
>> + */
>> + for (last = MAX_CMDLINECONSOLES - 1;
>> + last >= 0 && !console_cmdline[last].name[0];
>> + last--)
>> + ;
>
> This is a rather non-trivial code to find the last element.
> I might make sense to count it in a global variable.
> Then we might remove the check for console_cmdline[i].name[0]
> also in the other for cycles and make them better readable.

Having an additional variable console_cmdline_last pointing to the last element
would require maintaining consistency between this variable and
contents of console_cmdline. For the code we have it is not hard, but when code
is changed we need to check this. Also there exists preferred_console that
has almost the same meaning but it points not to the last element, but to the
last non-braille element. Also we need to have a special value (-1) for this
variable for empty array. So I personally would instead try to rewrite this:

for (last = MAX_CMDLINECONSOLES - 1; last >= 0; last--)
if (console_cmdline[last].name[0])
break;

Is it better? If not, I will send a version with console_cmdline_last.

>> +
>> + if (i != last)
>> + swap(console_cmdline[i], console_cmdline[last]);
>
> I was not aware of the swap() function. It is great to know ;-)

Yes, same for me. Thanks to Sergey Senozhatsky.

Thank you for review
Aleksey Makarov

2017-03-28 02:04:34

by Sergey Senozhatsky

[permalink] [raw]
Subject: Re: [PATCH v8 3/3] printk: fix double printing with earlycon

On (03/27/17 19:28), Aleksey Makarov wrote:
[..]
> > > + /*
> > > + * Maintain an invariant that will help to find if
> > > + * the matching console is preferred, see
> > > + * register_console():
> > > + *
> > > + * The last non-braille console is always
> > > + * the preferred one.
> > > + */
> > > + for (last = MAX_CMDLINECONSOLES - 1;
> > > + last >= 0 && !console_cmdline[last].name[0];
> > > + last--)
> > > + ;
> >
> > This is a rather non-trivial code to find the last element.
> > I might make sense to count it in a global variable.
> > Then we might remove the check for console_cmdline[i].name[0]
> > also in the other for cycles and make them better readable.
>
> Having an additional variable console_cmdline_last pointing to the last element
> would require maintaining consistency between this variable and
> contents of console_cmdline. For the code we have it is not hard, but when code
> is changed we need to check this. Also there exists preferred_console that
> has almost the same meaning but it points not to the last element, but to the
> last non-braille element. Also we need to have a special value (-1) for this
> variable for empty array. So I personally would instead try to rewrite this:
>
> for (last = MAX_CMDLINECONSOLES - 1; last >= 0; last--)
> if (console_cmdline[last].name[0])
> break;
>
> Is it better? If not, I will send a version with console_cmdline_last.

personally I'm fine with the nested loop. the latest version
"for (last = MAX_CMDLINECONSOLES - 1; last >= 0;..."

is even easier to read.


so we do not just iterate console_cmdline anymore, but also modify it.
this, probably, has impact on the following scenario

CPU0 CPU1

add_preferred_console() add_preferred_console()
__add_preferred_console() __add_preferred_console()
swap(i1, last) swap(i2, last)

temp1 = i1
i1 = last temp2 = i2
last = temp1 i2 = last
last = temp2

so both i1 and i2 will point to 'last' now, IOW, we will have two
identical entries in console_cmdline, while i1 or i2 will be lost.


neither add_preferred_console() nor __add_preferred_console() have any
serialization. and I assume that we can call add_preferred_console()
concurrently, can't we?

-ss

2017-03-28 12:57:28

by Petr Mladek

[permalink] [raw]
Subject: Re: [PATCH v8 3/3] printk: fix double printing with earlycon

On Tue 2017-03-28 11:04:04, Sergey Senozhatsky wrote:
> On (03/27/17 19:28), Aleksey Makarov wrote:
> [..]
> > > > + /*
> > > > + * Maintain an invariant that will help to find if
> > > > + * the matching console is preferred, see
> > > > + * register_console():
> > > > + *
> > > > + * The last non-braille console is always
> > > > + * the preferred one.
> > > > + */
> > > > + for (last = MAX_CMDLINECONSOLES - 1;
> > > > + last >= 0 && !console_cmdline[last].name[0];
> > > > + last--)
> > > > + ;
> > >
> > > This is a rather non-trivial code to find the last element.
> > > I might make sense to count it in a global variable.
> > > Then we might remove the check for console_cmdline[i].name[0]
> > > also in the other for cycles and make them better readable.
> >
> > Having an additional variable console_cmdline_last pointing to the last element
> > would require maintaining consistency between this variable and
> > contents of console_cmdline. For the code we have it is not hard, but when code
> > is changed we need to check this. Also there exists preferred_console that
> > has almost the same meaning but it points not to the last element, but to the
> > last non-braille element. Also we need to have a special value (-1) for this
> > variable for empty array. So I personally would instead try to rewrite this:
> >
> > for (last = MAX_CMDLINECONSOLES - 1; last >= 0; last--)
> > if (console_cmdline[last].name[0])
> > break;
> >
> > Is it better? If not, I will send a version with console_cmdline_last.
>
> personally I'm fine with the nested loop. the latest version
> "for (last = MAX_CMDLINECONSOLES - 1; last >= 0;..."
>
> is even easier to read.

The number of elements is bumped on a single location, so there
is not much to synchronize. The old approach was fine because
the for cycles were needed anyway, they started on the 0th element,
and NULL ended arrays are rather common practice.

But we are searching the array from the end now. Also we use the
for cycle just to get the number here. This is not a common
practice and it makes the code more complicated and strange from
my point of view.

If you do not like -1, you could use console_cmdline_cnt and
start with 0. I would actually do so because it is a common
approach and easy to understand.

>
> so we do not just iterate console_cmdline anymore, but also modify it.
> this, probably, has impact on the following scenario
>
> CPU0 CPU1
>
> add_preferred_console() add_preferred_console()
> __add_preferred_console() __add_preferred_console()
> swap(i1, last) swap(i2, last)
>
> temp1 = i1
> i1 = last temp2 = i2
> last = temp1 i2 = last
> last = temp2
>
> so both i1 and i2 will point to 'last' now, IOW, we will have two
> identical entries in console_cmdline, while i1 or i2 will be lost.
>
>
> neither add_preferred_console() nor __add_preferred_console() have any
> serialization. and I assume that we can call add_preferred_console()
> concurrently, can't we?

Very good point!

Well, if this race exists, it was racy even before. Of course,
the old race was only when new entry was added. It would
be more visible now because also shuffling would be racy.

OK, most add_preferred_console() calls are in functions
that are defined as console_initcall(). They seem to
be defined only when the respective drivers are built in.
It seems that these initcalls are serialized, see console_init().

add_preferred_console() is used also in uart_add_one_port():

-> uart_add_one_port()
-> of_console_check()
-> add_preferred_console()

But there the calls are synchronized as well via
port_mutex.

Finally, __add_preferred_console() is called also from
console_setup(). It is called via do_early_param()
even before the console_initcall() functions. It is
serialized as well.

If I did not miss anything, it would seem that
__add_preferred_console() are called synchronously
and only during boot by design.

Best Regards,
Petr

2017-03-30 05:55:58

by Sergey Senozhatsky

[permalink] [raw]
Subject: Re: [PATCH v8 3/3] printk: fix double printing with earlycon

On (03/28/17 14:56), Petr Mladek wrote:
[..]
> > > Is it better? If not, I will send a version with console_cmdline_last.
> >
> > personally I'm fine with the nested loop. the latest version
> > "for (last = MAX_CMDLINECONSOLES - 1; last >= 0;..."
> >
> > is even easier to read.
>
> The number of elements is bumped on a single location, so there
> is not much to synchronize. The old approach was fine because
> the for cycles were needed anyway, they started on the 0th element,
> and NULL ended arrays are rather common practice.
>
> But we are searching the array from the end now. Also we use the
> for cycle just to get the number here. This is not a common
> practice and it makes the code more complicated and strange from
> my point of view.

I'm fine with either way :)

[..]
> > neither add_preferred_console() nor __add_preferred_console() have any
> > serialization. and I assume that we can call add_preferred_console()
> > concurrently, can't we?
[..]
> If I did not miss anything, it would seem that
> __add_preferred_console() are called synchronously
> and only during boot by design.

thanks. I think you are right. it's console_initcall or __init.

-ss

2017-04-04 11:12:22

by Petr Mladek

[permalink] [raw]
Subject: Re: [PATCH v8 3/3] printk: fix double printing with earlycon

On Thu 2017-03-30 14:55:46, Sergey Senozhatsky wrote:
> On (03/28/17 14:56), Petr Mladek wrote:
> [..]
> > > > Is it better? If not, I will send a version with console_cmdline_last.
> > >
> > > personally I'm fine with the nested loop. the latest version
> > > "for (last = MAX_CMDLINECONSOLES - 1; last >= 0;..."
> > >
> > > is even easier to read.
> >
> > The number of elements is bumped on a single location, so there
> > is not much to synchronize. The old approach was fine because
> > the for cycles were needed anyway, they started on the 0th element,
> > and NULL ended arrays are rather common practice.
> >
> > But we are searching the array from the end now. Also we use the
> > for cycle just to get the number here. This is not a common
> > practice and it makes the code more complicated and strange from
> > my point of view.
>
> I'm fine with either way :)

Alekesey, any chance to use the global variable to count used or point
to the last element?

I know that you have already spent a lot of time with it. It was great
work. But the current solution of the cycle looks weird to me.

Best Regards,
Petr

2017-04-05 18:27:12

by Aleksey Makarov

[permalink] [raw]
Subject: Re: [PATCH v8 3/3] printk: fix double printing with earlycon



On 04/04/2017 02:12 PM, Petr Mladek wrote:
> On Thu 2017-03-30 14:55:46, Sergey Senozhatsky wrote:
>> On (03/28/17 14:56), Petr Mladek wrote:

[..]

> Alekesey, any chance to use the global variable to count used or point
> to the last element?
>
> I know that you have already spent a lot of time with it. It was great
> work. But the current solution of the cycle looks weird to me.

Sorry for the delay. I will send next version soon.

Thank you
Aleksey Makarov

2017-04-05 20:20:47

by Aleksey Makarov

[permalink] [raw]
Subject: [PATCH v9 3/3] printk: fix double printing with earlycon

If a console was specified by ACPI SPCR table _and_ command line
parameters like "console=ttyAMA0" _and_ "earlycon" were specified,
then log messages appear twice.

The root cause is that the code traverses the list of specified
consoles (the `console_cmdline` array) and stops at the first match.
But it may happen that the same console is referred by the elements
of this array twice:

pl011,mmio,0x87e024000000,115200 -- from SPCR
ttyAMA0 -- from command line

but in this case `preferred_console` points to the second entry and
the flag CON_CONSDEV is not set, so bootconsole is not deregistered.

To fix that, introduce an invariant "The last non-braille console
is always the preferred one" on the entries of the console_cmdline
array. Then traverse it in reverse order to be sure that if
the console is preferred then it will be the first matching entry.
Introduce variable console_cmdline_cnt that keeps the number
of elements of the console_cmdline array (Petr Mladek). It helps
to get rid of the loop that searches for the end of this array.

Reported-by: Sudeep Holla <[email protected]>
Signed-off-by: Aleksey Makarov <[email protected]>
---

v8 -> v9:
- Introduce variable console_cmdline_cnt that keeps the number
of elements of the console_cmdline array (Petr Mladek). It helps
to get rid of the loop that searches for the end of this array.
For the record: I think that this console_cmdline_cnt implementation
is worse than just a loop that finds the end of the array because
1) we have to support consistency between console_cmdline_cnt and
console_cmdline_cnt
2) it makes patch a bit more intrusive

v7 -> v8:
- add an explanation to the comment how console_cmdline can contain entries
referring to the same console
- move the body of the function introduced in the previous version to cycle
- don't panic() (Sergey Senozhatsky). Don't check this condition because
the loop condition guarantees that it holds.
- use swap() (Sergey Senozhatsky)

v6 -> v7:
- return back to v5
- leave the check for already registered entries and add a function that
maintains the invariant.

v5 -> v6:
- drop v5 and continue to work on v4:
- introduce _braille_is_braille_console(). It helps to split original loop
into three parts: 1) search for braille console, 2) check for
preferred_console, 3) match other entries so that these three parts do not
intersect.
- introduce for_each_console_cmdline() macros to traverse console_cmdline
(Petr Mladek)

kernel/printk/printk.c | 48 ++++++++++++++++++++++++++++++++++++++----------
1 file changed, 38 insertions(+), 10 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index fd752f0c8ef1..be657af45758 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -269,6 +269,7 @@ static struct console *exclusive_console;
#define MAX_CMDLINECONSOLES 8

static struct console_cmdline console_cmdline[MAX_CMDLINECONSOLES];
+static int console_cmdline_cnt;

static int preferred_console = -1;
int console_set_on_cmdline;
@@ -1905,12 +1906,26 @@ static int __add_preferred_console(char *name, int idx, char *options,
* See if this tty is not yet registered, and
* if we have a slot free.
*/
- for (i = 0, c = console_cmdline;
- i < MAX_CMDLINECONSOLES && c->name[0];
- i++, c++) {
+ for (i = 0, c = console_cmdline; i < console_cmdline_cnt; i++, c++) {
if (strcmp(c->name, name) == 0 && c->index == idx) {
- if (!brl_options)
- preferred_console = i;
+
+ if (brl_options)
+ return 0;
+
+ /*
+ * Maintain an invariant that will help to find if
+ * the matching console is preferred, see
+ * register_console():
+ *
+ * The last non-braille console is always
+ * the preferred one.
+ */
+ if (i != console_cmdline_cnt - 1)
+ swap(console_cmdline[i],
+ console_cmdline[console_cmdline_cnt - 1]);
+
+ preferred_console = console_cmdline_cnt - 1;
+
return 0;
}
}
@@ -1923,6 +1938,7 @@ static int __add_preferred_console(char *name, int idx, char *options,
braille_set_options(c, brl_options);

c->index = idx;
+ console_cmdline_cnt++;
return 0;
}
/*
@@ -2457,12 +2473,24 @@ void register_console(struct console *newcon)
}

/*
- * See if this console matches one we selected on
- * the command line.
+ * See if this console matches one we selected on the command line.
+ *
+ * There may be several entries in the console_cmdline array matching
+ * with the same console, one with newcon->match(), another by
+ * name/index:
+ *
+ * pl011,mmio,0x87e024000000,115200 -- added from SPCR
+ * ttyAMA0 -- added from command line
+ *
+ * Traverse the console_cmdline array in reverse order to be
+ * sure that if this console is preferred then it will be the first
+ * matching entry. We use the invariant that is maintained in
+ * __add_preferred_console().
*/
- for (i = 0, c = console_cmdline;
- i < MAX_CMDLINECONSOLES && c->name[0];
- i++, c++) {
+ for (i = console_cmdline_cnt - 1; i >= 0; i--) {
+
+ c = console_cmdline + i;
+
if (!newcon->match ||
newcon->match(newcon, c->name, c->index, c->options) != 0) {
/* default matching */
--
2.12.1

2017-04-05 21:57:24

by Andy Shevchenko

[permalink] [raw]
Subject: Re: [PATCH v9 3/3] printk: fix double printing with earlycon

On Wed, Apr 5, 2017 at 11:20 PM, Aleksey Makarov
<[email protected]> wrote:
> If a console was specified by ACPI SPCR table _and_ command line
> parameters like "console=ttyAMA0" _and_ "earlycon" were specified,
> then log messages appear twice.
>
> The root cause is that the code traverses the list of specified
> consoles (the `console_cmdline` array) and stops at the first match.
> But it may happen that the same console is referred by the elements
> of this array twice:
>
> pl011,mmio,0x87e024000000,115200 -- from SPCR
> ttyAMA0 -- from command line
>
> but in this case `preferred_console` points to the second entry and
> the flag CON_CONSDEV is not set, so bootconsole is not deregistered.
>
> To fix that, introduce an invariant "The last non-braille console
> is always the preferred one" on the entries of the console_cmdline
> array. Then traverse it in reverse order to be sure that if
> the console is preferred then it will be the first matching entry.
> Introduce variable console_cmdline_cnt that keeps the number
> of elements of the console_cmdline array (Petr Mladek). It helps
> to get rid of the loop that searches for the end of this array.

> #define MAX_CMDLINECONSOLES 8
>
> static struct console_cmdline console_cmdline[MAX_CMDLINECONSOLES];
> +static int console_cmdline_cnt;

This should be equal to -1 at the beginning, am I right?

> static int preferred_console = -1;
> int console_set_on_cmdline;
> @@ -1905,12 +1906,26 @@ static int __add_preferred_console(char *name, int idx, char *options,
> * See if this tty is not yet registered, and
> * if we have a slot free.
> */
> - for (i = 0, c = console_cmdline;
> - i < MAX_CMDLINECONSOLES && c->name[0];
> - i++, c++) {
> + for (i = 0, c = console_cmdline; i < console_cmdline_cnt; i++, c++) {
> if (strcmp(c->name, name) == 0 && c->index == idx) {
> - if (!brl_options)
> - preferred_console = i;
> +

> + if (brl_options)
> + return 0;

Is it invariant or brl_options may appear while looping?

> +
> + /*
> + * Maintain an invariant that will help to find if
> + * the matching console is preferred, see
> + * register_console():
> + *
> + * The last non-braille console is always
> + * the preferred one.
> + */
> + if (i != console_cmdline_cnt - 1)
> + swap(console_cmdline[i],
> + console_cmdline[console_cmdline_cnt - 1]);

i'm wondering if you can iterate from the end to beginning as you do below.
It would simplify things.

> +
> + preferred_console = console_cmdline_cnt - 1;
> +
> return 0;
> }
> }
> @@ -1923,6 +1938,7 @@ static int __add_preferred_console(char *name, int idx, char *options,
> braille_set_options(c, brl_options);
>
> c->index = idx;
> + console_cmdline_cnt++;
> return 0;
> }
> /*
> @@ -2457,12 +2473,24 @@ void register_console(struct console *newcon)
> }
>
> /*
> - * See if this console matches one we selected on
> - * the command line.
> + * See if this console matches one we selected on the command line.
> + *
> + * There may be several entries in the console_cmdline array matching
> + * with the same console, one with newcon->match(), another by
> + * name/index:
> + *
> + * pl011,mmio,0x87e024000000,115200 -- added from SPCR
> + * ttyAMA0 -- added from command line
> + *
> + * Traverse the console_cmdline array in reverse order to be
> + * sure that if this console is preferred then it will be the first
> + * matching entry. We use the invariant that is maintained in
> + * __add_preferred_console().
> */
> - for (i = 0, c = console_cmdline;
> - i < MAX_CMDLINECONSOLES && c->name[0];
> - i++, c++) {

> + for (i = console_cmdline_cnt - 1; i >= 0; i--) {



> +
> + c = console_cmdline + i;
> +
> if (!newcon->match ||
> newcon->match(newcon, c->name, c->index, c->options) != 0) {
> /* default matching */
> --
> 2.12.1
>



--
With Best Regards,
Andy Shevchenko

2017-04-06 04:44:21

by Aleksey Makarov

[permalink] [raw]
Subject: Re: [PATCH v9 3/3] printk: fix double printing with earlycon



On 04/06/2017 12:57 AM, Andy Shevchenko wrote:
> On Wed, Apr 5, 2017 at 11:20 PM, Aleksey Makarov
> <[email protected]> wrote:
>> If a console was specified by ACPI SPCR table _and_ command line
>> parameters like "console=ttyAMA0" _and_ "earlycon" were specified,
>> then log messages appear twice.
>>
>> The root cause is that the code traverses the list of specified
>> consoles (the `console_cmdline` array) and stops at the first match.
>> But it may happen that the same console is referred by the elements
>> of this array twice:
>>
>> pl011,mmio,0x87e024000000,115200 -- from SPCR
>> ttyAMA0 -- from command line
>>
>> but in this case `preferred_console` points to the second entry and
>> the flag CON_CONSDEV is not set, so bootconsole is not deregistered.
>>
>> To fix that, introduce an invariant "The last non-braille console
>> is always the preferred one" on the entries of the console_cmdline
>> array. Then traverse it in reverse order to be sure that if
>> the console is preferred then it will be the first matching entry.
>> Introduce variable console_cmdline_cnt that keeps the number
>> of elements of the console_cmdline array (Petr Mladek). It helps
>> to get rid of the loop that searches for the end of this array.
>
>> #define MAX_CMDLINECONSOLES 8
>>
>> static struct console_cmdline console_cmdline[MAX_CMDLINECONSOLES];
>> +static int console_cmdline_cnt;
>
> This should be equal to -1 at the beginning, am I right?

No, this is not an index of the last element, this is count of
elements of cmdline_console array. So it is 0 initially.

>> static int preferred_console = -1;
>> int console_set_on_cmdline;
>> @@ -1905,12 +1906,26 @@ static int __add_preferred_console(char *name, int idx, char *options,
>> * See if this tty is not yet registered, and
>> * if we have a slot free.
>> */
>> - for (i = 0, c = console_cmdline;
>> - i < MAX_CMDLINECONSOLES && c->name[0];
>> - i++, c++) {
>> + for (i = 0, c = console_cmdline; i < console_cmdline_cnt; i++, c++) {
>> if (strcmp(c->name, name) == 0 && c->index == idx) {
>> - if (!brl_options)
>> - preferred_console = i;
>> +
>
>> + if (brl_options)
>> + return 0;
>
> Is it invariant or brl_options may appear while looping?

I am not sure I understand your question.
If we find that we are registering a braille console that
has already been registered, we just return without updating
preferred console (it is only about regular consoles) and
without swapping it with the last element of the array (because it
is explicitly mentioned in the invariant: The last
*non-braille* console is always the preferred one)

>> +
>> + /*
>> + * Maintain an invariant that will help to find if
>> + * the matching console is preferred, see
>> + * register_console():
>> + *
>> + * The last non-braille console is always
>> + * the preferred one.
>> + */
>> + if (i != console_cmdline_cnt - 1)
>> + swap(console_cmdline[i],
>> + console_cmdline[console_cmdline_cnt - 1]);
>
> i'm wondering if you can iterate from the end to beginning as you do below.
> It would simplify things.

You mean iterate to find the last element?
Yes I can and it is how this was implemented in v8,
Petr Mladek asked to introduce console_cmdline_cnt.

Thank you for review
Aleksey Makarov

>> +
>> + preferred_console = console_cmdline_cnt - 1;
>> +
>> return 0;
>> }
>> }
>> @@ -1923,6 +1938,7 @@ static int __add_preferred_console(char *name, int idx, char *options,
>> braille_set_options(c, brl_options);
>>
>> c->index = idx;
>> + console_cmdline_cnt++;
>> return 0;
>> }
>> /*
>> @@ -2457,12 +2473,24 @@ void register_console(struct console *newcon)
>> }
>>
>> /*
>> - * See if this console matches one we selected on
>> - * the command line.
>> + * See if this console matches one we selected on the command line.
>> + *
>> + * There may be several entries in the console_cmdline array matching
>> + * with the same console, one with newcon->match(), another by
>> + * name/index:
>> + *
>> + * pl011,mmio,0x87e024000000,115200 -- added from SPCR
>> + * ttyAMA0 -- added from command line
>> + *
>> + * Traverse the console_cmdline array in reverse order to be
>> + * sure that if this console is preferred then it will be the first
>> + * matching entry. We use the invariant that is maintained in
>> + * __add_preferred_console().
>> */
>> - for (i = 0, c = console_cmdline;
>> - i < MAX_CMDLINECONSOLES && c->name[0];
>> - i++, c++) {
>
>> + for (i = console_cmdline_cnt - 1; i >= 0; i--) {
>
>
>
>> +
>> + c = console_cmdline + i;
>> +
>> if (!newcon->match ||
>> newcon->match(newcon, c->name, c->index, c->options) != 0) {
>> /* default matching */
>> --
>> 2.12.1
>>
>
>
>

2017-04-10 14:22:19

by Petr Mladek

[permalink] [raw]
Subject: Re: [PATCH v9 3/3] printk: fix double printing with earlycon

On Wed 2017-04-05 23:20:00, Aleksey Makarov wrote:
> If a console was specified by ACPI SPCR table _and_ command line
> parameters like "console=ttyAMA0" _and_ "earlycon" were specified,
> then log messages appear twice.
>
> The root cause is that the code traverses the list of specified
> consoles (the `console_cmdline` array) and stops at the first match.
> But it may happen that the same console is referred by the elements
> of this array twice:
>
> pl011,mmio,0x87e024000000,115200 -- from SPCR
> ttyAMA0 -- from command line
>
> but in this case `preferred_console` points to the second entry and
> the flag CON_CONSDEV is not set, so bootconsole is not deregistered.
>
> To fix that, introduce an invariant "The last non-braille console
> is always the preferred one" on the entries of the console_cmdline
> array. Then traverse it in reverse order to be sure that if
> the console is preferred then it will be the first matching entry.
> Introduce variable console_cmdline_cnt that keeps the number
> of elements of the console_cmdline array (Petr Mladek). It helps
> to get rid of the loop that searches for the end of this array.
>
> Reported-by: Sudeep Holla <[email protected]>
> Signed-off-by: Aleksey Makarov <[email protected]>

This version looks fine to me. Just a small nitpick below.
Anyway:

Reviewed-by: Petr Mladek <[email protected]>

> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index fd752f0c8ef1..be657af45758 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -269,6 +269,7 @@ static struct console *exclusive_console;
> #define MAX_CMDLINECONSOLES 8
>
> static struct console_cmdline console_cmdline[MAX_CMDLINECONSOLES];
> +static int console_cmdline_cnt;
>
> static int preferred_console = -1;
> int console_set_on_cmdline;
> @@ -1905,12 +1906,26 @@ static int __add_preferred_console(char *name, int idx, char *options,
> * See if this tty is not yet registered, and
> * if we have a slot free.
> */
> - for (i = 0, c = console_cmdline;
> - i < MAX_CMDLINECONSOLES && c->name[0];
> - i++, c++) {
> + for (i = 0, c = console_cmdline; i < console_cmdline_cnt; i++, c++) {
> if (strcmp(c->name, name) == 0 && c->index == idx) {
> - if (!brl_options)
> - preferred_console = i;
> +

This extra new line is non-standard and looks slightly weird to me.
I just point it out. I personally do not mind ;-)


> + if (brl_options)
> + return 0;
> +
> + /*
> + * Maintain an invariant that will help to find if
> + * the matching console is preferred, see
> + * register_console():
> + *
> + * The last non-braille console is always
> + * the preferred one.
> + */
> + if (i != console_cmdline_cnt - 1)
> + swap(console_cmdline[i],
> + console_cmdline[console_cmdline_cnt - 1]);
> +
> + preferred_console = console_cmdline_cnt - 1;
> +
> return 0;
> }
> }
> @@ -2457,12 +2473,24 @@ void register_console(struct console *newcon)
> }
>
> /*
> - * See if this console matches one we selected on
> - * the command line.
> + * See if this console matches one we selected on the command line.
> + *
> + * There may be several entries in the console_cmdline array matching
> + * with the same console, one with newcon->match(), another by
> + * name/index:
> + *
> + * pl011,mmio,0x87e024000000,115200 -- added from SPCR
> + * ttyAMA0 -- added from command line
> + *
> + * Traverse the console_cmdline array in reverse order to be
> + * sure that if this console is preferred then it will be the first
> + * matching entry. We use the invariant that is maintained in
> + * __add_preferred_console().
> */
> - for (i = 0, c = console_cmdline;
> - i < MAX_CMDLINECONSOLES && c->name[0];
> - i++, c++) {
> + for (i = console_cmdline_cnt - 1; i >= 0; i--) {
> +

Same here.

> + c = console_cmdline + i;
> +
> if (!newcon->match ||
> newcon->match(newcon, c->name, c->index, c->options) != 0) {
> /* default matching */

Best Regards,
Petr

2017-04-10 18:00:42

by Aleksey Makarov

[permalink] [raw]
Subject: Re: [PATCH v9 3/3] printk: fix double printing with earlycon



On 04/10/2017 05:22 PM, Petr Mladek wrote:
> On Wed 2017-04-05 23:20:00, Aleksey Makarov wrote:
>> If a console was specified by ACPI SPCR table _and_ command line
>> parameters like "console=ttyAMA0" _and_ "earlycon" were specified,
>> then log messages appear twice.
>>
>> The root cause is that the code traverses the list of specified
>> consoles (the `console_cmdline` array) and stops at the first match.
>> But it may happen that the same console is referred by the elements
>> of this array twice:
>>
>> pl011,mmio,0x87e024000000,115200 -- from SPCR
>> ttyAMA0 -- from command line
>>
>> but in this case `preferred_console` points to the second entry and
>> the flag CON_CONSDEV is not set, so bootconsole is not deregistered.
>>
>> To fix that, introduce an invariant "The last non-braille console
>> is always the preferred one" on the entries of the console_cmdline
>> array. Then traverse it in reverse order to be sure that if
>> the console is preferred then it will be the first matching entry.
>> Introduce variable console_cmdline_cnt that keeps the number
>> of elements of the console_cmdline array (Petr Mladek). It helps
>> to get rid of the loop that searches for the end of this array.
>>
>> Reported-by: Sudeep Holla <[email protected]>
>> Signed-off-by: Aleksey Makarov <[email protected]>
>
> This version looks fine to me. Just a small nitpick below.
> Anyway:
>
> Reviewed-by: Petr Mladek <[email protected]>

Thank you for review. Can you (or anybody else) ACK it?
I am going to resend the whole series without those empty lines.
May I add your Acked-by:?

Thank you
Aleksey Makarov

>> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
>> index fd752f0c8ef1..be657af45758 100644
>> --- a/kernel/printk/printk.c
>> +++ b/kernel/printk/printk.c
>> @@ -269,6 +269,7 @@ static struct console *exclusive_console;
>> #define MAX_CMDLINECONSOLES 8
>>
>> static struct console_cmdline console_cmdline[MAX_CMDLINECONSOLES];
>> +static int console_cmdline_cnt;
>>
>> static int preferred_console = -1;
>> int console_set_on_cmdline;
>> @@ -1905,12 +1906,26 @@ static int __add_preferred_console(char *name, int idx, char *options,
>> * See if this tty is not yet registered, and
>> * if we have a slot free.
>> */
>> - for (i = 0, c = console_cmdline;
>> - i < MAX_CMDLINECONSOLES && c->name[0];
>> - i++, c++) {
>> + for (i = 0, c = console_cmdline; i < console_cmdline_cnt; i++, c++) {
>> if (strcmp(c->name, name) == 0 && c->index == idx) {
>> - if (!brl_options)
>> - preferred_console = i;
>> +
>
> This extra new line is non-standard and looks slightly weird to me.
> I just point it out. I personally do not mind ;-)
>
>
>> + if (brl_options)
>> + return 0;
>> +
>> + /*
>> + * Maintain an invariant that will help to find if
>> + * the matching console is preferred, see
>> + * register_console():
>> + *
>> + * The last non-braille console is always
>> + * the preferred one.
>> + */
>> + if (i != console_cmdline_cnt - 1)
>> + swap(console_cmdline[i],
>> + console_cmdline[console_cmdline_cnt - 1]);
>> +
>> + preferred_console = console_cmdline_cnt - 1;
>> +
>> return 0;
>> }
>> }
>> @@ -2457,12 +2473,24 @@ void register_console(struct console *newcon)
>> }
>>
>> /*
>> - * See if this console matches one we selected on
>> - * the command line.
>> + * See if this console matches one we selected on the command line.
>> + *
>> + * There may be several entries in the console_cmdline array matching
>> + * with the same console, one with newcon->match(), another by
>> + * name/index:
>> + *
>> + * pl011,mmio,0x87e024000000,115200 -- added from SPCR
>> + * ttyAMA0 -- added from command line
>> + *
>> + * Traverse the console_cmdline array in reverse order to be
>> + * sure that if this console is preferred then it will be the first
>> + * matching entry. We use the invariant that is maintained in
>> + * __add_preferred_console().
>> */
>> - for (i = 0, c = console_cmdline;
>> - i < MAX_CMDLINECONSOLES && c->name[0];
>> - i++, c++) {
>> + for (i = console_cmdline_cnt - 1; i >= 0; i--) {
>> +
>
> Same here.
>
>> + c = console_cmdline + i;
>> +
>> if (!newcon->match ||
>> newcon->match(newcon, c->name, c->index, c->options) != 0) {
>> /* default matching */
>
> Best Regards,
> Petr
>

2017-04-11 01:54:27

by Sergey Senozhatsky

[permalink] [raw]
Subject: Re: [PATCH v9 3/3] printk: fix double printing with earlycon

On (04/10/17 21:00), Aleksey Makarov wrote:
> On 04/10/2017 05:22 PM, Petr Mladek wrote:
> > On Wed 2017-04-05 23:20:00, Aleksey Makarov wrote:
[..]
> > > To fix that, introduce an invariant "The last non-braille console
> > > is always the preferred one" on the entries of the console_cmdline
> > > array. Then traverse it in reverse order to be sure that if
> > > the console is preferred then it will be the first matching entry.
> > > Introduce variable console_cmdline_cnt that keeps the number
> > > of elements of the console_cmdline array (Petr Mladek). It helps
> > > to get rid of the loop that searches for the end of this array.
> > >
> > > Reported-by: Sudeep Holla <[email protected]>
> > > Signed-off-by: Aleksey Makarov <[email protected]>
> >
> > This version looks fine to me. Just a small nitpick below.
> > Anyway:
> >
> > Reviewed-by: Petr Mladek <[email protected]>
>
> Thank you for review. Can you (or anybody else) ACK it?
> I am going to resend the whole series without those empty lines.
> May I add your Acked-by:?

Acked-by: Sergey Senozhatsky <[email protected]>

feel free to resend. I know some setups that have repeating (double)
lines on the serial console, I'll ask people to test the patches.

-ss

2017-04-11 07:43:44

by Petr Mladek

[permalink] [raw]
Subject: Re: [PATCH v9 3/3] printk: fix double printing with earlycon

On Mon 2017-04-10 21:00:35, Aleksey Makarov wrote:
>
>
> On 04/10/2017 05:22 PM, Petr Mladek wrote:
> >On Wed 2017-04-05 23:20:00, Aleksey Makarov wrote:
> >>If a console was specified by ACPI SPCR table _and_ command line
> >>parameters like "console=ttyAMA0" _and_ "earlycon" were specified,
> >>then log messages appear twice.
> >>
> >>The root cause is that the code traverses the list of specified
> >>consoles (the `console_cmdline` array) and stops at the first match.
> >>But it may happen that the same console is referred by the elements
> >>of this array twice:
> >>
> >> pl011,mmio,0x87e024000000,115200 -- from SPCR
> >> ttyAMA0 -- from command line
> >>
> >>but in this case `preferred_console` points to the second entry and
> >>the flag CON_CONSDEV is not set, so bootconsole is not deregistered.
> >>
> >>To fix that, introduce an invariant "The last non-braille console
> >>is always the preferred one" on the entries of the console_cmdline
> >>array. Then traverse it in reverse order to be sure that if
> >>the console is preferred then it will be the first matching entry.
> >>Introduce variable console_cmdline_cnt that keeps the number
> >>of elements of the console_cmdline array (Petr Mladek). It helps
> >>to get rid of the loop that searches for the end of this array.
> >>
> >>Reported-by: Sudeep Holla <[email protected]>
> >>Signed-off-by: Aleksey Makarov <[email protected]>
> >
> >This version looks fine to me. Just a small nitpick below.
> >Anyway:
> >
> >Reviewed-by: Petr Mladek <[email protected]>
>
> Thank you for review. Can you (or anybody else) ACK it?
> I am going to resend the whole series without those empty lines.
> May I add your Acked-by:?

Sure. Feel free to use:

Acked-by: Petr Mladek <[email protected]>

The meaning of the tags is a bit unclear. Acked-by means that
the maintainer agrees with the idea. But it does not necessarily
means that she reviewed the code in details. I agree with the idea
and did the review, so I used the Reviewed-by tag.

Also you do not need to resend the patchset just because the two
empty lines. Sergey agrees. I will wait day or two and push
all three patches into the printk.git if nobody complains
in the meantime. I could remove the two empty lines when doing so.

Thanks a lot for the fix and patience.

Best Regards,
Petr

2017-04-12 06:24:21

by Aleksey Makarov

[permalink] [raw]
Subject: Re: [PATCH v9 3/3] printk: fix double printing with earlycon



On 04/11/2017 10:43 AM, Petr Mladek wrote:
> On Mon 2017-04-10 21:00:35, Aleksey Makarov wrote:
>>
>>
>> On 04/10/2017 05:22 PM, Petr Mladek wrote:
>>> On Wed 2017-04-05 23:20:00, Aleksey Makarov wrote:

[..]

>> Thank you for review. Can you (or anybody else) ACK it?
>> I am going to resend the whole series without those empty lines.
>> May I add your Acked-by:?
>
> Sure. Feel free to use:
>
> Acked-by: Petr Mladek <[email protected]>
>
> The meaning of the tags is a bit unclear. Acked-by means that
> the maintainer agrees with the idea. But it does not necessarily
> means that she reviewed the code in details. I agree with the idea
> and did the review, so I used the Reviewed-by tag.
>
> Also you do not need to resend the patchset just because the two
> empty lines. Sergey agrees. I will wait day or two and push
> all three patches into the printk.git if nobody complains
> in the meantime. I could remove the two empty lines when doing so.

Ok, then I will not resend it.

> Thanks a lot for the fix and patience.

Thank you for reviewing and acking it.
Aleksey Makarov

2017-06-01 12:03:30

by Petr Mladek

[permalink] [raw]
Subject: Re: [PATCH v9 3/3] printk: fix double printing with earlycon

On Fri 2017-05-26 12:37:12, Aleksey Makarov wrote:
>
>
> On 05/18/2017 06:49 PM, Petr Mladek wrote:
> >On Sun 2017-05-14 23:37:50, Aleksey Makarov wrote:
> >>
> >>
> >>On 05/12/2017 03:57 PM, Petr Mladek wrote:
> >>>On Thu 2017-05-11 17:41:58, Sergey Senozhatsky wrote:
> I meant that it is difficult to fix the bug that only one line
> (first matched) of registered console device receives kernel logs.
> That is because of 'index' field of struct console can refer to only one
> tty line.

I think that bigger problem is that con->match() functions have
side effects and we could not try matching all consoles
mentioned in console_cmdline. Otherwise, we would be able
to enable all mentioned ttyS* drivers that are listed.


> - The reason why logs appear twice is that earlycon is not
> deregistered after non-early consoles are available.

OK

> - Earlycon is not deregistered because in some cases
> flag CON_CONSDEV is not set for any of the new non-early
> consoles.

This is one explanation. Another reason might be that
an early console is added into console_cmdline by mistake.
By other words, if early consoles are not mentioned in
console_cmdline we could not mismatch them with the normal
console. See below for more on this idea.


> - That flag is not set when two entries of console_cmdline
> array refer to the same console. We match the first entry,
> it is not preferred and the flag CON_CONSDEV is set only
> for preferred console.
>
> - So I changed the order of array walk so that if there
> are two entries referring to the same console, last one is matched.
> If we specify a console as prefered (last entry in command line)
> that means that we expect a driver will eventually register
> its console and for that driver we will match the last
> entry and the earlycon will be deregistered.

This still handles the problem only for the preferred (last entry
in command line) console. In theory, there might be more consoles
listed twice.


> - The subtle question is why we deregister earlycon only
> when CON_CONSDEV is set (i. e. only for preferred console).
> That check for CON_CONSDEV was initially introduced in
>
> d37bf60de0b4 console: console handover to preferred console
>
> and then refactored in
>
> 4d09161196c9 printk: Enable the use of more than one CON_BOOT (early console)
> 8259cf434202 printk: Ensure that "console enabled" messages are printed on the console
>
> The reason is that some consoles can be registered later or earlier
> and if we deregister earlycon when the first non-early console
> is registered, we can lose some lines of log. To prevent that
> we specify the console *which is being watched* as preferred
> (the last console in the console_cmdline array) and
> deregister earlycon only when kernel registers its driver.

Good to know. Thanks a lot for the archaeology.


> >BTW: I wonder if we really need to add consoles defined by ACPI SPCR
> >table into the console_cmdline array.
>
> The console_cmdline array is the place where we add descriptions
> of consoles that should receive log output. ACPI SPCR specifies exactly
> that information, and I believe it should go to that array.

Are consoles defined by earlycon= command line parameter
added to console_cmdline? I do not see this anywhere in
the following functions:

+ param_setup_earlycon()
+ setup_earlycon()
+ register_earlycon()
+ early_init_dt_scan_chosen_stdout()
+ of_setup_earlycon()

IMHO, the main question is whether the console defined by
ACPI SPCR is early or normal one. IMHO, it is early console
and it should be handled the same way as the other early
consoles.


> >I am even more curious when
> >seeing the following code in drivers/acpi/spcr.c:
> >
> >int __init parse_spcr(bool earlycon) { [...] if (earlycon)
> >setup_earlycon(opts);

setup_early() calls register_earlycon() when the console is
found in __earlycon_table. Then it calls register_console().

I guess that the console is enabled here because we do not
have preferred cosole when this is called. Therefore it is
enabled by the following code:

/*
* See if we want to use this console driver. If we
* didn't select a console we take the first one
* that registers here.
*/
if (!has_preferred) {
if (newcon->index < 0)
newcon->index = 0;
if (newcon->setup == NULL ||
newcon->setup(newcon, NULL) == 0) {
newcon->flags |= CON_ENABLED;
if (newcon->device) {
newcon->flags |= CON_CONSDEV;
has_preferred = true;
}

Note that it gets enabled without being listed in console_cmdline.

> >err = add_preferred_console(uart, 0, opts + strlen(uart) + 1); }

Then it is added to the console_cmdline after being enabled.
Let's discuss why below.

> >Do we really need to call add_preferred_console() for
> these early consoles?
>
> Yes we need.

Why exactly?

> When we setup an earlycon, we enable output
> to that console immediately. Drivers can register its real
> non-early consoles much later so we just add description
> of that consoles to the console_cmdline arraly so that
> when the driver registers a matching driver, earlycon is replaced
> by a regular device.

console_cmdline is used to match the newly registered consoles.
If it matches and newcon->setup() succeeds, the console is enabled.
Why do we need to match the new consoles with the already
registered and enabled one?

Please, note that the early consoles are disabled using
the "console_drivers" list. They do not need to be listed in
"console_cmdline" to be disabled.

Do I miss something?

Best Regards,
Petr

2017-06-06 14:31:56

by Petr Mladek

[permalink] [raw]
Subject: Re: [PATCH v9 3/3] printk: fix double printing with earlycon

On Thu 2017-06-01 14:03:25, Petr Mladek wrote:
> On Fri 2017-05-26 12:37:12, Aleksey Makarov wrote:
> > The console_cmdline array is the place where we add descriptions
> > of consoles that should receive log output. ACPI SPCR specifies exactly
> > that information, and I believe it should go to that array.
>
> Are consoles defined by earlycon= command line parameter
> added to console_cmdline? I do not see this anywhere in
> the following functions:
>
> + param_setup_earlycon()
> + setup_earlycon()
> + register_earlycon()
> + early_init_dt_scan_chosen_stdout()
> + of_setup_earlycon()
>
> IMHO, the main question is whether the console defined by
> ACPI SPCR is early or normal one.

The answer is that it depends. The console defined by ACPI
SPCR is early when just 'earlycon' is defined on the command
line. See param_setup_earlycon() and the use of
earlycon_init_is_deferred. Otherwise, it is supposed to
be a normal console.

We need to call add_preferred_console() in parse_spcr()
to allow using the console as a normal one.

We must also work correctly when the user explicitly defines
the console on the command line, using another alias.

As a result, we could not easily prevent having two matching consoles
in console_cmdline list. And as long as the last mentioned console
has the special status (preferred_console, CON_CONSDEV), it would
make sense to try matching the preferred console first.

Sadly, it causes the change of the behavior of ttyS0 and ttyS1.


Now, systemd seems to handle the console= parameters as well.
According to http://0pointer.de/blog/projects/serial-console.html,
systemd instantiates one [email protected] on the preferred
(last mentioned) console.

This might be a reason to define both console=ttyS0 console=ttyS1
on the command line. People might actually want to get the logs
and the login prompt on different console.

Well, it is a bug that kernel shows the messages only on one
console.


There is one more thing that I found. Early consoles are forcefully
removed in a late_initcall(printk_late_init). It happens when they
use a code that is discarded after all initcalls finishes.
This has two effects.

First, boot consoles are removed even when the preferred one
is not registered. This explains why we need to call both
setup_earlycon() and add_preferred_console() in parse_spcr().

Second, the boot console might be removed before the normal/preferred
one is registered. For example, the normal one might be registered later
by a deferred probe call. As a result, the normal console might miss
that there was an early one, replays the entire log, and you
might see the beginning of the log twice.


All in all, I think that I have finally understood what
Aleksey wanted to say in his great summary, see
https://lkml.kernel.org/r/[email protected]
My proposed solution in parse_spcr() do not fly.

And I am still undecided about the Alexey's patch:

+ the patch makes some sense

+ but people might see the changed order as regressions;
there might be more users, especially because of systemd

+ IMHO, the patch fixed the duplicit output only partly;
it would not help when the normal console is registered
later


Best Regards,
Petr

2017-06-06 16:03:46

by Petr Mladek

[permalink] [raw]
Subject: Re: [PATCH v9 3/3] printk: fix double printing with earlycon

On Tue 2017-06-06 16:31:49, Petr Mladek wrote:
> On Thu 2017-06-01 14:03:25, Petr Mladek wrote:
> Now, systemd seems to handle the console= parameters as well.
> According to http://0pointer.de/blog/projects/serial-console.html,
> systemd instantiates one [email protected] on the preferred
> (last mentioned) console.
>
> This might be a reason to define both console=ttyS0 console=ttyS1
> on the command line. People might actually want to get the logs
> and the login prompt on different console.

I have consulted this with a colleague. I am sorry to say but we
believe that this fits into the category of breaking userspace
(systemd, qemu). I would like to revert the patch ASAP,
before rc5. Here is a proposal of the commit message:


>From 142d75792d0df874e80493654311f69f6a1ca798 Mon Sep 17 00:00:00 2001
From: Petr Mladek <[email protected]>
Date: Tue, 6 Jun 2017 17:20:38 +0200
Subject: [PATCH] Revert "printk: fix double printing with earlycon"

The commit cf39bf58afdaabc ("printk: fix double printing with earlycon")
caused regression to users that define both console=ttyS1 and console=ttyS0
on the command line, see
https://lkml.kernel.org/r/[email protected]

The kernel log messages always appeared only on one serial port. It is
even documented in Documentation/admin-guide/serial-console.rst:

"Note that you can only define one console per device type (serial,
video)."

The above mentioned commit changed the order in which the command line
parameters are searched. As a result, the kernel log messages go to
the last mentioned ttyS* instead of the first one.

We long thought that using two console=ttyS* on the command line
did not make sense. But then we realized that console= parameters
were handled also by systemd, see
http://0pointer.de/blog/projects/serial-console.html

"By default systemd will instantiate one [email protected] on
the main kernel console, if it is not a virtual terminal."

where

"[4] If multiple kernel consoles are used simultaneously, the main
console is the one listed first in /sys/class/tty/console/active,
which is the last one listed on the kernel command line."

This puts the original report into another light. The system is running
in qemu. The first serial port is used to store the messages into a file.
The second one is used to login to the system via a socket. It depends
on systemd and the historic kernel behavior.

By other words, systemd causes that it makes sense to define both
console=ttyS1 console=ttyS0 on the command line. The kernel fix
caused regression related to userspace (systemd) and need to be
reverted.

In addition, it went out that the fix helped only partially.
The messages still were duplicated when the boot console was
removed early by late_initcall(printk_late_init). Then the entire
log was replayed when the same console was registered as a normal one.

This reverts commit cf39bf58afdaabc0b86f141630fb3fd18190294e.
---
kernel/printk/printk.c | 46 ++++++++++------------------------------------
1 file changed, 10 insertions(+), 36 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index a1aecf44ab07..a1db38abac5b 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -269,7 +269,6 @@ static void __up_console_sem(unsigned long ip)
#define MAX_CMDLINECONSOLES 8

static struct console_cmdline console_cmdline[MAX_CMDLINECONSOLES];
-static int console_cmdline_cnt;

static int preferred_console = -1;
int console_set_on_cmdline;
@@ -1906,25 +1905,12 @@ static int __add_preferred_console(char *name, int idx, char *options,
* See if this tty is not yet registered, and
* if we have a slot free.
*/
- for (i = 0, c = console_cmdline; i < console_cmdline_cnt; i++, c++) {
+ for (i = 0, c = console_cmdline;
+ i < MAX_CMDLINECONSOLES && c->name[0];
+ i++, c++) {
if (strcmp(c->name, name) == 0 && c->index == idx) {
- if (brl_options)
- return 0;
-
- /*
- * Maintain an invariant that will help to find if
- * the matching console is preferred, see
- * register_console():
- *
- * The last non-braille console is always
- * the preferred one.
- */
- if (i != console_cmdline_cnt - 1)
- swap(console_cmdline[i],
- console_cmdline[console_cmdline_cnt - 1]);
-
- preferred_console = console_cmdline_cnt - 1;
-
+ if (!brl_options)
+ preferred_console = i;
return 0;
}
}
@@ -1937,7 +1923,6 @@ static int __add_preferred_console(char *name, int idx, char *options,
braille_set_options(c, brl_options);

c->index = idx;
- console_cmdline_cnt++;
return 0;
}
/*
@@ -2477,23 +2462,12 @@ void register_console(struct console *newcon)
}

/*
- * See if this console matches one we selected on the command line.
- *
- * There may be several entries in the console_cmdline array matching
- * with the same console, one with newcon->match(), another by
- * name/index:
- *
- * pl011,mmio,0x87e024000000,115200 -- added from SPCR
- * ttyAMA0 -- added from command line
- *
- * Traverse the console_cmdline array in reverse order to be
- * sure that if this console is preferred then it will be the first
- * matching entry. We use the invariant that is maintained in
- * __add_preferred_console().
+ * See if this console matches one we selected on
+ * the command line.
*/
- for (i = console_cmdline_cnt - 1; i >= 0; i--) {
- c = console_cmdline + i;
-
+ for (i = 0, c = console_cmdline;
+ i < MAX_CMDLINECONSOLES && c->name[0];
+ i++, c++) {
if (!newcon->match ||
newcon->match(newcon, c->name, c->index, c->options) != 0) {
/* default matching */
--
1.8.5.6

2017-06-07 09:13:24

by Sergey Senozhatsky

[permalink] [raw]
Subject: Re: [PATCH v9 3/3] printk: fix double printing with earlycon

On (06/06/17 18:03), Petr Mladek wrote:
[..]
> From 142d75792d0df874e80493654311f69f6a1ca798 Mon Sep 17 00:00:00 2001
> From: Petr Mladek <[email protected]>
> Date: Tue, 6 Jun 2017 17:20:38 +0200
> Subject: [PATCH] Revert "printk: fix double printing with earlycon"
>
> The commit cf39bf58afdaabc ("printk: fix double printing with earlycon")
> caused regression to users that define both console=ttyS1 and console=ttyS0
> on the command line, see
> https://lkml.kernel.org/r/[email protected]
>
> The kernel log messages always appeared only on one serial port. It is
> even documented in Documentation/admin-guide/serial-console.rst:
>
> "Note that you can only define one console per device type (serial,
> video)."
>
> The above mentioned commit changed the order in which the command line
> parameters are searched. As a result, the kernel log messages go to
> the last mentioned ttyS* instead of the first one.
>
> We long thought that using two console=ttyS* on the command line
> did not make sense. But then we realized that console= parameters
> were handled also by systemd, see
> http://0pointer.de/blog/projects/serial-console.html
>
> "By default systemd will instantiate one [email protected] on
> the main kernel console, if it is not a virtual terminal."
>
> where
>
> "[4] If multiple kernel consoles are used simultaneously, the main
> console is the one listed first in /sys/class/tty/console/active,
> which is the last one listed on the kernel command line."
>
> This puts the original report into another light. The system is running
> in qemu. The first serial port is used to store the messages into a file.
> The second one is used to login to the system via a socket. It depends
> on systemd and the historic kernel behavior.
>
> By other words, systemd causes that it makes sense to define both
> console=ttyS1 console=ttyS0 on the command line. The kernel fix
> caused regression related to userspace (systemd) and need to be
> reverted.
>
> In addition, it went out that the fix helped only partially.
> The messages still were duplicated when the boot console was
> removed early by late_initcall(printk_late_init). Then the entire
> log was replayed when the same console was registered as a normal one.
>
> This reverts commit cf39bf58afdaabc0b86f141630fb3fd18190294e.

FWIW,

Acked-by: Sergey Senozhatsky <[email protected]>


the whole thing is too fragile and, may be, it deserves a rewrite.

I agree with the decision to revert the patch. a user space visible
regression is a pretty annoying thing; even a rare one. it takes ~1-2
years until kernel release hits major vendors/users so the biggest part
of regressions might be years away, but in the meantime we can grow a
number of new setups that will depend on a new console= behavior. so
I'd prefer to revert early.

Petr, Aleksey, many thanks, good work.

-ss