x86/apic: Reduce print level of CPU limit announcement

PATCH In review Leon Romanovsky 2 participants 10 messages Mar 26, 2019

Subsystems (2)

x86 ACPI

lore

Share & tools

lore

Rafael J. Wysocki

maintainer

2019-03-26 12:29 UTC #1 lore raw

Quoted 9 lines · Leon Romanovsky

From: Leon Romanovsky <[email protected]>
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

Quoted 6 lines

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.

Quoted 11 lines

Signed-off-by Leon Romanovsky <[email protected]>
---
 arch/x86/kernel/acpi/boot.c | 2 +-
 arch/x86/kernel/apic/apic.c | 6 +++---
 2 files changed, 4 insertions(+), 4 deletions(-)
arch/x86/kernel/acpi/boot.c +0 -0
index 8dcbf6890714..3ef8ab89c02d 100644

arch/x86/kernel/acpi/boot.c int acpi_map_cpu(acpi_handle handle, phys_cpuid_t physid, u32 acpi_id, · line 773

Quoted 5 lines

arch/x86/kernel/acpi/boot.c +1 -1

@@ -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?

Quoted 8 lines

arch/x86/kernel/acpi/boot.c +0 -0

                return cpu;
        }

arch/x86/kernel/apic/apic.c +0 -0

index b7bcdd781651..8c2a487b5216 100644

arch/x86/kernel/apic/apic.c int generic_processor_info(int apicid, int version) · line 2310

Quoted 9 lines

arch/x86/kernel/apic/apic.c +3 -3

@@ -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.

Quoted 4 lines

arch/x86/kernel/apic/apic.c +0 -1

                disabled_cpus++;
                return -EINVAL;
--

Leon Romanovsky

author

2019-03-26 14:41 UTC #2 lore raw

Quoted 14 lines · Rafael J. Wysocki

Quoted 13 lines · Leon Romanovsky
From: Leon Romanovsky <[email protected]>
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.

Quoted 6 lines

Quoted 2 lines
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

Quoted 22 lines

Quoted 12 lines
Signed-off-by Leon Romanovsky <[email protected]>
---
 arch/x86/kernel/acpi/boot.c | 2 +-
 arch/x86/kernel/apic/apic.c | 6 +++---
 2 files changed, 4 insertions(+), 4 deletions(-)
arch/x86/kernel/acpi/boot.c +0 -0
index 8dcbf6890714..3ef8ab89c02d 100644
arch/x86/kernel/acpi/boot.c int acpi_map_cpu(acpi_handle handle, phys_cpuid_t physid, u32 acpi_id, · line 773
Quoted 5 lines
arch/x86/kernel/acpi/boot.c +1 -1
@@ -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.

Quoted 1 line

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

This can do the trick:

arch/x86/kernel/acpi/boot.c +4 -1

index 3ef8ab89c02d..00212b3991e0 100644
@@ -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;
 	}

arch/x86/kernel/apic/apic.c +1 -1

index 8c2a487b5216..2704a2c57df1 100644
@@ -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) {>

Quoted 11 lines

arch/x86/kernel/acpi/boot.c +0 -0

                return cpu;
        }

arch/x86/kernel/apic/apic.c +0 -0

