[PATCH -next] x86/apic: Reduce print level of CPU limit announcement

[PATCH -next] x86/apic: Reduce print level of CPU limit announcement

[Leon Romanovsky]

From: Leon Romanovsky <leonro@mellanox.com>

Kernel is booted with less possible CPUs (possible_cpus kernel boot
option) than available CPUs will have prints like this:

[    1.131039] APIC: NR_CPUS/possible_cpus limit of 8 reached. Processor 55/0x1f ignored.
[    1.132228] ACPI: Unable to map lapic to logical cpu number

Those warnings are printed for every not-enabled CPU and on the systems
with large number of such CPUs, we see a lot of those prints for default
print level.

Simple conversion of those prints to be in debug level removes them
while leaving the option to debug system.

Signed-off-by: Leon Romanovsky <leonro@mellanox.com>
---
 arch/x86/kernel/acpi/boot.c | 2 +-
 arch/x86/kernel/apic/apic.c | 6 +++---
 2 files changed, 4 insertions(+), 4 deletions(-)

diff --git a/arch/x86/kernel/acpi/boot.c b/arch/x86/kernel/acpi/boot.c
index 8dcbf6890714..3ef8ab89c02d 100644
--- a/arch/x86/kernel/acpi/boot.c
+++ b/arch/x86/kernel/acpi/boot.c
@@ -770,7 +770,7 @@ int acpi_map_cpu(acpi_handle handle, phys_cpuid_t physid, u32 acpi_id,

 	cpu = acpi_register_lapic(physid, acpi_id, ACPI_MADT_ENABLED);
 	if (cpu < 0) {
-		pr_info(PREFIX "Unable to map lapic to logical cpu number\n");
+		pr_debug(PREFIX "Unable to map lapic to logical cpu number\n");
 		return cpu;
 	}

diff --git a/arch/x86/kernel/apic/apic.c b/arch/x86/kernel/apic/apic.c
index b7bcdd781651..8c2a487b5216 100644
--- a/arch/x86/kernel/apic/apic.c
+++ b/arch/x86/kernel/apic/apic.c
@@ -2305,9 +2305,9 @@ int generic_processor_info(int apicid, int version)
 	if (num_processors >= nr_cpu_ids) {
 		int thiscpu = max + disabled_cpus;

-		pr_warning("APIC: NR_CPUS/possible_cpus limit of %i "
-			   "reached. Processor %d/0x%x ignored.\n",
-			   max, thiscpu, apicid);
+		pr_debug(
+			"APIC: NR_CPUS/possible_cpus limit of %i reached. Processor %d/0x%x ignored.\n",
+			max, thiscpu, apicid);

 		disabled_cpus++;
 		return -EINVAL;
--
2.20.1

Re: [PATCH -next] x86/apic: Reduce print level of CPU limit announcement

[Rafael J. Wysocki]

On Tue, Mar 26, 2019 at 1:02 PM Leon Romanovsky <leon@kernel.org> wrote:
>
> From: Leon Romanovsky <leonro@mellanox.com>
>
> Kernel is booted with less possible CPUs (possible_cpus kernel boot
> option) than available CPUs will have prints like this:
>
> [    1.131039] APIC: NR_CPUS/possible_cpus limit of 8 reached. Processor 55/0x1f ignored.
> [    1.132228] ACPI: Unable to map lapic to logical cpu number
>
> Those warnings are printed for every not-enabled CPU and on the systems
> with large number of such CPUs, we see a lot of those prints for default
> print level.
>
> Simple conversion of those prints to be in debug level removes them
> while leaving the option to debug system.

But generally dynamic debug must be enabled in order for pr_debug()
prints to be visible which is kind of cumbersome to do via the command
line.

> Signed-off-by: Leon Romanovsky <leonro@mellanox.com>
> ---
>  arch/x86/kernel/acpi/boot.c | 2 +-
>  arch/x86/kernel/apic/apic.c | 6 +++---
>  2 files changed, 4 insertions(+), 4 deletions(-)
>
> diff --git a/arch/x86/kernel/acpi/boot.c b/arch/x86/kernel/acpi/boot.c
> index 8dcbf6890714..3ef8ab89c02d 100644
> --- a/arch/x86/kernel/acpi/boot.c
> +++ b/arch/x86/kernel/acpi/boot.c
> @@ -770,7 +770,7 @@ int acpi_map_cpu(acpi_handle handle, phys_cpuid_t physid, u32 acpi_id,
>
>         cpu = acpi_register_lapic(physid, acpi_id, ACPI_MADT_ENABLED);
>         if (cpu < 0) {
> -               pr_info(PREFIX "Unable to map lapic to logical cpu number\n");
> +               pr_debug(PREFIX "Unable to map lapic to logical cpu number\n");

And this one is printed sometimes when something really goes wrong
which may be really hard to debug otherwise, so there is value in the
info level here.

Would it be possible to avoid printing it just in some cases?

>                 return cpu;
>         }
>
> diff --git a/arch/x86/kernel/apic/apic.c b/arch/x86/kernel/apic/apic.c
> index b7bcdd781651..8c2a487b5216 100644
> --- a/arch/x86/kernel/apic/apic.c
> +++ b/arch/x86/kernel/apic/apic.c
> @@ -2305,9 +2305,9 @@ int generic_processor_info(int apicid, int version)
>         if (num_processors >= nr_cpu_ids) {
>                 int thiscpu = max + disabled_cpus;
>
> -               pr_warning("APIC: NR_CPUS/possible_cpus limit of %i "
> -                          "reached. Processor %d/0x%x ignored.\n",
> -                          max, thiscpu, apicid);
> +               pr_debug(
> +                       "APIC: NR_CPUS/possible_cpus limit of %i reached. Processor %d/0x%x ignored.\n",
> +                       max, thiscpu, apicid);

I completely agree with this change, though.

>
>                 disabled_cpus++;
>                 return -EINVAL;
> --

Re: [PATCH -next] x86/apic: Reduce print level of CPU limit announcement

[Leon Romanovsky]

[-- Attachment #1: Type: text/plain, Size: 4133 bytes --]

On Tue, Mar 26, 2019 at 01:29:54PM +0100, Rafael J. Wysocki wrote:
> On Tue, Mar 26, 2019 at 1:02 PM Leon Romanovsky <leon@kernel.org> wrote:
> >
> > From: Leon Romanovsky <leonro@mellanox.com>
> >
> > Kernel is booted with less possible CPUs (possible_cpus kernel boot
> > option) than available CPUs will have prints like this:
> >
> > [    1.131039] APIC: NR_CPUS/possible_cpus limit of 8 reached. Processor 55/0x1f ignored.
> > [    1.132228] ACPI: Unable to map lapic to logical cpu number
> >
> > Those warnings are printed for every not-enabled CPU and on the systems
> > with large number of such CPUs, we see a lot of those prints for default
> > print level.
> >
> > Simple conversion of those prints to be in debug level removes them
> > while leaving the option to debug system.
>
> But generally dynamic debug must be enabled in order for pr_debug()
> prints to be visible which is kind of cumbersome to do via the command
> line.

It is doable and documented pretty well, which is uncommon :)
https://www.kernel.org/doc/html/latest/admin-guide/dynamic-debug-howto.html#debug-messages-during-boot-process

>
> > Signed-off-by: Leon Romanovsky <leonro@mellanox.com>
> > ---
> >  arch/x86/kernel/acpi/boot.c | 2 +-
> >  arch/x86/kernel/apic/apic.c | 6 +++---
> >  2 files changed, 4 insertions(+), 4 deletions(-)
> >
> > diff --git a/arch/x86/kernel/acpi/boot.c b/arch/x86/kernel/acpi/boot.c
> > index 8dcbf6890714..3ef8ab89c02d 100644
> > --- a/arch/x86/kernel/acpi/boot.c
> > +++ b/arch/x86/kernel/acpi/boot.c
> > @@ -770,7 +770,7 @@ int acpi_map_cpu(acpi_handle handle, phys_cpuid_t physid, u32 acpi_id,
> >
> >         cpu = acpi_register_lapic(physid, acpi_id, ACPI_MADT_ENABLED);
> >         if (cpu < 0) {
> > -               pr_info(PREFIX "Unable to map lapic to logical cpu number\n");
> > +               pr_debug(PREFIX "Unable to map lapic to logical cpu number\n");
>
> And this one is printed sometimes when something really goes wrong
> which may be really hard to debug otherwise, so there is value in the
> info level here.
>
> Would it be possible to avoid printing it just in some cases?

This can do the trick:

diff --git a/arch/x86/kernel/acpi/boot.c b/arch/x86/kernel/acpi/boot.c
index 3ef8ab89c02d..00212b3991e0 100644
--- a/arch/x86/kernel/acpi/boot.c
+++ b/arch/x86/kernel/acpi/boot.c
@@ -770,7 +770,10 @@ int acpi_map_cpu(acpi_handle handle, phys_cpuid_t physid, u32 acpi_id,

 	cpu = acpi_register_lapic(physid, acpi_id, ACPI_MADT_ENABLED);
 	if (cpu < 0) {
-		pr_debug(PREFIX "Unable to map lapic to logical cpu number\n");
+		if (cpu == -ENOENT)
+			pr_debug(PREFIX "Unable to map lapic to logical cpu number\n");
+		else
+			pr_info(PREFIX "Unable to map lapic to logical cpu number\n");
 		return cpu;
 	}

diff --git a/arch/x86/kernel/apic/apic.c b/arch/x86/kernel/apic/apic.c
index 8c2a487b5216..2704a2c57df1 100644
--- a/arch/x86/kernel/apic/apic.c
+++ b/arch/x86/kernel/apic/apic.c
@@ -2299,7 +2299,7 @@ int generic_processor_info(int apicid, int version)
 			"  Processor %d/0x%x ignored.\n", max, thiscpu, apicid);

 		disabled_cpus++;
-		return -ENODEV;
+		return -ENOENT;
 	}

 	if (num_processors >= nr_cpu_ids) {>

> >                 return cpu;
> >         }
> >
> > diff --git a/arch/x86/kernel/apic/apic.c b/arch/x86/kernel/apic/apic.c
> > index b7bcdd781651..8c2a487b5216 100644
> > --- a/arch/x86/kernel/apic/apic.c
> > +++ b/arch/x86/kernel/apic/apic.c
> > @@ -2305,9 +2305,9 @@ int generic_processor_info(int apicid, int version)
> >         if (num_processors >= nr_cpu_ids) {
> >                 int thiscpu = max + disabled_cpus;
> >
> > -               pr_warning("APIC: NR_CPUS/possible_cpus limit of %i "
> > -                          "reached. Processor %d/0x%x ignored.\n",
> > -                          max, thiscpu, apicid);
> > +               pr_debug(
> > +                       "APIC: NR_CPUS/possible_cpus limit of %i reached. Processor %d/0x%x ignored.\n",
> > +                       max, thiscpu, apicid);
>
> I completely agree with this change, though.

Thanks

>
> >
> >                 disabled_cpus++;
> >                 return -EINVAL;
> > --

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 801 bytes --]

Re: [PATCH -next] x86/apic: Reduce print level of CPU limit announcement

[Rafael J. Wysocki]

On Tue, Mar 26, 2019 at 3:41 PM Leon Romanovsky <leon@kernel.org> wrote:
>
> On Tue, Mar 26, 2019 at 01:29:54PM +0100, Rafael J. Wysocki wrote:
> > On Tue, Mar 26, 2019 at 1:02 PM Leon Romanovsky <leon@kernel.org> wrote:
> > >
> > > From: Leon Romanovsky <leonro@mellanox.com>
> > >
> > > Kernel is booted with less possible CPUs (possible_cpus kernel boot
> > > option) than available CPUs will have prints like this:
> > >
> > > [    1.131039] APIC: NR_CPUS/possible_cpus limit of 8 reached. Processor 55/0x1f ignored.
> > > [    1.132228] ACPI: Unable to map lapic to logical cpu number
> > >
> > > Those warnings are printed for every not-enabled CPU and on the systems
> > > with large number of such CPUs, we see a lot of those prints for default
> > > print level.
> > >
> > > Simple conversion of those prints to be in debug level removes them
> > > while leaving the option to debug system.
> >
> > But generally dynamic debug must be enabled in order for pr_debug()
> > prints to be visible which is kind of cumbersome to do via the command
> > line.
>
> It is doable and documented pretty well, which is uncommon :)
> https://www.kernel.org/doc/html/latest/admin-guide/dynamic-debug-howto.html#debug-messages-during-boot-process

I know.

That's what I mean by "kind of cumbersome", because you need to know
which debug messages to enable upfront.

> >
> > > Signed-off-by: Leon Romanovsky <leonro@mellanox.com>
> > > ---
> > >  arch/x86/kernel/acpi/boot.c | 2 +-
> > >  arch/x86/kernel/apic/apic.c | 6 +++---
> > >  2 files changed, 4 insertions(+), 4 deletions(-)
> > >
> > > diff --git a/arch/x86/kernel/acpi/boot.c b/arch/x86/kernel/acpi/boot.c
> > > index 8dcbf6890714..3ef8ab89c02d 100644
> > > --- a/arch/x86/kernel/acpi/boot.c
> > > +++ b/arch/x86/kernel/acpi/boot.c
> > > @@ -770,7 +770,7 @@ int acpi_map_cpu(acpi_handle handle, phys_cpuid_t physid, u32 acpi_id,
> > >
> > >         cpu = acpi_register_lapic(physid, acpi_id, ACPI_MADT_ENABLED);
> > >         if (cpu < 0) {
> > > -               pr_info(PREFIX "Unable to map lapic to logical cpu number\n");
> > > +               pr_debug(PREFIX "Unable to map lapic to logical cpu number\n");
> >
> > And this one is printed sometimes when something really goes wrong
> > which may be really hard to debug otherwise, so there is value in the
> > info level here.
> >
> > Would it be possible to avoid printing it just in some cases?
>
> This can do the trick:
>
> diff --git a/arch/x86/kernel/acpi/boot.c b/arch/x86/kernel/acpi/boot.c
> index 3ef8ab89c02d..00212b3991e0 100644
> --- a/arch/x86/kernel/acpi/boot.c
> +++ b/arch/x86/kernel/acpi/boot.c
> @@ -770,7 +770,10 @@ int acpi_map_cpu(acpi_handle handle, phys_cpuid_t physid, u32 acpi_id,
>
>         cpu = acpi_register_lapic(physid, acpi_id, ACPI_MADT_ENABLED);
>         if (cpu < 0) {
> -               pr_debug(PREFIX "Unable to map lapic to logical cpu number\n");
> +               if (cpu == -ENOENT)
> +                       pr_debug(PREFIX "Unable to map lapic to logical cpu number\n");

I don't think it is necessary to print this in the -ENOENT case, as
there is a message for that case that will be printed anyway.

> +               else
> +                       pr_info(PREFIX "Unable to map lapic to logical cpu number\n");
>                 return cpu;
>         }
>

Re: [PATCH -next] x86/apic: Reduce print level of CPU limit announcement

[Leon Romanovsky]

[-- Attachment #1: Type: text/plain, Size: 3435 bytes --]

On Tue, Mar 26, 2019 at 04:12:27PM +0100, Rafael J. Wysocki wrote:
> On Tue, Mar 26, 2019 at 3:41 PM Leon Romanovsky <leon@kernel.org> wrote:
> >
> > On Tue, Mar 26, 2019 at 01:29:54PM +0100, Rafael J. Wysocki wrote:
> > > On Tue, Mar 26, 2019 at 1:02 PM Leon Romanovsky <leon@kernel.org> wrote:
> > > >
> > > > From: Leon Romanovsky <leonro@mellanox.com>
> > > >
> > > > Kernel is booted with less possible CPUs (possible_cpus kernel boot
> > > > option) than available CPUs will have prints like this:
> > > >
> > > > [    1.131039] APIC: NR_CPUS/possible_cpus limit of 8 reached. Processor 55/0x1f ignored.
> > > > [    1.132228] ACPI: Unable to map lapic to logical cpu number
> > > >
> > > > Those warnings are printed for every not-enabled CPU and on the systems
> > > > with large number of such CPUs, we see a lot of those prints for default
> > > > print level.
> > > >
> > > > Simple conversion of those prints to be in debug level removes them
> > > > while leaving the option to debug system.
> > >
> > > But generally dynamic debug must be enabled in order for pr_debug()
> > > prints to be visible which is kind of cumbersome to do via the command
> > > line.
> >
> > It is doable and documented pretty well, which is uncommon :)
> > https://www.kernel.org/doc/html/latest/admin-guide/dynamic-debug-howto.html#debug-messages-during-boot-process
>
> I know.
>
> That's what I mean by "kind of cumbersome", because you need to know
> which debug messages to enable upfront.
>
> > >
> > > > Signed-off-by: Leon Romanovsky <leonro@mellanox.com>
> > > > ---
> > > >  arch/x86/kernel/acpi/boot.c | 2 +-
> > > >  arch/x86/kernel/apic/apic.c | 6 +++---
> > > >  2 files changed, 4 insertions(+), 4 deletions(-)
> > > >
> > > > diff --git a/arch/x86/kernel/acpi/boot.c b/arch/x86/kernel/acpi/boot.c
> > > > index 8dcbf6890714..3ef8ab89c02d 100644
> > > > --- a/arch/x86/kernel/acpi/boot.c
> > > > +++ b/arch/x86/kernel/acpi/boot.c
> > > > @@ -770,7 +770,7 @@ int acpi_map_cpu(acpi_handle handle, phys_cpuid_t physid, u32 acpi_id,
> > > >
> > > >         cpu = acpi_register_lapic(physid, acpi_id, ACPI_MADT_ENABLED);
> > > >         if (cpu < 0) {
> > > > -               pr_info(PREFIX "Unable to map lapic to logical cpu number\n");
> > > > +               pr_debug(PREFIX "Unable to map lapic to logical cpu number\n");
> > >
> > > And this one is printed sometimes when something really goes wrong
> > > which may be really hard to debug otherwise, so there is value in the
> > > info level here.
> > >
> > > Would it be possible to avoid printing it just in some cases?
> >
> > This can do the trick:
> >
> > diff --git a/arch/x86/kernel/acpi/boot.c b/arch/x86/kernel/acpi/boot.c
> > index 3ef8ab89c02d..00212b3991e0 100644
> > --- a/arch/x86/kernel/acpi/boot.c
> > +++ b/arch/x86/kernel/acpi/boot.c
> > @@ -770,7 +770,10 @@ int acpi_map_cpu(acpi_handle handle, phys_cpuid_t physid, u32 acpi_id,
> >
> >         cpu = acpi_register_lapic(physid, acpi_id, ACPI_MADT_ENABLED);
> >         if (cpu < 0) {
> > -               pr_debug(PREFIX "Unable to map lapic to logical cpu number\n");
> > +               if (cpu == -ENOENT)
> > +                       pr_debug(PREFIX "Unable to map lapic to logical cpu number\n");
>
> I don't think it is necessary to print this in the -ENOENT case, as
> there is a message for that case that will be printed anyway.

Agree, how do you want me to progress? Should I resend patch?

Thanks

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 801 bytes --]

Re: [PATCH -next] x86/apic: Reduce print level of CPU limit announcement

[Rafael J. Wysocki]

On Tue, Mar 26, 2019 at 4:32 PM Leon Romanovsky <leon@kernel.org> wrote:
>
> On Tue, Mar 26, 2019 at 04:12:27PM +0100, Rafael J. Wysocki wrote:
> > On Tue, Mar 26, 2019 at 3:41 PM Leon Romanovsky <leon@kernel.org> wrote:
> > >
> > > On Tue, Mar 26, 2019 at 01:29:54PM +0100, Rafael J. Wysocki wrote:
> > > > On Tue, Mar 26, 2019 at 1:02 PM Leon Romanovsky <leon@kernel.org> wrote:
> > > > >
> > > > > From: Leon Romanovsky <leonro@mellanox.com>
> > > > >
> > > > > Kernel is booted with less possible CPUs (possible_cpus kernel boot
> > > > > option) than available CPUs will have prints like this:
> > > > >
> > > > > [    1.131039] APIC: NR_CPUS/possible_cpus limit of 8 reached. Processor 55/0x1f ignored.
> > > > > [    1.132228] ACPI: Unable to map lapic to logical cpu number
> > > > >
> > > > > Those warnings are printed for every not-enabled CPU and on the systems
> > > > > with large number of such CPUs, we see a lot of those prints for default
> > > > > print level.
> > > > >
> > > > > Simple conversion of those prints to be in debug level removes them
> > > > > while leaving the option to debug system.
> > > >
> > > > But generally dynamic debug must be enabled in order for pr_debug()
> > > > prints to be visible which is kind of cumbersome to do via the command
> > > > line.
> > >
> > > It is doable and documented pretty well, which is uncommon :)
> > > https://www.kernel.org/doc/html/latest/admin-guide/dynamic-debug-howto.html#debug-messages-during-boot-process
> >
> > I know.
> >
> > That's what I mean by "kind of cumbersome", because you need to know
> > which debug messages to enable upfront.
> >
> > > >
> > > > > Signed-off-by: Leon Romanovsky <leonro@mellanox.com>
> > > > > ---
> > > > >  arch/x86/kernel/acpi/boot.c | 2 +-
> > > > >  arch/x86/kernel/apic/apic.c | 6 +++---
> > > > >  2 files changed, 4 insertions(+), 4 deletions(-)
> > > > >
> > > > > diff --git a/arch/x86/kernel/acpi/boot.c b/arch/x86/kernel/acpi/boot.c
> > > > > index 8dcbf6890714..3ef8ab89c02d 100644
> > > > > --- a/arch/x86/kernel/acpi/boot.c
> > > > > +++ b/arch/x86/kernel/acpi/boot.c
> > > > > @@ -770,7 +770,7 @@ int acpi_map_cpu(acpi_handle handle, phys_cpuid_t physid, u32 acpi_id,
> > > > >
> > > > >         cpu = acpi_register_lapic(physid, acpi_id, ACPI_MADT_ENABLED);
> > > > >         if (cpu < 0) {
> > > > > -               pr_info(PREFIX "Unable to map lapic to logical cpu number\n");
> > > > > +               pr_debug(PREFIX "Unable to map lapic to logical cpu number\n");
> > > >
> > > > And this one is printed sometimes when something really goes wrong
> > > > which may be really hard to debug otherwise, so there is value in the
> > > > info level here.
> > > >
> > > > Would it be possible to avoid printing it just in some cases?
> > >
> > > This can do the trick:
> > >
> > > diff --git a/arch/x86/kernel/acpi/boot.c b/arch/x86/kernel/acpi/boot.c
> > > index 3ef8ab89c02d..00212b3991e0 100644
> > > --- a/arch/x86/kernel/acpi/boot.c
> > > +++ b/arch/x86/kernel/acpi/boot.c
> > > @@ -770,7 +770,10 @@ int acpi_map_cpu(acpi_handle handle, phys_cpuid_t physid, u32 acpi_id,
> > >
> > >         cpu = acpi_register_lapic(physid, acpi_id, ACPI_MADT_ENABLED);
> > >         if (cpu < 0) {
> > > -               pr_debug(PREFIX "Unable to map lapic to logical cpu number\n");
> > > +               if (cpu == -ENOENT)
> > > +                       pr_debug(PREFIX "Unable to map lapic to logical cpu number\n");
> >
> > I don't think it is necessary to print this in the -ENOENT case, as
> > there is a message for that case that will be printed anyway.
>
> Agree, how do you want me to progress? Should I resend patch?

Yes, please.

Re: [PATCH -next] x86/apic: Reduce print level of CPU limit announcement

[Leon Romanovsky]

[-- Attachment #1: Type: text/plain, Size: 4180 bytes --]

On Tue, Mar 26, 2019 at 05:30:22PM +0100, Rafael J. Wysocki wrote:
> On Tue, Mar 26, 2019 at 4:32 PM Leon Romanovsky <leon@kernel.org> wrote:
> >
> > On Tue, Mar 26, 2019 at 04:12:27PM +0100, Rafael J. Wysocki wrote:
> > > On Tue, Mar 26, 2019 at 3:41 PM Leon Romanovsky <leon@kernel.org> wrote:
> > > >
> > > > On Tue, Mar 26, 2019 at 01:29:54PM +0100, Rafael J. Wysocki wrote:
> > > > > On Tue, Mar 26, 2019 at 1:02 PM Leon Romanovsky <leon@kernel.org> wrote:
> > > > > >
> > > > > > From: Leon Romanovsky <leonro@mellanox.com>
> > > > > >
> > > > > > Kernel is booted with less possible CPUs (possible_cpus kernel boot
> > > > > > option) than available CPUs will have prints like this:
> > > > > >
> > > > > > [    1.131039] APIC: NR_CPUS/possible_cpus limit of 8 reached. Processor 55/0x1f ignored.
> > > > > > [    1.132228] ACPI: Unable to map lapic to logical cpu number
> > > > > >
> > > > > > Those warnings are printed for every not-enabled CPU and on the systems
> > > > > > with large number of such CPUs, we see a lot of those prints for default
> > > > > > print level.
> > > > > >
> > > > > > Simple conversion of those prints to be in debug level removes them
> > > > > > while leaving the option to debug system.
> > > > >
> > > > > But generally dynamic debug must be enabled in order for pr_debug()
> > > > > prints to be visible which is kind of cumbersome to do via the command
> > > > > line.
> > > >
> > > > It is doable and documented pretty well, which is uncommon :)
> > > > https://www.kernel.org/doc/html/latest/admin-guide/dynamic-debug-howto.html#debug-messages-during-boot-process
> > >
> > > I know.
> > >
> > > That's what I mean by "kind of cumbersome", because you need to know
> > > which debug messages to enable upfront.
> > >
> > > > >
> > > > > > Signed-off-by: Leon Romanovsky <leonro@mellanox.com>
> > > > > > ---
> > > > > >  arch/x86/kernel/acpi/boot.c | 2 +-
> > > > > >  arch/x86/kernel/apic/apic.c | 6 +++---
> > > > > >  2 files changed, 4 insertions(+), 4 deletions(-)
> > > > > >
> > > > > > diff --git a/arch/x86/kernel/acpi/boot.c b/arch/x86/kernel/acpi/boot.c
> > > > > > index 8dcbf6890714..3ef8ab89c02d 100644
> > > > > > --- a/arch/x86/kernel/acpi/boot.c
> > > > > > +++ b/arch/x86/kernel/acpi/boot.c
> > > > > > @@ -770,7 +770,7 @@ int acpi_map_cpu(acpi_handle handle, phys_cpuid_t physid, u32 acpi_id,
> > > > > >
> > > > > >         cpu = acpi_register_lapic(physid, acpi_id, ACPI_MADT_ENABLED);
> > > > > >         if (cpu < 0) {
> > > > > > -               pr_info(PREFIX "Unable to map lapic to logical cpu number\n");
> > > > > > +               pr_debug(PREFIX "Unable to map lapic to logical cpu number\n");
> > > > >
> > > > > And this one is printed sometimes when something really goes wrong
> > > > > which may be really hard to debug otherwise, so there is value in the
> > > > > info level here.
> > > > >
> > > > > Would it be possible to avoid printing it just in some cases?
> > > >
> > > > This can do the trick:
> > > >
> > > > diff --git a/arch/x86/kernel/acpi/boot.c b/arch/x86/kernel/acpi/boot.c
> > > > index 3ef8ab89c02d..00212b3991e0 100644
> > > > --- a/arch/x86/kernel/acpi/boot.c
> > > > +++ b/arch/x86/kernel/acpi/boot.c
> > > > @@ -770,7 +770,10 @@ int acpi_map_cpu(acpi_handle handle, phys_cpuid_t physid, u32 acpi_id,
> > > >
> > > >         cpu = acpi_register_lapic(physid, acpi_id, ACPI_MADT_ENABLED);
> > > >         if (cpu < 0) {
> > > > -               pr_debug(PREFIX "Unable to map lapic to logical cpu number\n");
> > > > +               if (cpu == -ENOENT)
> > > > +                       pr_debug(PREFIX "Unable to map lapic to logical cpu number\n");
> > >
> > > I don't think it is necessary to print this in the -ENOENT case, as
> > > there is a message for that case that will be printed anyway.
> >
> > Agree, how do you want me to progress? Should I resend patch?
>
> Yes, please.

I looked in the code and seems like there is one place only in acpi_register_lapic() which returns
EINVAL without any debug prints and that flow can't be because we are providing ACPI_MADT_ENABLED
as an input.

It looks like that we can safely remove the print from acpi_map_cpu().

Thanks

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 801 bytes --]

Re: [PATCH -next] x86/apic: Reduce print level of CPU limit announcement

[Rafael J. Wysocki]

On Tue, Mar 26, 2019 at 6:53 PM Leon Romanovsky <leon@kernel.org> wrote:
>
> On Tue, Mar 26, 2019 at 05:30:22PM +0100, Rafael J. Wysocki wrote:
> > On Tue, Mar 26, 2019 at 4:32 PM Leon Romanovsky <leon@kernel.org> wrote:
> > >
> > > On Tue, Mar 26, 2019 at 04:12:27PM +0100, Rafael J. Wysocki wrote:
> > > > On Tue, Mar 26, 2019 at 3:41 PM Leon Romanovsky <leon@kernel.org> wrote:
> > > > >
> > > > > On Tue, Mar 26, 2019 at 01:29:54PM +0100, Rafael J. Wysocki wrote:
> > > > > > On Tue, Mar 26, 2019 at 1:02 PM Leon Romanovsky <leon@kernel.org> wrote:
> > > > > > >
> > > > > > > From: Leon Romanovsky <leonro@mellanox.com>
> > > > > > >
> > > > > > > Kernel is booted with less possible CPUs (possible_cpus kernel boot
> > > > > > > option) than available CPUs will have prints like this:
> > > > > > >
> > > > > > > [    1.131039] APIC: NR_CPUS/possible_cpus limit of 8 reached. Processor 55/0x1f ignored.
> > > > > > > [    1.132228] ACPI: Unable to map lapic to logical cpu number
> > > > > > >
> > > > > > > Those warnings are printed for every not-enabled CPU and on the systems
> > > > > > > with large number of such CPUs, we see a lot of those prints for default
> > > > > > > print level.
> > > > > > >
> > > > > > > Simple conversion of those prints to be in debug level removes them
> > > > > > > while leaving the option to debug system.
> > > > > >
> > > > > > But generally dynamic debug must be enabled in order for pr_debug()
> > > > > > prints to be visible which is kind of cumbersome to do via the command
> > > > > > line.
> > > > >
> > > > > It is doable and documented pretty well, which is uncommon :)
> > > > > https://www.kernel.org/doc/html/latest/admin-guide/dynamic-debug-howto.html#debug-messages-during-boot-process
> > > >
> > > > I know.
> > > >
> > > > That's what I mean by "kind of cumbersome", because you need to know
> > > > which debug messages to enable upfront.
> > > >
> > > > > >
> > > > > > > Signed-off-by: Leon Romanovsky <leonro@mellanox.com>
> > > > > > > ---
> > > > > > >  arch/x86/kernel/acpi/boot.c | 2 +-
> > > > > > >  arch/x86/kernel/apic/apic.c | 6 +++---
> > > > > > >  2 files changed, 4 insertions(+), 4 deletions(-)
> > > > > > >
> > > > > > > diff --git a/arch/x86/kernel/acpi/boot.c b/arch/x86/kernel/acpi/boot.c
> > > > > > > index 8dcbf6890714..3ef8ab89c02d 100644
> > > > > > > --- a/arch/x86/kernel/acpi/boot.c
> > > > > > > +++ b/arch/x86/kernel/acpi/boot.c
> > > > > > > @@ -770,7 +770,7 @@ int acpi_map_cpu(acpi_handle handle, phys_cpuid_t physid, u32 acpi_id,
> > > > > > >
> > > > > > >         cpu = acpi_register_lapic(physid, acpi_id, ACPI_MADT_ENABLED);
> > > > > > >         if (cpu < 0) {
> > > > > > > -               pr_info(PREFIX "Unable to map lapic to logical cpu number\n");
> > > > > > > +               pr_debug(PREFIX "Unable to map lapic to logical cpu number\n");
> > > > > >
> > > > > > And this one is printed sometimes when something really goes wrong
> > > > > > which may be really hard to debug otherwise, so there is value in the
> > > > > > info level here.
> > > > > >
> > > > > > Would it be possible to avoid printing it just in some cases?
> > > > >
> > > > > This can do the trick:
> > > > >
> > > > > diff --git a/arch/x86/kernel/acpi/boot.c b/arch/x86/kernel/acpi/boot.c
> > > > > index 3ef8ab89c02d..00212b3991e0 100644
> > > > > --- a/arch/x86/kernel/acpi/boot.c
> > > > > +++ b/arch/x86/kernel/acpi/boot.c
> > > > > @@ -770,7 +770,10 @@ int acpi_map_cpu(acpi_handle handle, phys_cpuid_t physid, u32 acpi_id,
> > > > >
> > > > >         cpu = acpi_register_lapic(physid, acpi_id, ACPI_MADT_ENABLED);
> > > > >         if (cpu < 0) {
> > > > > -               pr_debug(PREFIX "Unable to map lapic to logical cpu number\n");
> > > > > +               if (cpu == -ENOENT)
> > > > > +                       pr_debug(PREFIX "Unable to map lapic to logical cpu number\n");
> > > >
> > > > I don't think it is necessary to print this in the -ENOENT case, as
> > > > there is a message for that case that will be printed anyway.
> > >
> > > Agree, how do you want me to progress? Should I resend patch?
> >
> > Yes, please.
>
> I looked in the code and seems like there is one place only in acpi_register_lapic() which returns
> EINVAL without any debug prints and that flow can't be because we are providing ACPI_MADT_ENABLED
> as an input.
>
> It looks like that we can safely remove the print from acpi_map_cpu().

What about generic_processor_info()?  That may return -EINVAL too silently.

Re: [PATCH -next] x86/apic: Reduce print level of CPU limit announcement

[Leon Romanovsky]

[-- Attachment #1: Type: text/plain, Size: 4888 bytes --]

On Tue, Mar 26, 2019 at 07:08:07PM +0100, Rafael J. Wysocki wrote:
> On Tue, Mar 26, 2019 at 6:53 PM Leon Romanovsky <leon@kernel.org> wrote:
> >
> > On Tue, Mar 26, 2019 at 05:30:22PM +0100, Rafael J. Wysocki wrote:
> > > On Tue, Mar 26, 2019 at 4:32 PM Leon Romanovsky <leon@kernel.org> wrote:
> > > >
> > > > On Tue, Mar 26, 2019 at 04:12:27PM +0100, Rafael J. Wysocki wrote:
> > > > > On Tue, Mar 26, 2019 at 3:41 PM Leon Romanovsky <leon@kernel.org> wrote:
> > > > > >
> > > > > > On Tue, Mar 26, 2019 at 01:29:54PM +0100, Rafael J. Wysocki wrote:
> > > > > > > On Tue, Mar 26, 2019 at 1:02 PM Leon Romanovsky <leon@kernel.org> wrote:
> > > > > > > >
> > > > > > > > From: Leon Romanovsky <leonro@mellanox.com>
> > > > > > > >
> > > > > > > > Kernel is booted with less possible CPUs (possible_cpus kernel boot
> > > > > > > > option) than available CPUs will have prints like this:
> > > > > > > >
> > > > > > > > [    1.131039] APIC: NR_CPUS/possible_cpus limit of 8 reached. Processor 55/0x1f ignored.
> > > > > > > > [    1.132228] ACPI: Unable to map lapic to logical cpu number
> > > > > > > >
> > > > > > > > Those warnings are printed for every not-enabled CPU and on the systems
> > > > > > > > with large number of such CPUs, we see a lot of those prints for default
> > > > > > > > print level.
> > > > > > > >
> > > > > > > > Simple conversion of those prints to be in debug level removes them
> > > > > > > > while leaving the option to debug system.
> > > > > > >
> > > > > > > But generally dynamic debug must be enabled in order for pr_debug()
> > > > > > > prints to be visible which is kind of cumbersome to do via the command
> > > > > > > line.
> > > > > >
> > > > > > It is doable and documented pretty well, which is uncommon :)
> > > > > > https://www.kernel.org/doc/html/latest/admin-guide/dynamic-debug-howto.html#debug-messages-during-boot-process
> > > > >
> > > > > I know.
> > > > >
> > > > > That's what I mean by "kind of cumbersome", because you need to know
> > > > > which debug messages to enable upfront.
> > > > >
> > > > > > >
> > > > > > > > Signed-off-by: Leon Romanovsky <leonro@mellanox.com>
> > > > > > > > ---
> > > > > > > >  arch/x86/kernel/acpi/boot.c | 2 +-
> > > > > > > >  arch/x86/kernel/apic/apic.c | 6 +++---
> > > > > > > >  2 files changed, 4 insertions(+), 4 deletions(-)
> > > > > > > >
> > > > > > > > diff --git a/arch/x86/kernel/acpi/boot.c b/arch/x86/kernel/acpi/boot.c
> > > > > > > > index 8dcbf6890714..3ef8ab89c02d 100644
> > > > > > > > --- a/arch/x86/kernel/acpi/boot.c
> > > > > > > > +++ b/arch/x86/kernel/acpi/boot.c
> > > > > > > > @@ -770,7 +770,7 @@ int acpi_map_cpu(acpi_handle handle, phys_cpuid_t physid, u32 acpi_id,
> > > > > > > >
> > > > > > > >         cpu = acpi_register_lapic(physid, acpi_id, ACPI_MADT_ENABLED);
> > > > > > > >         if (cpu < 0) {
> > > > > > > > -               pr_info(PREFIX "Unable to map lapic to logical cpu number\n");
> > > > > > > > +               pr_debug(PREFIX "Unable to map lapic to logical cpu number\n");
> > > > > > >
> > > > > > > And this one is printed sometimes when something really goes wrong
> > > > > > > which may be really hard to debug otherwise, so there is value in the
> > > > > > > info level here.
> > > > > > >
> > > > > > > Would it be possible to avoid printing it just in some cases?
> > > > > >
> > > > > > This can do the trick:
> > > > > >
> > > > > > diff --git a/arch/x86/kernel/acpi/boot.c b/arch/x86/kernel/acpi/boot.c
> > > > > > index 3ef8ab89c02d..00212b3991e0 100644
> > > > > > --- a/arch/x86/kernel/acpi/boot.c
> > > > > > +++ b/arch/x86/kernel/acpi/boot.c
> > > > > > @@ -770,7 +770,10 @@ int acpi_map_cpu(acpi_handle handle, phys_cpuid_t physid, u32 acpi_id,
> > > > > >
> > > > > >         cpu = acpi_register_lapic(physid, acpi_id, ACPI_MADT_ENABLED);
> > > > > >         if (cpu < 0) {
> > > > > > -               pr_debug(PREFIX "Unable to map lapic to logical cpu number\n");
> > > > > > +               if (cpu == -ENOENT)
> > > > > > +                       pr_debug(PREFIX "Unable to map lapic to logical cpu number\n");
> > > > >
> > > > > I don't think it is necessary to print this in the -ENOENT case, as
> > > > > there is a message for that case that will be printed anyway.
> > > >
> > > > Agree, how do you want me to progress? Should I resend patch?
> > >
> > > Yes, please.
> >
> > I looked in the code and seems like there is one place only in acpi_register_lapic() which returns
> > EINVAL without any debug prints and that flow can't be because we are providing ACPI_MADT_ENABLED
> > as an input.
> >
> > It looks like that we can safely remove the print from acpi_map_cpu().
>
> What about generic_processor_info()?  That may return -EINVAL too silently.

It returns -EINVAL for failure in allocate_logical_cpuid() only and that
function prints WARN_ONCE inside in such case. You won't miss it.

Thanks

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 801 bytes --]

Re: [PATCH -next] x86/apic: Reduce print level of CPU limit announcement

[Rafael J. Wysocki]

On Tue, Mar 26, 2019 at 7:31 PM Leon Romanovsky <leon@kernel.org> wrote:
>
> On Tue, Mar 26, 2019 at 07:08:07PM +0100, Rafael J. Wysocki wrote:
> > On Tue, Mar 26, 2019 at 6:53 PM Leon Romanovsky <leon@kernel.org> wrote:
> > >
> > > On Tue, Mar 26, 2019 at 05:30:22PM +0100, Rafael J. Wysocki wrote:
> > > > On Tue, Mar 26, 2019 at 4:32 PM Leon Romanovsky <leon@kernel.org> wrote:
> > > > >
> > > > > On Tue, Mar 26, 2019 at 04:12:27PM +0100, Rafael J. Wysocki wrote:
> > > > > > On Tue, Mar 26, 2019 at 3:41 PM Leon Romanovsky <leon@kernel.org> wrote:
> > > > > > >
> > > > > > > On Tue, Mar 26, 2019 at 01:29:54PM +0100, Rafael J. Wysocki wrote:
> > > > > > > > On Tue, Mar 26, 2019 at 1:02 PM Leon Romanovsky <leon@kernel.org> wrote:
> > > > > > > > >
> > > > > > > > > From: Leon Romanovsky <leonro@mellanox.com>
> > > > > > > > >
> > > > > > > > > Kernel is booted with less possible CPUs (possible_cpus kernel boot
> > > > > > > > > option) than available CPUs will have prints like this:
> > > > > > > > >
> > > > > > > > > [    1.131039] APIC: NR_CPUS/possible_cpus limit of 8 reached. Processor 55/0x1f ignored.
> > > > > > > > > [    1.132228] ACPI: Unable to map lapic to logical cpu number
> > > > > > > > >
> > > > > > > > > Those warnings are printed for every not-enabled CPU and on the systems
> > > > > > > > > with large number of such CPUs, we see a lot of those prints for default
> > > > > > > > > print level.
> > > > > > > > >
> > > > > > > > > Simple conversion of those prints to be in debug level removes them
> > > > > > > > > while leaving the option to debug system.
> > > > > > > >
> > > > > > > > But generally dynamic debug must be enabled in order for pr_debug()
> > > > > > > > prints to be visible which is kind of cumbersome to do via the command
> > > > > > > > line.
> > > > > > >
> > > > > > > It is doable and documented pretty well, which is uncommon :)
> > > > > > > https://www.kernel.org/doc/html/latest/admin-guide/dynamic-debug-howto.html#debug-messages-during-boot-process
> > > > > >
> > > > > > I know.
> > > > > >
> > > > > > That's what I mean by "kind of cumbersome", because you need to know
> > > > > > which debug messages to enable upfront.
> > > > > >
> > > > > > > >
> > > > > > > > > Signed-off-by: Leon Romanovsky <leonro@mellanox.com>
> > > > > > > > > ---
> > > > > > > > >  arch/x86/kernel/acpi/boot.c | 2 +-
> > > > > > > > >  arch/x86/kernel/apic/apic.c | 6 +++---
> > > > > > > > >  2 files changed, 4 insertions(+), 4 deletions(-)
> > > > > > > > >
> > > > > > > > > diff --git a/arch/x86/kernel/acpi/boot.c b/arch/x86/kernel/acpi/boot.c
> > > > > > > > > index 8dcbf6890714..3ef8ab89c02d 100644
> > > > > > > > > --- a/arch/x86/kernel/acpi/boot.c
> > > > > > > > > +++ b/arch/x86/kernel/acpi/boot.c
> > > > > > > > > @@ -770,7 +770,7 @@ int acpi_map_cpu(acpi_handle handle, phys_cpuid_t physid, u32 acpi_id,
> > > > > > > > >
> > > > > > > > >         cpu = acpi_register_lapic(physid, acpi_id, ACPI_MADT_ENABLED);
> > > > > > > > >         if (cpu < 0) {
> > > > > > > > > -               pr_info(PREFIX "Unable to map lapic to logical cpu number\n");
> > > > > > > > > +               pr_debug(PREFIX "Unable to map lapic to logical cpu number\n");
> > > > > > > >
> > > > > > > > And this one is printed sometimes when something really goes wrong
> > > > > > > > which may be really hard to debug otherwise, so there is value in the
> > > > > > > > info level here.
> > > > > > > >
> > > > > > > > Would it be possible to avoid printing it just in some cases?
> > > > > > >
> > > > > > > This can do the trick:
> > > > > > >
> > > > > > > diff --git a/arch/x86/kernel/acpi/boot.c b/arch/x86/kernel/acpi/boot.c
> > > > > > > index 3ef8ab89c02d..00212b3991e0 100644
> > > > > > > --- a/arch/x86/kernel/acpi/boot.c
> > > > > > > +++ b/arch/x86/kernel/acpi/boot.c
> > > > > > > @@ -770,7 +770,10 @@ int acpi_map_cpu(acpi_handle handle, phys_cpuid_t physid, u32 acpi_id,
> > > > > > >
> > > > > > >         cpu = acpi_register_lapic(physid, acpi_id, ACPI_MADT_ENABLED);
> > > > > > >         if (cpu < 0) {
> > > > > > > -               pr_debug(PREFIX "Unable to map lapic to logical cpu number\n");
> > > > > > > +               if (cpu == -ENOENT)
> > > > > > > +                       pr_debug(PREFIX "Unable to map lapic to logical cpu number\n");
> > > > > >
> > > > > > I don't think it is necessary to print this in the -ENOENT case, as
> > > > > > there is a message for that case that will be printed anyway.
> > > > >
> > > > > Agree, how do you want me to progress? Should I resend patch?
> > > >
> > > > Yes, please.
> > >
> > > I looked in the code and seems like there is one place only in acpi_register_lapic() which returns
> > > EINVAL without any debug prints and that flow can't be because we are providing ACPI_MADT_ENABLED
> > > as an input.
> > >
> > > It looks like that we can safely remove the print from acpi_map_cpu().
> >
> > What about generic_processor_info()?  That may return -EINVAL too silently.
>
> It returns -EINVAL for failure in allocate_logical_cpuid() only and that
> function prints WARN_ONCE inside in such case. You won't miss it.

Fair enough.

So yes, the message printed in acpi_map_cpu() is redundant.