Discussion:
RFC: Hiding per-CPU kernel output behind bootverbose
Add Reply
Colin Percival
2018-04-19 18:06:21 UTC
Reply
Permalink
On large systems (e.g., EC2's x1e.32xlarge instance type, with 128 vCPUs)
the boot time console output contains a large number of lines of the forms

SMP: AP CPU #N Launched!
cpuN: <ACPI CPU> on acpi0
estN: <Enhanced SpeedStep Frequency Control> on cpuN

Having 128 almost-identical lines of output doesn't seem very useful, and
it actually has a nontrivial impact on the time spent booting.

Does anyone mind if I hide these by default, having them only show up if
boot verbosity is requested?
--
Colin Percival
Security Officer Emeritus, FreeBSD | The power to serve
Founder, Tarsnap | www.tarsnap.com | Online backups for the truly paranoid
Konstantin Belousov
2018-04-19 20:44:05 UTC
Reply
Permalink
Post by Colin Percival
On large systems (e.g., EC2's x1e.32xlarge instance type, with 128 vCPUs)
the boot time console output contains a large number of lines of the forms
SMP: AP CPU #N Launched!
cpuN: <ACPI CPU> on acpi0
estN: <Enhanced SpeedStep Frequency Control> on cpuN
Having 128 almost-identical lines of output doesn't seem very useful, and
it actually has a nontrivial impact on the time spent booting.
Does anyone mind if I hide these by default, having them only show up if
boot verbosity is requested?
The 'CPU XX Launched' messages are very useful for initial diagnostic
of the SMP startup failures. You need to enable bootverbose to see the
hang details, but for initial hint they are required. Unfortunately, AP
startup hangs occur too often to pretend that this can be delegated to
very specific circumstances.

Rest of the lines you pasted are normal device attach messages, so it is
not clear how would you hide them without ugly hacks.
Colin Percival
2018-04-19 20:59:34 UTC
Reply
Permalink
Post by Konstantin Belousov
Post by Colin Percival
On large systems (e.g., EC2's x1e.32xlarge instance type, with 128 vCPUs)
the boot time console output contains a large number of lines of the forms
SMP: AP CPU #N Launched!
cpuN: <ACPI CPU> on acpi0
estN: <Enhanced SpeedStep Frequency Control> on cpuN
Having 128 almost-identical lines of output doesn't seem very useful, and
it actually has a nontrivial impact on the time spent booting.
Does anyone mind if I hide these by default, having them only show up if
boot verbosity is requested?
The 'CPU XX Launched' messages are very useful for initial diagnostic
of the SMP startup failures. You need to enable bootverbose to see the
hang details, but for initial hint they are required. Unfortunately, AP
startup hangs occur too often to pretend that this can be delegated to
very specific circumstances.
Do SMP startup failures need to be debugged often enough to justify having
this verbosity every time a FreeBSD system boots?
Post by Konstantin Belousov
Rest of the lines you pasted are normal device attach messages, so it is
not clear how would you hide them without ugly hacks.
I would be willing to employ ugly hacks in order to silence unhelpful output
and speed up the boot process.
--
Colin Percival
Security Officer Emeritus, FreeBSD | The power to serve
Founder, Tarsnap | www.tarsnap.com | Online backups for the truly paranoid
Conrad Meyer
2018-04-19 21:37:56 UTC
Reply
Permalink
On Thu, Apr 19, 2018 at 1:44 PM, Konstantin Belousov
Post by Konstantin Belousov
Post by Colin Percival
On large systems (e.g., EC2's x1e.32xlarge instance type, with 128 vCPUs)
the boot time console output contains a large number of lines of the forms
SMP: AP CPU #N Launched!
cpuN: <ACPI CPU> on acpi0
estN: <Enhanced SpeedStep Frequency Control> on cpuN
Having 128 almost-identical lines of output doesn't seem very useful, and
it actually has a nontrivial impact on the time spent booting.
Does anyone mind if I hide these by default, having them only show up if
boot verbosity is requested?
+1. For the device attaches, perhaps it makes sense to add a device
'spammy' flag, and set it for per-CPU devices like cpuN or estN. Then
the generic attach code can choose whether to print spammy attaches
based on bootverbose. dmesg for device attaches seems mostly
redundant with devinfo(8) for persistent devices like ACPI CPU and
est(4).
Post by Konstantin Belousov
The 'CPU XX Launched' messages are very useful for initial diagnostic
of the SMP startup failures. You need to enable bootverbose to see the
hang details, but for initial hint they are required. Unfortunately, AP
startup hangs occur too often to pretend that this can be delegated to
very specific circumstances.
Really? I don't know that I've ever seen an AP startup hang. How
often do they occur?

Best,
Conrad
Konstantin Belousov
2018-04-19 21:45:50 UTC
Reply
Permalink
Post by Conrad Meyer
On Thu, Apr 19, 2018 at 1:44 PM, Konstantin Belousov
Post by Konstantin Belousov
Post by Colin Percival
On large systems (e.g., EC2's x1e.32xlarge instance type, with 128 vCPUs)
the boot time console output contains a large number of lines of the forms
SMP: AP CPU #N Launched!
cpuN: <ACPI CPU> on acpi0
estN: <Enhanced SpeedStep Frequency Control> on cpuN
Having 128 almost-identical lines of output doesn't seem very useful, and
it actually has a nontrivial impact on the time spent booting.
Does anyone mind if I hide these by default, having them only show up if
boot verbosity is requested?
+1. For the device attaches, perhaps it makes sense to add a device
'spammy' flag, and set it for per-CPU devices like cpuN or estN. Then
the generic attach code can choose whether to print spammy attaches
based on bootverbose. dmesg for device attaches seems mostly
redundant with devinfo(8) for persistent devices like ACPI CPU and
est(4).
Post by Konstantin Belousov
The 'CPU XX Launched' messages are very useful for initial diagnostic
of the SMP startup failures. You need to enable bootverbose to see the
hang details, but for initial hint they are required. Unfortunately, AP
startup hangs occur too often to pretend that this can be delegated to
very specific circumstances.
Really? I don't know that I've ever seen an AP startup hang. How
often do they occur?
It was epidemic with Sandy Bridge, mostly correlated to specific BIOS
supplier and its interaction with the x2APIC enablement, see madt.c:170
and below.

There were several recent reports of the issue with Broadwell Xeon
machines, no additional data or resolution.

There are sporadic reports of the problem, where I do not see
a clear commonality.
Stefan Blachmann
2018-04-19 23:05:00 UTC
Reply
Permalink
I would also like a solution to this issue, which is looking highly
unprofessional and uselessly wasting space in the dmesg ring buffer.

In the first version of my sysutils/cpupdate tool I also had spammy
output like being complained about.
This was hard-to-read. Thus I changed code so that identical cores
output was collected up in blocks of single output, i.e.: "core #n to
#m: <identical stats>".
If all cpus are identical, cpu stats will be output only once this
way, else in subsequent blocks comprising all identical cores on
different cpus.

To avoid the spamming at bootup and microcode updating, the kernel
would need such a function to read/evaluate *all* cores in a row, like
I did in cpupdate.
This would be only a few lines of code.
Post by Konstantin Belousov
Post by Conrad Meyer
On Thu, Apr 19, 2018 at 1:44 PM, Konstantin Belousov
Post by Konstantin Belousov
Post by Colin Percival
On large systems (e.g., EC2's x1e.32xlarge instance type, with 128 vCPUs)
the boot time console output contains a large number of lines of the forms
SMP: AP CPU #N Launched!
cpuN: <ACPI CPU> on acpi0
estN: <Enhanced SpeedStep Frequency Control> on cpuN
Having 128 almost-identical lines of output doesn't seem very useful, and
it actually has a nontrivial impact on the time spent booting.
Does anyone mind if I hide these by default, having them only show up if
boot verbosity is requested?
+1. For the device attaches, perhaps it makes sense to add a device
'spammy' flag, and set it for per-CPU devices like cpuN or estN. Then
the generic attach code can choose whether to print spammy attaches
based on bootverbose. dmesg for device attaches seems mostly
redundant with devinfo(8) for persistent devices like ACPI CPU and
est(4).
Post by Konstantin Belousov
The 'CPU XX Launched' messages are very useful for initial diagnostic
of the SMP startup failures. You need to enable bootverbose to see the
hang details, but for initial hint they are required. Unfortunately, AP
startup hangs occur too often to pretend that this can be delegated to
very specific circumstances.
Really? I don't know that I've ever seen an AP startup hang. How
often do they occur?
It was epidemic with Sandy Bridge, mostly correlated to specific BIOS
supplier and its interaction with the x2APIC enablement, see madt.c:170
and below.
There were several recent reports of the issue with Broadwell Xeon
machines, no additional data or resolution.
There are sporadic reports of the problem, where I do not see
a clear commonality.
_______________________________________________
https://lists.freebsd.org/mailman/listinfo/freebsd-hackers
Colin Percival
2018-04-21 00:11:07 UTC
Reply
Permalink
Post by Konstantin Belousov
Post by Conrad Meyer
Post by Konstantin Belousov
The 'CPU XX Launched' messages are very useful for initial diagnostic
of the SMP startup failures. You need to enable bootverbose to see the
hang details, but for initial hint they are required. Unfortunately, AP
startup hangs occur too often to pretend that this can be delegated to
very specific circumstances.
Really? I don't know that I've ever seen an AP startup hang. How
often do they occur?
It was epidemic with Sandy Bridge, mostly correlated to specific BIOS
supplier and its interaction with the x2APIC enablement, see madt.c:170
and below.
There were several recent reports of the issue with Broadwell Xeon
machines, no additional data or resolution.
There are sporadic reports of the problem, where I do not see
a clear commonality.
Would it be sufficient for debugging purposes if I change the !bootverbose
case from printing many lines of

SMP: AP CPU #N Launched!

to instead have a single

SMP: Launching AP CPUs: 86 73 111 21 8 77 100 28 57 42 10 60 87 88 41 113 36
19 72 46 92 52 24 81 90 3 107 96 9 14 80 118 29 121 62 74 56 55 1 12 63 18 67
13 45 102 33 94 69 68 93 83 48 31 30 32 51 89 71 78 64 84 123 61 40 47 37 22
54 101 38 4 97 44 17 109 104 5 85 43 2 99 39 65 95 53 58 66 91 125 23 115 16
35 79 112 103 82 7 75 11 6 98 15 126 127 20 70 34 105 27 50 116 120 49 25 108
106 122 117 114 26 110 59 76 124 119

? (With each AP printing its number as it reaches the appropriate point?)

This yields almost the same gain as silencing the launch messages completely,
while still allowing you to see each CPU announcing itself.
--
Colin Percival
Security Officer Emeritus, FreeBSD | The power to serve
Founder, Tarsnap | www.tarsnap.com | Online backups for the truly paranoid
Warner Losh
2018-04-21 17:02:40 UTC
Reply
Permalink
Post by Colin Percival
Post by Konstantin Belousov
Post by Conrad Meyer
Post by Konstantin Belousov
The 'CPU XX Launched' messages are very useful for initial diagnostic
of the SMP startup failures. You need to enable bootverbose to see the
hang details, but for initial hint they are required. Unfortunately, AP
startup hangs occur too often to pretend that this can be delegated to
very specific circumstances.
Really? I don't know that I've ever seen an AP startup hang. How
often do they occur?
It was epidemic with Sandy Bridge, mostly correlated to specific BIOS
supplier and its interaction with the x2APIC enablement, see madt.c:170
and below.
There were several recent reports of the issue with Broadwell Xeon
machines, no additional data or resolution.
There are sporadic reports of the problem, where I do not see
a clear commonality.
Would it be sufficient for debugging purposes if I change the !bootverbose
case from printing many lines of
SMP: AP CPU #N Launched!
to instead have a single
SMP: Launching AP CPUs: 86 73 111 21 8 77 100 28 57 42 10 60 87 88 41 113 36
19 72 46 92 52 24 81 90 3 107 96 9 14 80 118 29 121 62 74 56 55 1 12 63 18 67
13 45 102 33 94 69 68 93 83 48 31 30 32 51 89 71 78 64 84 123 61 40 47 37 22
54 101 38 4 97 44 17 109 104 5 85 43 2 99 39 65 95 53 58 66 91 125 23 115 16
35 79 112 103 82 7 75 11 6 98 15 126 127 20 70 34 105 27 50 116 120 49 25 108
106 122 117 114 26 110 59 76 124 119
? (With each AP printing its number as it reaches the appropriate point?)
This yields almost the same gain as silencing the launch messages completely,
while still allowing you to see each CPU announcing itself.
The trouble is that you've got N CPUs that are doing output at the same
time. You'll need to synchronize somehow. And how do you know that the last
one is done? Especailly if one of the CPUs doesn't start..

It looks great in theory, but I'm not sure how you'd make it work in
practice.

The other stuff (cpu and per-cpu stuff) is actually easy to pare down
entirely inside of newbus. I'll share a patch to do that.

Warner
Conrad Meyer
2018-04-21 18:03:49 UTC
Reply
Permalink
Post by Warner Losh
Post by Colin Percival
Would it be sufficient for debugging purposes if I change the !bootverbose
case from printing many lines of
SMP: AP CPU #N Launched!
to instead have a single
SMP: Launching AP CPUs: 86 73 111 21 8 77 100 28 57 42 10 60 87 88 41 113 36
19 72 46 92 52 24 81 90 3 107 96 9 14 80 118 29 121 62 74 56 55 1 12 63 18 67
13 45 102 33 94 69 68 93 83 48 31 30 32 51 89 71 78 64 84 123 61 40 47 37 22
54 101 38 4 97 44 17 109 104 5 85 43 2 99 39 65 95 53 58 66 91 125 23 115 16
35 79 112 103 82 7 75 11 6 98 15 126 127 20 70 34 105 27 50 116 120 49 25 108
106 122 117 114 26 110 59 76 124 119
? (With each AP printing its number as it reaches the appropriate point?)
This yields almost the same gain as silencing the launch messages completely,
while still allowing you to see each CPU announcing itself.
The trouble is that you've got N CPUs that are doing output at the same
time. You'll need to synchronize somehow. And how do you know that the last
one is done? Especailly if one of the CPUs doesn't start..
It looks great in theory, but I'm not sure how you'd make it work in
practice.
Yeah. You could pare down the number of characters per-AP
substantially. Something like:

SMP: Launching APs:
2
3
4
...

It sounds like EC2 is redrawing on every character emitted, scrolling
or not. So the additional line breaks shouldn't hurt.

Best,
Conrad
Colin Percival
2018-04-21 20:25:30 UTC
Reply
Permalink
Post by Conrad Meyer
It sounds like EC2 is redrawing on every character emitted, scrolling
or not. So the additional line breaks shouldn't hurt.
EC2 redraws characters when they're written to the VGA text mode buffer.
Line breaks absolutely matter -- when we have a line break we rewrite the
entire screen. Writing characters without scrolling is much faster.

(FWIW, this applies to vt_fb as well; it's just that EC2 is the most extreme
case since it combines a large number of CPUs with a slow emulated VGA.
--
Colin Percival
Security Officer Emeritus, FreeBSD | The power to serve
Founder, Tarsnap | www.tarsnap.com | Online backups for the truly paranoid
Colin Percival
2018-04-21 20:30:10 UTC
Reply
Permalink
Post by Colin Percival
Would it be sufficient for debugging purposes if I change the !bootverbose
case from printing many lines of
SMP: AP CPU #N Launched!
to instead have a single
SMP: Launching AP CPUs: 86 73 111 21 8 77 100 28 57 42 10 60 87 88 41 113 36
19 72 46 92 52 24 81 90 3 107 96 9 14 80 118 29 121 62 74 56 55 1 12 63 18 67
13 45 102 33 94 69 68 93 83 48 31 30 32 51 89 71 78 64 84 123 61 40 47 37 22
54 101 38 4 97 44 17 109 104 5 85 43 2 99 39 65 95 53 58 66 91 125 23 115 16
35 79 112 103 82 7 75 11 6 98 15 126 127 20 70 34 105 27 50 116 120 49 25 108
106 122 117 114 26 110 59 76 124 119
?  (With each AP printing its number as it reaches the appropriate point?)
This yields almost the same gain as silencing the launch messages completely,
while still allowing you to see each CPU announcing itself.
The trouble is that you've got N CPUs that are doing output at the same time.
You'll need to synchronize somehow. And how do you know that the last one is
done? Especailly if one of the CPUs doesn't start..
Fortunately, this output is all generated with the ap_boot_mtx lock held.
--
Colin Percival
Security Officer Emeritus, FreeBSD | The power to serve
Founder, Tarsnap | www.tarsnap.com | Online backups for the truly paranoid
Konstantin Belousov
2018-04-21 09:20:49 UTC
Reply
Permalink
Post by Colin Percival
Post by Konstantin Belousov
Post by Conrad Meyer
Post by Konstantin Belousov
The 'CPU XX Launched' messages are very useful for initial diagnostic
of the SMP startup failures. You need to enable bootverbose to see the
hang details, but for initial hint they are required. Unfortunately, AP
startup hangs occur too often to pretend that this can be delegated to
very specific circumstances.
Really? I don't know that I've ever seen an AP startup hang. How
often do they occur?
It was epidemic with Sandy Bridge, mostly correlated to specific BIOS
supplier and its interaction with the x2APIC enablement, see madt.c:170
and below.
There were several recent reports of the issue with Broadwell Xeon
machines, no additional data or resolution.
There are sporadic reports of the problem, where I do not see
a clear commonality.
Would it be sufficient for debugging purposes if I change the !bootverbose
case from printing many lines of
SMP: AP CPU #N Launched!
to instead have a single
SMP: Launching AP CPUs: 86 73 111 21 8 77 100 28 57 42 10 60 87 88 41 113 36
19 72 46 92 52 24 81 90 3 107 96 9 14 80 118 29 121 62 74 56 55 1 12 63 18 67
13 45 102 33 94 69 68 93 83 48 31 30 32 51 89 71 78 64 84 123 61 40 47 37 22
54 101 38 4 97 44 17 109 104 5 85 43 2 99 39 65 95 53 58 66 91 125 23 115 16
35 79 112 103 82 7 75 11 6 98 15 126 127 20 70 34 105 27 50 116 120 49 25 108
106 122 117 114 26 110 59 76 124 119
? (With each AP printing its number as it reaches the appropriate point?)
This yields almost the same gain as silencing the launch messages completely,
while still allowing you to see each CPU announcing itself.
I am fine with the behaviour, but I am not sure how would you implement
this. printf(9) buffers the output, you need to flush it somehow.
Gary Jennejohn
2018-04-21 10:35:44 UTC
Reply
Permalink
On Sat, 21 Apr 2018 12:20:49 +0300
Post by Konstantin Belousov
Post by Colin Percival
Post by Konstantin Belousov
Post by Conrad Meyer
Post by Konstantin Belousov
The 'CPU XX Launched' messages are very useful for initial diagnostic
of the SMP startup failures. You need to enable bootverbose to see the
hang details, but for initial hint they are required. Unfortunately, AP
startup hangs occur too often to pretend that this can be delegated to
very specific circumstances.
Really? I don't know that I've ever seen an AP startup hang. How
often do they occur?
It was epidemic with Sandy Bridge, mostly correlated to specific BIOS
supplier and its interaction with the x2APIC enablement, see madt.c:170
and below.
There were several recent reports of the issue with Broadwell Xeon
machines, no additional data or resolution.
There are sporadic reports of the problem, where I do not see
a clear commonality.
Would it be sufficient for debugging purposes if I change the !bootverbose
case from printing many lines of
SMP: AP CPU #N Launched!
to instead have a single
SMP: Launching AP CPUs: 86 73 111 21 8 77 100 28 57 42 10 60 87 88 41 113 36
19 72 46 92 52 24 81 90 3 107 96 9 14 80 118 29 121 62 74 56 55 1 12 63 18 67
13 45 102 33 94 69 68 93 83 48 31 30 32 51 89 71 78 64 84 123 61 40 47 37 22
54 101 38 4 97 44 17 109 104 5 85 43 2 99 39 65 95 53 58 66 91 125 23 115 16
35 79 112 103 82 7 75 11 6 98 15 126 127 20 70 34 105 27 50 116 120 49 25 108
106 122 117 114 26 110 59 76 124 119
? (With each AP printing its number as it reaches the appropriate point?)
This yields almost the same gain as silencing the launch messages completely,
while still allowing you to see each CPU announcing itself.
I am fine with the behaviour, but I am not sure how would you implement
this. printf(9) buffers the output, you need to flush it somehow.
And printf(9) calls vprintf(9) which in turn calls _vprintf which
will allocate a buffer on the stack (bad idea) if the option
PRINTF_BUFR_SIZE is set in the kernel config file. So it seems
that output may even be double buffered.
--
Gary Jennejohn
Stefan Blachmann
2018-04-21 13:03:01 UTC
Reply
Permalink
There are not many places that call the cpu initializing routine.
Thus it should be easy to add a pointer to the output function to be used.

What about solving the problem using simple code like I did this in
sysutils/cpupdate?
(https://github.com/kernschmelze/cpupdate)

[BEGIN PSEUDOCODE SNIPPET]
print_cpu_stats( stringbuffer *info, int from, int to)
{
print( "Core %d to %d: %s", from, to, info);
}

initialize_all_cpus()
{
int startcore = 0;
int ncore = 1;
stringbuffer
*ncoreinfo,
*startcoreinfo = initializeCPU(0, functionPointerPrintToStringBuffer);

for ( ; ncore < numCores ; ++ncore) {
ncoreinfo = initialize_one_CPU(ncore, functionPointerPrintToStringBuffer);
if ( <compare_startcoreinfo_output_is_different_to_ncoreinfo> ) {
// core #ncore is different than core #startcore..#(ncore-1).
// Print core info for that block
print_cpu_stats( startcoreinfo, startcore, ncore - 1);
startcore = ncore;
startcoreinfo = ncoreinfo;
}
}
// make sure also the last block of identical cores are shown
if (startcore < ncore)
print_cpu_stats( startcoreinfo, startcore, ncore - 1);
}
[END PSEUDOCODE SNIPPET]

Only such a small change would be necessary in the bootup code and in
cpuctl.c to avoid massive spamming when updating microcode.

But I have given up attempting to contribute to FreeBSD, because of
the gross lack of interest on core developers' side in things
important to people running FreeBSD on bare metal.

For example, it is just amazing to see how all reports about massive
flaws in kernel microcode detection/updating and all offered patches
are being blatantly ignored for many years. See for example:
https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=192487

Sad, very sad!
Post by Gary Jennejohn
On Sat, 21 Apr 2018 12:20:49 +0300
Post by Konstantin Belousov
Post by Colin Percival
Post by Konstantin Belousov
Post by Conrad Meyer
Post by Konstantin Belousov
The 'CPU XX Launched' messages are very useful for initial diagnostic
of the SMP startup failures. You need to enable bootverbose to see the
hang details, but for initial hint they are required. Unfortunately, AP
startup hangs occur too often to pretend that this can be delegated to
very specific circumstances.
Really? I don't know that I've ever seen an AP startup hang. How
often do they occur?
It was epidemic with Sandy Bridge, mostly correlated to specific BIOS
supplier and its interaction with the x2APIC enablement, see madt.c:170
and below.
There were several recent reports of the issue with Broadwell Xeon
machines, no additional data or resolution.
There are sporadic reports of the problem, where I do not see
a clear commonality.
Would it be sufficient for debugging purposes if I change the !bootverbose
case from printing many lines of
SMP: AP CPU #N Launched!
to instead have a single
SMP: Launching AP CPUs: 86 73 111 21 8 77 100 28 57 42 10 60 87 88 41 113 36
19 72 46 92 52 24 81 90 3 107 96 9 14 80 118 29 121 62 74 56 55 1 12 63 18 67
13 45 102 33 94 69 68 93 83 48 31 30 32 51 89 71 78 64 84 123 61 40 47 37 22
54 101 38 4 97 44 17 109 104 5 85 43 2 99 39 65 95 53 58 66 91 125 23 115 16
35 79 112 103 82 7 75 11 6 98 15 126 127 20 70 34 105 27 50 116 120 49 25 108
106 122 117 114 26 110 59 76 124 119
? (With each AP printing its number as it reaches the appropriate point?)
This yields almost the same gain as silencing the launch messages completely,
while still allowing you to see each CPU announcing itself.
I am fine with the behaviour, but I am not sure how would you implement
this. printf(9) buffers the output, you need to flush it somehow.
And printf(9) calls vprintf(9) which in turn calls _vprintf which
will allocate a buffer on the stack (bad idea) if the option
PRINTF_BUFR_SIZE is set in the kernel config file. So it seems
that output may even be double buffered.
--
Gary Jennejohn
_______________________________________________
https://lists.freebsd.org/mailman/listinfo/freebsd-hackers
Julian Elischer
2018-04-21 17:00:21 UTC
Reply
Permalink
Post by Stefan Blachmann
For example, it is just amazing to see how all reports about massive
flaws in kernel microcode detection/updating and all offered patches
https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=192487
yes I saw that but Only a handful of people know what's going on there
so 99% of the
developers just stood back and said "I hope someone who understands
this picks it up".
I didn't follow the one response I saw. So I couldn't decide on who
had the better argument.
Warner Losh
2018-04-21 17:04:11 UTC
Reply
Permalink
Post by Stefan Blachmann
For example, it is just amazing to see how all reports about massive
flaws in kernel microcode detection/updating and all offered patches
https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=192487
yes I saw that but Only a handful of people know what's going on there so
99% of the
developers just stood back and said "I hope someone who understands this
picks it up".
I didn't follow the one response I saw. So I couldn't decide on who had
the better argument.
Except that I said "sure, I'll integrate it, but you need to do these
things" and Stefan said "oh, lemme get you the code" and I never heard back
anything except complaints that it hasn't been integrated yet. Not playing
well with others makes them less willing to help you.

Warner
Stefan Blachmann
2018-04-21 17:30:24 UTC
Reply
Permalink
Post by Warner Losh
Except that I said "sure, I'll integrate it, but you need to do these
things" and Stefan said "oh, lemme get you the code" and I never heard back
anything except complaints that it hasn't been integrated yet. Not playing
well with others makes them less willing to help you.
Well, I refactored the code to be up to style guidelines, and when it
was ready on Mar 20th, I emailed you and the other guys involved with
microcode stuff.
Didn't get an answer from you, so I thought there would be no more interest.

But, maybe it was just the mail slipping through, or get forgotten due
to much work?
Warner Losh
2018-04-21 19:52:46 UTC
Reply
Permalink
Post by Gary Jennejohn
On Sat, 21 Apr 2018 12:20:49 +0300
Post by Konstantin Belousov
Post by Colin Percival
Post by Konstantin Belousov
Post by Conrad Meyer
Post by Konstantin Belousov
The 'CPU XX Launched' messages are very useful for initial
diagnostic
Post by Konstantin Belousov
Post by Colin Percival
Post by Konstantin Belousov
Post by Conrad Meyer
Post by Konstantin Belousov
of the SMP startup failures. You need to enable bootverbose to see
the
Post by Konstantin Belousov
Post by Colin Percival
Post by Konstantin Belousov
Post by Conrad Meyer
Post by Konstantin Belousov
hang details, but for initial hint they are required.
Unfortunately, AP
Post by Konstantin Belousov
Post by Colin Percival
Post by Konstantin Belousov
Post by Conrad Meyer
Post by Konstantin Belousov
startup hangs occur too often to pretend that this can be
delegated to
Post by Konstantin Belousov
Post by Colin Percival
Post by Konstantin Belousov
Post by Conrad Meyer
Post by Konstantin Belousov
very specific circumstances.
Really? I don't know that I've ever seen an AP startup hang. How
often do they occur?
It was epidemic with Sandy Bridge, mostly correlated to specific BIOS
supplier and its interaction with the x2APIC enablement, see
madt.c:170
Post by Konstantin Belousov
Post by Colin Percival
Post by Konstantin Belousov
and below.
There were several recent reports of the issue with Broadwell Xeon
machines, no additional data or resolution.
There are sporadic reports of the problem, where I do not see
a clear commonality.
Would it be sufficient for debugging purposes if I change the
!bootverbose
Post by Konstantin Belousov
Post by Colin Percival
case from printing many lines of
SMP: AP CPU #N Launched!
to instead have a single
SMP: Launching AP CPUs: 86 73 111 21 8 77 100 28 57 42 10 60 87 88 41
113 36
Post by Konstantin Belousov
Post by Colin Percival
19 72 46 92 52 24 81 90 3 107 96 9 14 80 118 29 121 62 74 56 55 1 12
63 18 67
Post by Konstantin Belousov
Post by Colin Percival
13 45 102 33 94 69 68 93 83 48 31 30 32 51 89 71 78 64 84 123 61 40 47
37 22
Post by Konstantin Belousov
Post by Colin Percival
54 101 38 4 97 44 17 109 104 5 85 43 2 99 39 65 95 53 58 66 91 125 23
115 16
Post by Konstantin Belousov
Post by Colin Percival
35 79 112 103 82 7 75 11 6 98 15 126 127 20 70 34 105 27 50 116 120 49
25 108
Post by Konstantin Belousov
Post by Colin Percival
106 122 117 114 26 110 59 76 124 119
? (With each AP printing its number as it reaches the appropriate
point?)
Post by Konstantin Belousov
Post by Colin Percival
This yields almost the same gain as silencing the launch messages
completely,
Post by Konstantin Belousov
Post by Colin Percival
while still allowing you to see each CPU announcing itself.
I am fine with the behaviour, but I am not sure how would you implement
this. printf(9) buffers the output, you need to flush it somehow.
And printf(9) calls vprintf(9) which in turn calls _vprintf which
will allocate a buffer on the stack (bad idea) if the option
PRINTF_BUFR_SIZE is set in the kernel config file. So it seems
that output may even be double buffered.
I don't think either of these is true (the double buffered part,. nor the
buffered part). Well, they are both kinda true, but they don't matter. It's
all to make dmesg and friends work. There's other issues, but at this stage
of the boot we're single threaded and the CPUs that are launching take out
a spin lock.

We always call putchar for each character that kvprintf(). So any buffering
that's done is in addition to putchar going to the console.

diff --git a/sys/x86/x86/mp_x86.c b/sys/x86/x86/mp_x86.c
index 3fcf7aa25152..06973b1ea6d5 100644
--- a/sys/x86/x86/mp_x86.c
+++ b/sys/x86/x86/mp_x86.c
@@ -1020,7 +1020,7 @@ init_secondary_tail(void)
smp_cpus++;

CTR1(KTR_SMP, "SMP: AP CPU #%d Launched", cpuid);
- printf("SMP: AP CPU #%d Launched!\n", cpuid);
+ printf("%d%s", cpuid, smp_cpus == mp_ncpus ? "\n" : " ");

/* Determine if we are a logical CPU. */
if (cpu_info[PCPU_GET(apic_id)].cpu_hyperthread)

is enough to give them all to me on a single line. We'd need another printf
that says 'Starting APs: ' since otherwise we see:

andom: unblocking device.
ioapic0 <Version 2.0> irqs 0-23 on motherboard
ioapic1 <Version 2.0> irqs 24-47 on motherboard
1 8 10 20 2 19 11 12 22 4 14 23 16 13 3 18 5 17 21 9 15 6 7
Timecounter "TSC-low" frequency 1350029824 Hz quality 1000

which doesn't make a lot of sense.

Comments?

Warner
Konstantin Belousov
2018-04-21 20:19:29 UTC
Reply
Permalink
Post by Warner Losh
Post by Gary Jennejohn
On Sat, 21 Apr 2018 12:20:49 +0300
Post by Konstantin Belousov
Post by Colin Percival
Post by Konstantin Belousov
Post by Conrad Meyer
Post by Konstantin Belousov
The 'CPU XX Launched' messages are very useful for initial
diagnostic
Post by Konstantin Belousov
Post by Colin Percival
Post by Konstantin Belousov
Post by Conrad Meyer
Post by Konstantin Belousov
of the SMP startup failures. You need to enable bootverbose to see
the
Post by Konstantin Belousov
Post by Colin Percival
Post by Konstantin Belousov
Post by Conrad Meyer
Post by Konstantin Belousov
hang details, but for initial hint they are required.
Unfortunately, AP
Post by Konstantin Belousov
Post by Colin Percival
Post by Konstantin Belousov
Post by Conrad Meyer
Post by Konstantin Belousov
startup hangs occur too often to pretend that this can be
delegated to
Post by Konstantin Belousov
Post by Colin Percival
Post by Konstantin Belousov
Post by Conrad Meyer
Post by Konstantin Belousov
very specific circumstances.
Really? I don't know that I've ever seen an AP startup hang. How
often do they occur?
It was epidemic with Sandy Bridge, mostly correlated to specific BIOS
supplier and its interaction with the x2APIC enablement, see
madt.c:170
Post by Konstantin Belousov
Post by Colin Percival
Post by Konstantin Belousov
and below.
There were several recent reports of the issue with Broadwell Xeon
machines, no additional data or resolution.
There are sporadic reports of the problem, where I do not see
a clear commonality.
Would it be sufficient for debugging purposes if I change the
!bootverbose
Post by Konstantin Belousov
Post by Colin Percival
case from printing many lines of
SMP: AP CPU #N Launched!
to instead have a single
SMP: Launching AP CPUs: 86 73 111 21 8 77 100 28 57 42 10 60 87 88 41
113 36
Post by Konstantin Belousov
Post by Colin Percival
19 72 46 92 52 24 81 90 3 107 96 9 14 80 118 29 121 62 74 56 55 1 12
63 18 67
Post by Konstantin Belousov
Post by Colin Percival
13 45 102 33 94 69 68 93 83 48 31 30 32 51 89 71 78 64 84 123 61 40 47
37 22
Post by Konstantin Belousov
Post by Colin Percival
54 101 38 4 97 44 17 109 104 5 85 43 2 99 39 65 95 53 58 66 91 125 23
115 16
Post by Konstantin Belousov
Post by Colin Percival
35 79 112 103 82 7 75 11 6 98 15 126 127 20 70 34 105 27 50 116 120 49
25 108
Post by Konstantin Belousov
Post by Colin Percival
106 122 117 114 26 110 59 76 124 119
? (With each AP printing its number as it reaches the appropriate
point?)
Post by Konstantin Belousov
Post by Colin Percival
This yields almost the same gain as silencing the launch messages
completely,
Post by Konstantin Belousov
Post by Colin Percival
while still allowing you to see each CPU announcing itself.
I am fine with the behaviour, but I am not sure how would you implement
this. printf(9) buffers the output, you need to flush it somehow.
And printf(9) calls vprintf(9) which in turn calls _vprintf which
will allocate a buffer on the stack (bad idea) if the option
PRINTF_BUFR_SIZE is set in the kernel config file. So it seems
that output may even be double buffered.
I don't think either of these is true (the double buffered part,. nor the
buffered part). Well, they are both kinda true, but they don't matter. It's
all to make dmesg and friends work. There's other issues, but at this stage
of the boot we're single threaded and the CPUs that are launching take out
a spin lock.
We always call putchar for each character that kvprintf(). So any buffering
that's done is in addition to putchar going to the console.
diff --git a/sys/x86/x86/mp_x86.c b/sys/x86/x86/mp_x86.c
index 3fcf7aa25152..06973b1ea6d5 100644
--- a/sys/x86/x86/mp_x86.c
+++ b/sys/x86/x86/mp_x86.c
@@ -1020,7 +1020,7 @@ init_secondary_tail(void)
smp_cpus++;
CTR1(KTR_SMP, "SMP: AP CPU #%d Launched", cpuid);
- printf("SMP: AP CPU #%d Launched!\n", cpuid);
+ printf("%d%s", cpuid, smp_cpus == mp_ncpus ? "\n" : " ");
With this, my concern is to have the cpu ids printed immediately, instead
of being buffered until \n is printed as well. Please ensure that this is
the case.
Post by Warner Losh
/* Determine if we are a logical CPU. */
if (cpu_info[PCPU_GET(apic_id)].cpu_hyperthread)
is enough to give them all to me on a single line. We'd need another printf
andom: unblocking device.
ioapic0 <Version 2.0> irqs 0-23 on motherboard
ioapic1 <Version 2.0> irqs 24-47 on motherboard
1 8 10 20 2 19 11 12 22 4 14 23 16 13 3 18 5 17 21 9 15 6 7
Timecounter "TSC-low" frequency 1350029824 Hz quality 1000
which doesn't make a lot of sense.
Comments?
Warner
Colin Percival
2018-04-21 20:30:12 UTC
Reply
Permalink
Post by Gary Jennejohn
On Sat, 21 Apr 2018 12:20:49 +0300
Post by Konstantin Belousov
Post by Colin Percival
Would it be sufficient for debugging purposes if I change the !bootverbose
case from printing many lines of
SMP: AP CPU #N Launched!
to instead have a single
SMP: Launching AP CPUs: 86 73 111 21 8 77 100 28 57 42 10 60 87 [...]
?  (With each AP printing its number as it reaches the appropriate point?)
I am fine with the behaviour, but I am not sure how would you implement
this.  printf(9) buffers the output, you need to flush it somehow.
I don't think either of these is true (the double buffered part,. nor the
buffered part). Well, they are both kinda true, but they don't matter. It's
all to make dmesg and friends work. There's other issues, but at this stage of
the boot we're single threaded and the CPUs that are launching take out a spin
lock.
I just checked (by adding a 500 ms delay after each CPU prints its ID) and I
can definitely see the individual numbers being printed on the console.
Post by Gary Jennejohn
diff --git a/sys/x86/x86/mp_x86.c b/sys/x86/x86/mp_x86.c
index 3fcf7aa25152..06973b1ea6d5 100644
--- a/sys/x86/x86/mp_x86.c
+++ b/sys/x86/x86/mp_x86.c
@@ -1020,7 +1020,7 @@ init_secondary_tail(void)
        smp_cpus++;
        CTR1(KTR_SMP, "SMP: AP CPU #%d Launched", cpuid);
-       printf("SMP: AP CPU #%d Launched!\n", cpuid);
+       printf("%d%s", cpuid, smp_cpus == mp_ncpus ? "\n" : " ");
        /* Determine if we are a logical CPU. */
        if (cpu_info[PCPU_GET(apic_id)].cpu_hyperthread)
is enough to give them all to me on a single line. We'd need another printf
andom: unblocking device.
ioapic0 <Version 2.0> irqs 0-23 on motherboard
ioapic1 <Version 2.0> irqs 24-47 on motherboard
1 8 10 20 2 19 11 12 22 4 14 23 16 13 3 18 5 17 21 9 15 6 7
Timecounter "TSC-low" frequency 1350029824 Hz quality 1000
which doesn't make a lot of sense.
Comments?
Here's the patch I have, which prints a header before the CPU IDs:

Index: sys/x86/x86/mp_x86.c
===================================================================
--- sys/x86/x86/mp_x86.c (revision 332638)
+++ sys/x86/x86/mp_x86.c (working copy)
@@ -1020,7 +1020,9 @@
smp_cpus++;

CTR1(KTR_SMP, "SMP: AP CPU #%d Launched", cpuid);
- printf("SMP: AP CPU #%d Launched!\n", cpuid);
+ printf(" %d", cpuid);
+ if (smp_cpus == mp_ncpus)
+ printf("\n");

/* Determine if we are a logical CPU. */
if (cpu_info[PCPU_GET(apic_id)].cpu_hyperthread)
@@ -1508,6 +1510,7 @@

if (mp_ncpus == 1)
return;
+ printf("SMP: Launching AP CPUs:");
atomic_store_rel_int(&aps_ready, 1);
while (smp_started == 0)
ia32_pause();
--
Colin Percival
Security Officer Emeritus, FreeBSD | The power to serve
Founder, Tarsnap | www.tarsnap.com | Online backups for the truly paranoid
Warner Losh
2018-04-21 20:35:42 UTC
Reply
Permalink
Post by Colin Percival
Post by Gary Jennejohn
On Sat, 21 Apr 2018 12:20:49 +0300
Post by Konstantin Belousov
Post by Colin Percival
Would it be sufficient for debugging purposes if I change the
!bootverbose
Post by Gary Jennejohn
Post by Konstantin Belousov
Post by Colin Percival
case from printing many lines of
SMP: AP CPU #N Launched!
to instead have a single
SMP: Launching AP CPUs: 86 73 111 21 8 77 100 28 57 42 10 60 87
[...]
Post by Gary Jennejohn
Post by Konstantin Belousov
Post by Colin Percival
? (With each AP printing its number as it reaches the
appropriate point?)
Post by Gary Jennejohn
Post by Konstantin Belousov
I am fine with the behaviour, but I am not sure how would you
implement
Post by Gary Jennejohn
Post by Konstantin Belousov
this. printf(9) buffers the output, you need to flush it somehow.
I don't think either of these is true (the double buffered part,. nor the
buffered part). Well, they are both kinda true, but they don't matter.
It's
Post by Gary Jennejohn
all to make dmesg and friends work. There's other issues, but at this
stage of
Post by Gary Jennejohn
the boot we're single threaded and the CPUs that are launching take out
a spin
Post by Gary Jennejohn
lock.
I just checked (by adding a 500 ms delay after each CPU prints its ID) and
I
can definitely see the individual numbers being printed on the console.
Post by Gary Jennejohn
diff --git a/sys/x86/x86/mp_x86.c b/sys/x86/x86/mp_x86.c
index 3fcf7aa25152..06973b1ea6d5 100644
--- a/sys/x86/x86/mp_x86.c
+++ b/sys/x86/x86/mp_x86.c
@@ -1020,7 +1020,7 @@ init_secondary_tail(void)
smp_cpus++;
CTR1(KTR_SMP, "SMP: AP CPU #%d Launched", cpuid);
- printf("SMP: AP CPU #%d Launched!\n", cpuid);
+ printf("%d%s", cpuid, smp_cpus == mp_ncpus ? "\n" : " ");
/* Determine if we are a logical CPU. */
if (cpu_info[PCPU_GET(apic_id)].cpu_hyperthread)
is enough to give them all to me on a single line. We'd need another
printf
Post by Gary Jennejohn
andom: unblocking device.
ioapic0 <Version 2.0> irqs 0-23 on motherboard
ioapic1 <Version 2.0> irqs 24-47 on motherboard
1 8 10 20 2 19 11 12 22 4 14 23 16 13 3 18 5 17 21 9 15 6 7
Timecounter "TSC-low" frequency 1350029824 Hz quality 1000
which doesn't make a lot of sense.
Comments?
Index: sys/x86/x86/mp_x86.c
===================================================================
--- sys/x86/x86/mp_x86.c (revision 332638)
+++ sys/x86/x86/mp_x86.c (working copy)
@@ -1020,7 +1020,9 @@
smp_cpus++;
CTR1(KTR_SMP, "SMP: AP CPU #%d Launched", cpuid);
- printf("SMP: AP CPU #%d Launched!\n", cpuid);
+ printf(" %d", cpuid);
+ if (smp_cpus == mp_ncpus)
+ printf("\n");
/* Determine if we are a logical CPU. */
if (cpu_info[PCPU_GET(apic_id)].cpu_hyperthread)
@@ -1508,6 +1510,7 @@
if (mp_ncpus == 1)
return;
+ printf("SMP: Launching AP CPUs:");
atomic_store_rel_int(&aps_ready, 1);
while (smp_started == 0)
ia32_pause();
Here's the one that I have:

diff --git a/sys/x86/x86/mp_x86.c b/sys/x86/x86/mp_x86.c
index 3fcf7aa25152..4637243c4274 100644
--- a/sys/x86/x86/mp_x86.c
+++ b/sys/x86/x86/mp_x86.c
@@ -1020,7 +1020,8 @@ init_secondary_tail(void)
smp_cpus++;

CTR1(KTR_SMP, "SMP: AP CPU #%d Launched", cpuid);
- printf("SMP: AP CPU #%d Launched!\n", cpuid);
+ printf("%s%d%s", smp_cpus == 1 ? "Launching APs: " : "",
+ cpuid, smp_cpus == mp_ncpus ? "\n" : " ");

/* Determine if we are a logical CPU. */
if (cpu_info[PCPU_GET(apic_id)].cpu_hyperthread)

which will print the results one at a time. Except when PRINTF_BUFR_SIZE is
defined (which is in the GENERIC config). Do you have it in the kernel
you're booting in the cloud?

Warner
Colin Percival
2018-04-21 20:50:19 UTC
Reply
Permalink
Post by Warner Losh
diff --git a/sys/x86/x86/mp_x86.c b/sys/x86/x86/mp_x86.c
index 3fcf7aa25152..4637243c4274 100644
--- a/sys/x86/x86/mp_x86.c
+++ b/sys/x86/x86/mp_x86.c
@@ -1020,7 +1020,8 @@ init_secondary_tail(void)
        smp_cpus++;
        CTR1(KTR_SMP, "SMP: AP CPU #%d Launched", cpuid);
-       printf("SMP: AP CPU #%d Launched!\n", cpuid);
+       printf("%s%d%s", smp_cpus == 1 ? "Launching APs: " : "",
+           cpuid, smp_cpus == mp_ncpus ? "\n" : " ");
Have you tested this? If you're going to print the header here, I think
you need to check for smp_cpus == 2, since it starts at 1 and is already
incremented once. (Because CPU #0 isn't an AP and thus doesn't hit this
code path.)
Post by Warner Losh
which will print the results one at a time. Except when PRINTF_BUFR_SIZE is
defined (which is in the GENERIC config). Do you have it in the kernel you're
booting in the cloud?
I'm running GENERIC + options TSLOG, and (with a 500 ms delay added) I could
definitely see the individual numbers showing up one by one on the VGA output.
--
Colin Percival
Security Officer Emeritus, FreeBSD | The power to serve
Founder, Tarsnap | www.tarsnap.com | Online backups for the truly paranoid
Steven Hartland
2018-04-19 20:48:13 UTC
Reply
Permalink
Sounds good to me, I think we could actually benefit from even quieter
modes if I’m honest.
Post by Colin Percival
On large systems (e.g., EC2's x1e.32xlarge instance type, with 128 vCPUs)
the boot time console output contains a large number of lines of the forms
SMP: AP CPU #N Launched!
cpuN: <ACPI CPU> on acpi0
estN: <Enhanced SpeedStep Frequency Control> on cpuN
Having 128 almost-identical lines of output doesn't seem very useful, and
it actually has a nontrivial impact on the time spent booting.
Does anyone mind if I hide these by default, having them only show up if
boot verbosity is requested?
--
Colin Percival
Security Officer Emeritus, FreeBSD | The power to serve
Founder, Tarsnap | www.tarsnap.com | Online backups for the truly paranoid
_______________________________________________
https://lists.freebsd.org/mailman/listinfo/freebsd-hackers
Julian Elischer
2018-04-20 06:11:36 UTC
Reply
Permalink
Post by Steven Hartland
Sounds good to me, I think we could actually benefit from even quieter
modes if I’m honest.
Post by Colin Percival
On large systems (e.g., EC2's x1e.32xlarge instance type, with 128 vCPUs)
the boot time console output contains a large number of lines of the forms
SMP: AP CPU #N Launched!
cpuN: <ACPI CPU> on acpi0
estN: <Enhanced SpeedStep Frequency Control> on cpuN
Having 128 almost-identical lines of output doesn't seem very useful, and
it actually has a nontrivial impact on the time spent booting.
Does anyone mind if I hide these by default, having them only show up if
boot verbosity is requested?
make them single line and just type a CR at the end so they cycle
through on the same line.
or "previous line repeated N times  with only 3 characters different"
Post by Steven Hartland
Post by Colin Percival
--
Colin Percival
Security Officer Emeritus, FreeBSD | The power to serve
Founder, Tarsnap | www.tarsnap.com | Online backups for the truly paranoid
_______________________________________________
https://lists.freebsd.org/mailman/listinfo/freebsd-hackers
_______________________________________________
https://lists.freebsd.org/mailman/listinfo/freebsd-hackers
Warner Losh
2018-04-21 19:28:44 UTC
Reply
Permalink
Post by Steven Hartland
Sounds good to me, I think we could actually benefit from even quieter
modes if I’m honest.
On large systems (e.g., EC2's x1e.32xlarge instance type, with 128 vCPUs)
Post by Colin Percival
the boot time console output contains a large number of lines of the forms
SMP: AP CPU #N Launched!
cpuN: <ACPI CPU> on acpi0
estN: <Enhanced SpeedStep Frequency Control> on cpuN
Having 128 almost-identical lines of output doesn't seem very useful, and
it actually has a nontrivial impact on the time spent booting.
Does anyone mind if I hide these by default, having them only show up if
boot verbosity is requested?
https://reviews.freebsd.org/D15153 implements that for everything except
the CPU launched.

Warner
Rodney W. Grimes
2018-04-19 23:17:41 UTC
Reply
Permalink
Post by Conrad Meyer
On Thu, Apr 19, 2018 at 1:44 PM, Konstantin Belousov
Post by Konstantin Belousov
Post by Colin Percival
On large systems (e.g., EC2's x1e.32xlarge instance type, with 128 vCPUs)
the boot time console output contains a large number of lines of the forms
SMP: AP CPU #N Launched!
cpuN: <ACPI CPU> on acpi0
estN: <Enhanced SpeedStep Frequency Control> on cpuN
Having 128 almost-identical lines of output doesn't seem very useful, and
it actually has a nontrivial impact on the time spent booting.
Does anyone mind if I hide these by default, having them only show up if
boot verbosity is requested?
+1. For the device attaches, perhaps it makes sense to add a device
'spammy' flag, and set it for per-CPU devices like cpuN or estN. Then
the generic attach code can choose whether to print spammy attaches
based on bootverbose. dmesg for device attaches seems mostly
redundant with devinfo(8) for persistent devices like ACPI CPU and
est(4).
Post by Konstantin Belousov
The 'CPU XX Launched' messages are very useful for initial diagnostic
of the SMP startup failures. You need to enable bootverbose to see the
hang details, but for initial hint they are required. Unfortunately, AP
startup hangs occur too often to pretend that this can be delegated to
very specific circumstances.
Really? I don't know that I've ever seen an AP startup hang. How
often do they occur?
What about if XX > 4 silence the messages unless bootverbose is set?
That gets us kinda both worlds, you still see AP startup occuring,
but once you seen 4 of them go off there isnt much point in seeing
the next N of them.
--
Rod Grimes ***@freebsd.org
Cy Schubert
2018-04-21 14:55:00 UTC
Reply
Permalink
In message <CACc-My0qnG1f7Szxho-***@mail.gma
il.com>
Post by Stefan Blachmann
I would also like a solution to this issue, which is looking highly
unprofessional and uselessly wasting space in the dmesg ring buffer.
Really? Have you looked at Red Hat (or Oracle) Linux or Solaris dmesg
output?

Why neuter the dmesg ring buffer?
Post by Stefan Blachmann
In the first version of my sysutils/cpupdate tool I also had spammy
output like being complained about.
This was hard-to-read. Thus I changed code so that identical cores
output was collected up in blocks of single output, i.e.: "core #n to
#m: <identical stats>".
If all cpus are identical, cpu stats will be output only once this
way, else in subsequent blocks comprising all identical cores on
different cpus.
To avoid the spamming at bootup and microcode updating, the kernel
would need such a function to read/evaluate *all* cores in a row, like
I did in cpupdate.
This would be only a few lines of code.
Maybe the solution is a Red Hat style of slider bar or a Windows style
graphic to hide messages.

Personally, a Red Hat style of slider might work. Hit the enter to see
the gory details. Hit enter again to see the slider bar again. It
doesn't have to be a slider -- we don't want to look like a RH
derivative. It can be any kind of progress indicator.

Additionally, green and red checkboxes like HP/UX and Red Hat (they
ripped that off from HP) is okay but when something fails you're in the
dark. (At $JOB we use HP SA, with its green checkmarks and red x's on
various dashboard style outputs. All you can tell is something is out
of compliance but not where the actual problem is. This is totally
unacceptable.)

~cy
Post by Stefan Blachmann
Post by Konstantin Belousov
Post by Conrad Meyer
On Thu, Apr 19, 2018 at 1:44 PM, Konstantin Belousov
Post by Konstantin Belousov
Post by Colin Percival
On large systems (e.g., EC2's x1e.32xlarge instance type, with 128
vCPUs)
the boot time console output contains a large number of lines of the
forms
SMP: AP CPU #N Launched!
cpuN: <ACPI CPU> on acpi0
estN: <Enhanced SpeedStep Frequency Control> on cpuN
Having 128 almost-identical lines of output doesn't seem very useful,
and
it actually has a nontrivial impact on the time spent booting.
Does anyone mind if I hide these by default, having them only show up
if
boot verbosity is requested?
+1. For the device attaches, perhaps it makes sense to add a device
'spammy' flag, and set it for per-CPU devices like cpuN or estN. Then
the generic attach code can choose whether to print spammy attaches
based on bootverbose. dmesg for device attaches seems mostly
redundant with devinfo(8) for persistent devices like ACPI CPU and
est(4).
Post by Konstantin Belousov
The 'CPU XX Launched' messages are very useful for initial diagnostic
of the SMP startup failures. You need to enable bootverbose to see the
hang details, but for initial hint they are required. Unfortunately, AP
startup hangs occur too often to pretend that this can be delegated to
very specific circumstances.
Really? I don't know that I've ever seen an AP startup hang. How
often do they occur?
It was epidemic with Sandy Bridge, mostly correlated to specific BIOS
supplier and its interaction with the x2APIC enablement, see madt.c:170
and below.
There were several recent reports of the issue with Broadwell Xeon
machines, no additional data or resolution.
There are sporadic reports of the problem, where I do not see
a clear commonality.
_______________________________________________
https://lists.freebsd.org/mailman/listinfo/freebsd-hackers
_______________________________________________
https://lists.freebsd.org/mailman/listinfo/freebsd-hackers
--
Cheers,
Cy Schubert <***@cschubert.com>
FreeBSD UNIX: <***@FreeBSD.org> Web: http://www.FreeBSD.org

The need of the many outweighs the greed of the few.
Cy Schubert
2018-11-18 22:05:04 UTC
Reply
Permalink
In message <CACc-My33oRg7eqjfDuEQU51inyydc66Hx+-***@mail.gma
il.com>
The inconveniences that the new swapping strategy causes are a regular
topic in the FreeBSD forums.
Desktop users complain about lagginess, server users complain of long
delays because server processes intended to be kept in memory for
quick response times got swapped out and need to be swapped in again,
resulting in outrageously poor server performance in spite of plenty
of unused memory.
There are many factors for this. One of the biggest mistakes people
make is use UFS and ZFS on the same system. Limiting ZFS ARC max would
be a good place to start.

Unfortunately like many operating systems these days, FreeBSD's tuning
parameters are generally baked in. And, fencing (an IBM term to limit
address space memory use or to establish a minimum) isn't available.
So, tuning for a site specific workload is more difficult.

Making sure there is plenty of RAM installed and tuning down ZFS ARC
can go a long way. Having said that, it's been a while since I've had
to do this. The updates made to ZFS ARC and NUMA have allowed me to
rely on the algorithms baked into FreeBSD. My 8 GB systems have
performed rather well.
Turning off swap completely, as Cy Schubert suggests, is strongly
discouraged in the forums, as it can lead to kernel panicking because
of being unable to swap out in critical kernel memory shortage
situations, leading to the risk of very serious filesystem
corruption.
Actually, I didn't suggest it. I simply pointed out the option.
Furthermore, it was a mistake for Linux to remove swapping entirely
from their kernel. For those who want to try it, however, the option is
there.
However, Cy Schubert is probably right when stating that the new
swapping strategy resembles the 1960s-1980s industry's main swapping
strategy.
The bad thing is now, that nowadays memory is no longer scarce and
people can dimension their memory such that under normal circumstances
there will never be any need to swap.
Adding more RAM has been the general thinking over the last 15-20 years.
So I guess the unwillingness of the developer team to add an option
like "NoPreemptiveSwapping", which disables swapping out as long as
there is free physical memory available, is of psychological nature.
How do you know processes are indeed swapped out rather than (many)
pages paged out. You can't tell and using top's w mode, sorted by swap
doesn't tell us anything because IMO it's bogus, incorrect numbers.
Lacking such an option, there is still the possibility to use rctl to
disable swapping for particular users, processes, jails etc to
mitigate the problems caused by the new swapping strategy to some
degree.
Our options are limited. I'd prefer something similar to what we had on
MVS, when I worked on it, however even IBM has dumbed down SRM (System
Resource Manager) such that knobs that were once there no longer are.
Tuning based upon analysis of site specific stats are a thing of the
past. It's 2018 and sadly one size fits all.
--
Cheers,
Cy Schubert <***@cschubert.com>
FreeBSD UNIX: <***@FreeBSD.org> Web: http://www.FreeBSD.org

The need of the many outweighs the greed of the few.
Rebecca Cran via freebsd-hackers
2018-11-19 04:44:02 UTC
Reply
Permalink
Post by Cy Schubert
Unfortunately like many operating systems these days, FreeBSD's tuning
parameters are generally baked in. And, fencing (an IBM term to limit
address space memory use or to establish a minimum) isn't available.
So, tuning for a site specific workload is more difficult.
Talking of tuning, this seems like a good resource for tuning for desktop use:
https://cooltrainer.org/a-freebsd-desktop-howto/ .
--
Rebecca
Wojciech Puchar
2018-11-19 10:24:55 UTC
Reply
Permalink
Post by Cy Schubert
can go a long way. Having said that, it's been a while since I've had
to do this. The updates made to ZFS ARC and NUMA have allowed me to
rely on the algorithms baked into FreeBSD. My 8 GB systems have
performed rather well.
8GB is LOT LOT LOT of memory.
Steven Hartland
2018-11-19 10:32:50 UTC
Reply
Permalink
It really isn't
Post by Wojciech Puchar
Post by Cy Schubert
can go a long way. Having said that, it's been a while since I've had
to do this. The updates made to ZFS ARC and NUMA have allowed me to
rely on the algorithms baked into FreeBSD. My 8 GB systems have
performed rather well.
8GB is LOT LOT LOT of memory.
_______________________________________________
https://lists.freebsd.org/mailman/listinfo/freebsd-hackers
To unsubscribe, send any mail to
Stefan Blachmann
2018-11-19 14:40:01 UTC
Reply
Permalink
Post by Wojciech Puchar
Post by Cy Schubert
can go a long way. Having said that, it's been a while since I've had
to do this. The updates made to ZFS ARC and NUMA have allowed me to
rely on the algorithms baked into FreeBSD. My 8 GB systems have
performed rather well.
8GB is LOT LOT LOT of memory.
This might indeed be a cue.
Actually, I *never* had such annoying swap lag issues, until I
replaced my old computers (8GB) with newer ones (24-48GB).

With this increased memory, the ZFS ARC issue became apparent, causing
massive problems when ARC used more than 40 of the 48GB, starving
programs from memory, but this can be tuned easily.

And the "preemptive swapping" issue became apparent, too. Letting
programs idle for some time caused swapping out. This led to a very
bad user experience... often when one changes to another
desktop/virtual screen to another program, there is a delay of
swapping in, which in some cases could last for seconds when hundreds
of megabytes were swapped in again, in spite of some tens of gigabytes
of memory that never have been used since system boot.
Post by Wojciech Puchar
and my servers that have LOTS of httpd servers each for one webpage which are usually rarely visited.
I wondered why my test server had a delayed response time the first
few times I call a page from it after having it idled for some time.
To me it looks like that the threads apache keeps cached in memory for
fast response times got swapped out and the server response is slow
until all these have become "memory resident" again.

As the bad response times due to unnecessary preemptive swapping would
induce Google downranking for sites that aren't visited sufficiently
frequently enough to keep them from being swapped out, I consider this
a very very serious problem.


Disabling swap (either totally or for the affected
programs/users/jails using rctl) and taking care that memory never
runs out was the only way I was able to fix these issues.

And I find very interesting that this seems to occur *only* on
machines with *much* memory.
The complaints about this swapping behavior I saw on the forums
*always* regarded machines with at least 48GB of RAM. (I am not sure
whether I saw reports regarding 32GB machines, so I would suggest
investigating the issue on machines >=48GB)
Mark Millard via freebsd-hackers
2018-11-19 17:41:06 UTC
Reply
Permalink
Post by Stefan Blachmann
Post by Wojciech Puchar
Post by Cy Schubert
can go a long way. Having said that, it's been a while since I've had
to do this. The updates made to ZFS ARC and NUMA have allowed me to
rely on the algorithms baked into FreeBSD. My 8 GB systems have
performed rather well.
8GB is LOT LOT LOT of memory.
This might indeed be a cue.
Actually, I *never* had such annoying swap lag issues, until I
replaced my old computers (8GB) with newer ones (24-48GB).
With this increased memory, the ZFS ARC issue became apparent, causing
massive problems when ARC used more than 40 of the 48GB, starving
programs from memory, but this can be tuned easily.
And the "preemptive swapping" issue became apparent, too.
You mentioned ZFS. Have any reports of "preemptive swapping" been
for a context where ZFS was not involved? This might always be
part of the context, sort of like you are saying larger amounts
of RAM are.

My contexts do not use ZFS but I have one context with 96 GiBytes
of RAM. It has no problem with pageouts/swapouts during idle, even
when idle for days. Such activity is always well explained by
process RAM use and dirty page handling that follows. No evidence
of "preemptive swapping".

But idle here means very little running: only running the processes
the OS starts plus up to a few ssh sessions, nfs client/server
included, ntpd included, ssh allowed, a couple of network protocol
daemons enabled, sendmail enables set to "NO". (There are 32
"cpus".) The machines are not outward accessible and do not run X11
or other such.
Post by Stefan Blachmann
Letting
programs idle for some time caused swapping out.
Is there any evidence of growing RAM use during such generally idle
times? Might there be some form of RAM leak in your workload or
the OS (for how you are using it)?

FreeBSD waits to start paging/swapping until the free RAM is
low --by its criteria for low. The pageout/swapout is just
a a step in the means of gaining more free RAM.

Have you observed what is going on (RAM use) just before and during
when pages-outs/swap-outs are first initiated? A description of
that would be handy for folks trying to help you.
Post by Stefan Blachmann
This led to a very
bad user experience... often when one changes to another
desktop/virtual screen to another program, there is a delay of
swapping in, which in some cases could last for seconds when hundreds
of megabytes were swapped in again, in spite of some tens of gigabytes
of memory that never have been used since system boot.
Post by Wojciech Puchar
and my servers that have LOTS of httpd servers each for one webpage which are usually rarely visited.
I wondered why my test server had a delayed response time the first
few times I call a page from it after having it idled for some time.
To me it looks like that the threads apache keeps cached in memory for
fast response times got swapped out and the server response is slow
until all these have become "memory resident" again.
As the bad response times due to unnecessary preemptive swapping would
induce Google downranking for sites that aren't visited sufficiently
frequently enough to keep them from being swapped out, I consider this
a very very serious problem.
Disabling swap (either totally or for the affected
programs/users/jails using rctl) and taking care that memory never
runs out was the only way I was able to fix these issues.
And I find very interesting that this seems to occur *only* on
machines with *much* memory.
The complaints about this swapping behavior I saw on the forums
*always* regarded machines with at least 48GB of RAM. (I am not sure
whether I saw reports regarding 32GB machines, so I would suggest
investigating the issue on machines >=48GB)
===
Mark Millard
marklmi at yahoo.com
( dsl-only.net went
away in early 2018-Mar)

Rodney W. Grimes
2018-11-19 15:51:17 UTC
Reply
Permalink
Post by Steven Hartland
It really isn't
It is all relative. You have to take into perspective just what it
is your "computing" and how much state it should need to do that
"computation".

Modern systems and software have become very wasteful as memory
was "cheap". With 10nM getting the better of Intel, and DARPA
pushing towards 5nM the cheapness factor is rapidly erroding.

8GB is a huge amount of memory if I am trying to play astroids
on a 640x480 display, it is a drop in the bucket if I am trying
to do fluid dynamics of a aircraft wing.
Post by Steven Hartland
Post by Wojciech Puchar
Post by Cy Schubert
can go a long way. Having said that, it's been a while since I've had
to do this. The updates made to ZFS ARC and NUMA have allowed me to
rely on the algorithms baked into FreeBSD. My 8 GB systems have
performed rather well.
8GB is LOT LOT LOT of memory.
My diskless boot server laptop is running ZFS and now since updated to
12.0Beta4 NUMA too and is rather happy in its 2GB of memory. The work
load fits niceless into this footprint. I probably would not want to
fire up X11 and Firefox as a daily browswer on it, but the fact is it
can also do that without too much pain.
--
Rod Grimes ***@freebsd.org
Loading...