index b7bcdd781651..8c2a487b5216 100644
@@ -2305,9 +2305,9 @@ int generic_processor_info(int apicid, int version)
        if (num_processors >= nr_cpu_ids) {
                int thiscpu = max + disabled_cpus;

Quoted 8 lines

arch/x86/kernel/apic/apic.c int generic_processor_info(int apicid, int version) · line 2310

Quoted 6 lines

arch/x86/kernel/apic/apic.c +3 -3

-               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

Quoted 5 lines

arch/x86/kernel/apic/apic.c +0 -1

                disabled_cpus++;
                return -EINVAL;
--

Rafael J. Wysocki

maintainer

2019-03-26 15:12 UTC #3 lore raw

Quoted 19 lines · Leon Romanovsky

Quoted 17 lines · Rafael J. Wysocki
Quoted 15 lines · Leon Romanovsky
From: Leon Romanovsky <[email protected]>
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.

Quoted 6 lines

Quoted 3 lines
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.

Quoted 31 lines

Quoted 22 lines
Quoted 12 lines
Signed-off-by Leon Romanovsky <[email protected]>
---
 arch/x86/kernel/acpi/boot.c | 2 +-
 arch/x86/kernel/apic/apic.c | 6 +++---
 2 files changed, 4 insertions(+), 4 deletions(-)
arch/x86/kernel/acpi/boot.c +0 -0
index 8dcbf6890714..3ef8ab89c02d 100644
arch/x86/kernel/acpi/boot.c int acpi_map_cpu(acpi_handle handle, phys_cpuid_t physid, u32 acpi_id, · line 773
Quoted 5 lines
arch/x86/kernel/acpi/boot.c +1 -1
@@ -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.
Quoted 1 line
Would it be possible to avoid printing it just in some cases?
This can do the trick:
arch/x86/kernel/acpi/boot.c +0 -0
index 3ef8ab89c02d..00212b3991e0 100644

arch/x86/kernel/acpi/boot.c int acpi_map_cpu(acpi_handle handle, phys_cpuid_t physid, u32 acpi_id, · line 774

Quoted 6 lines

arch/x86/kernel/acpi/boot.c +2 -1

@@ -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.

Quoted 5 lines

arch/x86/kernel/acpi/boot.c +2 -0

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

Leon Romanovsky

author

2019-03-26 15:32 UTC #4 lore raw

Quoted 64 lines · Rafael J. Wysocki

Quoted 19 lines · Leon Romanovsky
Quoted 17 lines · Rafael J. Wysocki
Quoted 15 lines · Leon Romanovsky
From: Leon Romanovsky <[email protected]>
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.
Quoted 6 lines
Quoted 3 lines
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.
Quoted 32 lines
Quoted 22 lines
Quoted 12 lines
Signed-off-by Leon Romanovsky <[email protected]>
---
 arch/x86/kernel/acpi/boot.c | 2 +-
 arch/x86/kernel/apic/apic.c | 6 +++---
 2 files changed, 4 insertions(+), 4 deletions(-)
arch/x86/kernel/acpi/boot.c +0 -0
index 8dcbf6890714..3ef8ab89c02d 100644
arch/x86/kernel/acpi/boot.c int acpi_map_cpu(acpi_handle handle, phys_cpuid_t physid, u32 acpi_id, · line 773
Quoted 5 lines
arch/x86/kernel/acpi/boot.c +1 -1
@@ -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.
Quoted 1 line
Would it be possible to avoid printing it just in some cases?
This can do the trick:
arch/x86/kernel/acpi/boot.c +0 -0
index 3ef8ab89c02d..00212b3991e0 100644
@@ -770,7 +770,10 @@ int acpi_map_cpu(acpi_handle handle, phys_cpuid_t physid, u32 acpi_id,
 

Quoted 8 lines

arch/x86/kernel/acpi/boot.c int acpi_map_cpu(acpi_handle handle, phys_cpuid_t physid, u32 acpi_id, · line 774
Quoted 5 lines
arch/x86/kernel/acpi/boot.c +2 -1
        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

Rafael J. Wysocki

maintainer

2019-03-26 16:30 UTC #5 lore raw

Quoted 75 lines · Leon Romanovsky

Quoted 64 lines · Rafael J. Wysocki
Quoted 19 lines · Leon Romanovsky
Quoted 17 lines · Rafael J. Wysocki
Quoted 15 lines · Leon Romanovsky
From: Leon Romanovsky <[email protected]>
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.
Quoted 6 lines
Quoted 3 lines
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.
Quoted 32 lines
Quoted 22 lines
Quoted 12 lines
Signed-off-by Leon Romanovsky <[email protected]>
---
 arch/x86/kernel/acpi/boot.c | 2 +-
 arch/x86/kernel/apic/apic.c | 6 +++---
 2 files changed, 4 insertions(+), 4 deletions(-)
arch/x86/kernel/acpi/boot.c +0 -0
index 8dcbf6890714..3ef8ab89c02d 100644
arch/x86/kernel/acpi/boot.c int acpi_map_cpu(acpi_handle handle, phys_cpuid_t physid, u32 acpi_id, · line 773
Quoted 5 lines
arch/x86/kernel/acpi/boot.c +1 -1
@@ -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.
Quoted 1 line
Would it be possible to avoid printing it just in some cases?
This can do the trick:
arch/x86/kernel/acpi/boot.c +0 -0
index 3ef8ab89c02d..00212b3991e0 100644
@@ -770,7 +770,10 @@ int acpi_map_cpu(acpi_handle handle, phys_cpuid_t physid, u32 acpi_id,
 
Quoted 8 lines
arch/x86/kernel/acpi/boot.c int acpi_map_cpu(acpi_handle handle, phys_cpuid_t physid, u32 acpi_id, · line 774
Quoted 5 lines
arch/x86/kernel/acpi/boot.c +2 -1
        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.

Quoted 1 line

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

Yes, please.

Leon Romanovsky

author

2019-03-26 17:53 UTC #6 lore raw

Quoted 76 lines · Rafael J. Wysocki

Quoted 75 lines · Leon Romanovsky
Quoted 72 lines · Rafael J. Wysocki
Quoted 19 lines · Leon Romanovsky
Quoted 17 lines · Rafael J. Wysocki
Quoted 15 lines · Leon Romanovsky
From: Leon Romanovsky <[email protected]>
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.
Quoted 6 lines
Quoted 3 lines
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.
Quoted 31 lines
Quoted 22 lines
Quoted 12 lines
Signed-off-by Leon Romanovsky <[email protected]>
---
 arch/x86/kernel/acpi/boot.c | 2 +-
 arch/x86/kernel/apic/apic.c | 6 +++---
 2 files changed, 4 insertions(+), 4 deletions(-)
arch/x86/kernel/acpi/boot.c +0 -0
index 8dcbf6890714..3ef8ab89c02d 100644
arch/x86/kernel/acpi/boot.c int acpi_map_cpu(acpi_handle handle, phys_cpuid_t physid, u32 acpi_id, · line 773
Quoted 5 lines
arch/x86/kernel/acpi/boot.c +1 -1
@@ -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.
Quoted 1 line
Would it be possible to avoid printing it just in some cases?
This can do the trick:
arch/x86/kernel/acpi/boot.c +0 -0
index 3ef8ab89c02d..00212b3991e0 100644
arch/x86/kernel/acpi/boot.c int acpi_map_cpu(acpi_handle handle, phys_cpuid_t physid, u32 acpi_id, · line 774
Quoted 6 lines
arch/x86/kernel/acpi/boot.c +2 -1
@@ -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.

Quoted 3 lines

Quoted 1 line
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

Rafael J. Wysocki

maintainer

2019-03-26 18:08 UTC #7 lore raw

Quoted 80 lines · Leon Romanovsky

Quoted 78 lines · Rafael J. Wysocki
Quoted 76 lines · Leon Romanovsky
Quoted 64 lines · Rafael J. Wysocki
Quoted 19 lines · Leon Romanovsky
Quoted 17 lines · Rafael J. Wysocki
Quoted 15 lines · Leon Romanovsky
From: Leon Romanovsky <[email protected]>
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.
Quoted 6 lines
Quoted 3 lines
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.
Quoted 32 lines
Quoted 22 lines
Quoted 12 lines
Signed-off-by Leon Romanovsky <[email protected]>
---
 arch/x86/kernel/acpi/boot.c | 2 +-
 arch/x86/kernel/apic/apic.c | 6 +++---
 2 files changed, 4 insertions(+), 4 deletions(-)
arch/x86/kernel/acpi/boot.c +0 -0
index 8dcbf6890714..3ef8ab89c02d 100644
arch/x86/kernel/acpi/boot.c int acpi_map_cpu(acpi_handle handle, phys_cpuid_t physid, u32 acpi_id, · line 773
Quoted 5 lines
arch/x86/kernel/acpi/boot.c +1 -1
@@ -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.
Quoted 1 line
Would it be possible to avoid printing it just in some cases?
This can do the trick:
arch/x86/kernel/acpi/boot.c +0 -0
index 3ef8ab89c02d..00212b3991e0 100644
@@ -770,7 +770,10 @@ int acpi_map_cpu(acpi_handle handle, phys_cpuid_t physid, u32 acpi_id,
 
Quoted 8 lines
arch/x86/kernel/acpi/boot.c int acpi_map_cpu(acpi_handle handle, phys_cpuid_t physid, u32 acpi_id, · line 774
Quoted 5 lines
arch/x86/kernel/acpi/boot.c +2 -1
        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?

Quoted 7 lines

Quoted 1 line
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.

Leon Romanovsky

author

2019-03-26 18:31 UTC #8 lore raw

Quoted 83 lines · Rafael J. Wysocki

Quoted 82 lines · Leon Romanovsky
Quoted 79 lines · Rafael J. Wysocki
Quoted 75 lines · Leon Romanovsky
Quoted 64 lines · Rafael J. Wysocki
Quoted 19 lines · Leon Romanovsky
Quoted 17 lines · Rafael J. Wysocki
Quoted 15 lines · Leon Romanovsky
From: Leon Romanovsky <[email protected]>
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.
Quoted 6 lines
Quoted 3 lines
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.
Quoted 32 lines
Quoted 22 lines
Quoted 12 lines
Signed-off-by Leon Romanovsky <[email protected]>
---
 arch/x86/kernel/acpi/boot.c | 2 +-
 arch/x86/kernel/apic/apic.c | 6 +++---
 2 files changed, 4 insertions(+), 4 deletions(-)
arch/x86/kernel/acpi/boot.c +0 -0
index 8dcbf6890714..3ef8ab89c02d 100644
arch/x86/kernel/acpi/boot.c int acpi_map_cpu(acpi_handle handle, phys_cpuid_t physid, u32 acpi_id, · line 773
Quoted 5 lines
arch/x86/kernel/acpi/boot.c +1 -1
@@ -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.
Quoted 1 line
Would it be possible to avoid printing it just in some cases?
This can do the trick:
arch/x86/kernel/acpi/boot.c +0 -0
index 3ef8ab89c02d..00212b3991e0 100644
@@ -770,7 +770,10 @@ int acpi_map_cpu(acpi_handle handle, phys_cpuid_t physid, u32 acpi_id,
 
Quoted 8 lines
arch/x86/kernel/acpi/boot.c int acpi_map_cpu(acpi_handle handle, phys_cpuid_t physid, u32 acpi_id, · line 774
Quoted 5 lines
arch/x86/kernel/acpi/boot.c +2 -1
        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.
Quoted 1 line
Agree, how do you want me to progress? Should I resend patch?
Yes, please.

Quoted 7 lines

Quoted 5 lines
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

Rafael J. Wysocki

maintainer

2019-03-26 21:28 UTC #9 lore raw

Quoted 89 lines · Leon Romanovsky

Quoted 87 lines · Rafael J. Wysocki
Quoted 86 lines · Leon Romanovsky
Quoted 76 lines · Rafael J. Wysocki
Quoted 75 lines · Leon Romanovsky
Quoted 72 lines · Rafael J. Wysocki
Quoted 19 lines · Leon Romanovsky
Quoted 17 lines · Rafael J. Wysocki
Quoted 15 lines · Leon Romanovsky
From: Leon Romanovsky <[email protected]>
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.
Quoted 6 lines
Quoted 3 lines
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.
Quoted 31 lines
Quoted 22 lines
Quoted 12 lines
Signed-off-by Leon Romanovsky <[email protected]>
---
 arch/x86/kernel/acpi/boot.c | 2 +-
 arch/x86/kernel/apic/apic.c | 6 +++---
 2 files changed, 4 insertions(+), 4 deletions(-)
arch/x86/kernel/acpi/boot.c +0 -0
index 8dcbf6890714..3ef8ab89c02d 100644
arch/x86/kernel/acpi/boot.c int acpi_map_cpu(acpi_handle handle, phys_cpuid_t physid, u32 acpi_id, · line 773
Quoted 5 lines
arch/x86/kernel/acpi/boot.c +1 -1
@@ -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.
Quoted 1 line
Would it be possible to avoid printing it just in some cases?
This can do the trick:
arch/x86/kernel/acpi/boot.c +0 -0
index 3ef8ab89c02d..00212b3991e0 100644
arch/x86/kernel/acpi/boot.c int acpi_map_cpu(acpi_handle handle, phys_cpuid_t physid, u32 acpi_id, · line 774
Quoted 6 lines
arch/x86/kernel/acpi/boot.c +2 -1
@@ -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.
Quoted 3 lines
Quoted 1 line
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.

Quoted 6 lines

Quoted 3 lines
Quoted 1 line
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.