Mailing List Archive: [PATCH v5 3/3] printk: fix double printing with earlycon

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

Mar 15, 2017, 4:20 AM

Post #1 of 6 (45 views)

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 <sudeep.holla@arm.com>
Signed-off-by: Aleksey Makarov <aleksey.makarov@linaro.org>
---
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

Re: [PATCH v5 3/3] printk: fix double printing with earlycon [ In reply to ]

pmladek at suse

Mar 15, 2017, 10:20 AM

Post #2 of 6 (44 views)

Permalink

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 <sudeep.holla@arm.com>
> Signed-off-by: Aleksey Makarov <aleksey.makarov@linaro.org>
> ---
> 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

Re: [PATCH v5 3/3] printk: fix double printing with earlycon [ In reply to ]

sergey.senozhatsky.work at gmail

Mar 16, 2017, 1:05 AM

Post #3 of 6 (44 views)

Permalink

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

Re: [PATCH v5 3/3] printk: fix double printing with earlycon [ In reply to ]

aleksey.makarov at linaro

Mar 16, 2017, 4:20 AM

Post #4 of 6 (44 views)

Permalink

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 <sudeep.holla@arm.com>
>> Signed-off-by: Aleksey Makarov <aleksey.makarov@linaro.org>
>> ---
>> 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 majordomo@vger.kernel.org
> More majordomo info at http://vger.kernel.org/majordomo-info.html
>

Re: [PATCH v5 3/3] printk: fix double printing with earlycon [ In reply to ]

pmladek at suse

Mar 16, 2017, 8:20 AM

Post #5 of 6 (43 views)

Permalink

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

Re: [PATCH v5 3/3] printk: fix double printing with earlycon [ In reply to ]

amakarov.linux at gmail

Mar 17, 2017, 4:20 AM

Post #6 of 6 (43 views)

Permalink

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 majordomo@vger.kernel.org
> More majordomo info at http://vger.kernel.org/majordomo-info.html
>