Dear Petr,
Thank you for the quick reply.
Am 16.02.21 um 10:49 schrieb Petr Mladek:
On Mon 2021-02-15 20:22:34, Paul Menzel wrote:
Using Linux 5.10.13 (and before), looking at the Linux kernel warnings, the
CPU numbers show up. For example with 12 cpus/threads:
```
$ sudo dmesg --level=warn
[ 0.216103] #2
[ 0.220105] #3
[ 0.224103] #4
[ 0.228104] #5
[ 0.232110] #6
[ 0.236101] #7
[ 0.240102] #8
[ 0.244102] #9
[ 0.248100] #10
[ 0.252098] #11
```
Is this the exact output from sudo dmesg --level=warn?
Yes, it is.
It is strange that each CPU number is printed on its own line.
Should it be put on one line, if `dmesg --level=warn` is executed, even
with other messages in between?
Anyway, it might be affected by the new lockless ringbuffer.
The original code decided whether to connect the lines only by
"current" task pointer. The lockless ring buffer takes into account
also CPU number.
Well, it has never been reliable. For example, I see here:
<6>[ 0.238262][ T1] smp: Bringing up secondary CPUs ...
<6>[ 0.239340][ T1] x86: Booting SMP configuration:
<6>[ 0.239794][ T1] .... node #0, CPUs: #1
<6>[ 0.113946][ T0] kvm-clock: cpu 1, msr 6ba01041, secondary cpu clock
<6>[ 0.113946][ T0] smpboot: CPU 1 Converting physical 0 to logical die 1
<6>[ 0.246056][ T16] kvm-guest: stealtime: cpu 1, msr 17f9f2080
<4>[ 0.246679][ T1] #2
<6>[ 0.113946][ T0] kvm-clock: cpu 2, msr 6ba01081, secondary cpu clock
<6>[ 0.113946][ T0] smpboot: CPU 2 Converting physical 0 to logical die 2
<6>[ 0.250023][ T21] kvm-guest: stealtime: cpu 2, msr 17fbf2080
<4>[ 0.250648][ T1] #3
<6>[ 0.113946][ T0] kvm-clock: cpu 3, msr 6ba010c1, secondary cpu clock
<6>[ 0.113946][ T0] smpboot: CPU 3 Converting physical 0 to logical die 3
<6>[ 0.254026][ T26] kvm-guest: stealtime: cpu 3, msr 17fdf2080
<6>[ 0.254568][ T1] smp: Brought up 1 node, 4 CPUs
<6>[ 0.254597][ T1] smpboot: Max logical packages: 4
<6>[ 0.255097][ T1] smpboot: Total of 4 processors activated (16896.11
BogoMIPS)
There are another messages printed in between that obviously break pr_cont().
Yes, that is what I meant.
If I am not mistaken, this is from `announce_cpu()` in
`arch/x86/kernel/smpboot.c`, and the `pr_cont()` in their “forgets” the log
level it belongs to, maybe because of SMP and other messages are printed in
between.
```
if (system_state < SYSTEM_RUNNING) {
if (node != current_node) {
if (current_node > (-1))
pr_cont("\n");
current_node = node;
printk(KERN_INFO ".... node %*s#%d, CPUs: ",
node_width - num_digits(node), " ", node);
}
/* Add padding for the BSP */
if (cpu == 1)
pr_cont("%*s", width + 1, " ");
pr_cont("%*s#%d", width - num_digits(cpu), " ", cpu);
} else
pr_info("Booting Node %d Processor %d APIC 0x%x\n",
node, cpu, apicid);
```
Would using `pr_info()` instead be an acceptable fix?
Makes sense to me.
Also you should add '\n' into the previous string to make the behavior
clear. It will always be printed on a new line when pr_info()
is used.
I am going to reply to Borislav’s response.
Kind regards,
Paul
