2020-02-01 17:54:29

by Toralf Förster

[permalink] [raw]
Subject: why does "mem auto-init: clearing system memory may take some time..." takes about 14 sec under 5.4.17 but only few msec under 5.5.1?

I do wonder (and I'm surprised) about increased boot speed according to dmesg for thi9s hardend Gentoo Linux system:
Linux mr-fox 5.5.1 #1 SMP Sat Feb 1 18:25:21 CET 2020 x86_64 Intel(R) Xeon(R) CPU E5-1650 v3 @ 3.50GHz GenuineIntel GNU/Linux

Under 5.4.17 I do have usually 14 sec to wait:

[ 0.497171] mem auto-init: stack:byref_all, heap alloc:on, heap free:on
[ 0.497171] mem auto-init: clearing system memory may take some time...
[ 0.501549] Calgary: detecting Calgary via BIOS EBDA area
[ 0.501550] Calgary: Unable to locate Rio Grande table in EBDA - bailing!
[ 14.083235] Memory: 131812972K/134101088K available (12291K kernel code, 1400K rwdata, 1912K rodata, 1272K init, 2040K bss, 2288116K reserved, 0K cma-reserved)
[ 14.083342] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=12, Nodes=1
[ 14.083350] Kernel/User page tables isolation: enabled
[ 14.083403] rcu: Hierarchical RCU implementation.
[ 14.083404] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies.
[ 14.083414] NR_IRQS: 4352, nr_irqs: 928, preallocated irqs: 16

but with 5.5.1 there's no wait?:

[ 0.000000] mem auto-init: stack:byref_all, heap alloc:on, heap free:on
[ 0.000000] mem auto-init: clearing system memory may take some time...
[ 0.000000] Memory: 131812876K/134101088K available (12291K kernel code, 1412K rwdata, 1936K rodata, 1260K init, 2012K bss, 2288212K reserved, 0K cma-reserved)
[ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=12, Nodes=1
[ 0.000000] Kernel/User page tables isolation: enabled
[ 0.000000] rcu: Hierarchical RCU implementation.
[ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies.
[ 0.000000] NR_IRQS: 4352, nr_irqs: 928, preallocated irqs: 16
[ 0.000000] random: get_random_bytes called from start_kernel+0x4a8/0x659 with crng_init=0

Do I miss something? (The kernel config was derived via "make oldconfig").

--
Toralf


2020-03-30 03:00:36

by Randy Dunlap

[permalink] [raw]
Subject: Re: why does "mem auto-init: clearing system memory may take some time..." takes about 14 sec under 5.4.17 but only few msec under 5.5.1?

On 2/1/20 9:52 AM, Toralf Förster wrote:
> I do wonder (and I'm surprised) about increased boot speed according to dmesg for thi9s hardend Gentoo Linux system:
> Linux mr-fox 5.5.1 #1 SMP Sat Feb 1 18:25:21 CET 2020 x86_64 Intel(R) Xeon(R) CPU E5-1650 v3 @ 3.50GHz GenuineIntel GNU/Linux
>
> Under 5.4.17 I do have usually 14 sec to wait:
>
> [ 0.497171] mem auto-init: stack:byref_all, heap alloc:on, heap free:on
> [ 0.497171] mem auto-init: clearing system memory may take some time...
> [ 0.501549] Calgary: detecting Calgary via BIOS EBDA area
> [ 0.501550] Calgary: Unable to locate Rio Grande table in EBDA - bailing!
> [ 14.083235] Memory: 131812972K/134101088K available (12291K kernel code, 1400K rwdata, 1912K rodata, 1272K init, 2040K bss, 2288116K reserved, 0K cma-reserved)
> [ 14.083342] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=12, Nodes=1
> [ 14.083350] Kernel/User page tables isolation: enabled
> [ 14.083403] rcu: Hierarchical RCU implementation.
> [ 14.083404] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies.
> [ 14.083414] NR_IRQS: 4352, nr_irqs: 928, preallocated irqs: 16
>
> but with 5.5.1 there's no wait?:
>
> [ 0.000000] mem auto-init: stack:byref_all, heap alloc:on, heap free:on
> [ 0.000000] mem auto-init: clearing system memory may take some time...
> [ 0.000000] Memory: 131812876K/134101088K available (12291K kernel code, 1412K rwdata, 1936K rodata, 1260K init, 2012K bss, 2288212K reserved, 0K cma-reserved)
> [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=12, Nodes=1
> [ 0.000000] Kernel/User page tables isolation: enabled
> [ 0.000000] rcu: Hierarchical RCU implementation.
> [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies.
> [ 0.000000] NR_IRQS: 4352, nr_irqs: 928, preallocated irqs: 16
> [ 0.000000] random: get_random_bytes called from start_kernel+0x4a8/0x659 with crng_init=0
>
> Do I miss something? (The kernel config was derived via "make oldconfig").

Hi > Toralf,

Curious/odd.

Do you have the kernel .config files for 5.4.17 and 5.5.1?
Looks like it would have to be a config difference AFAICT.

--
~Randy

2020-03-30 07:13:49

by Toralf Förster

[permalink] [raw]
Subject: Re: why does "mem auto-init: clearing system memory may take some time..." takes about 14 sec under 5.4.17 but only few msec under 5.5.1?

On 3/30/20 4:55 AM, Randy Dunlap wrote:
> Hi > Toralf,
>
> Curious/odd.
>
> Do you have the kernel .config files for 5.4.17 and 5.5.1?
> Looks like it would have to be a config difference AFAICT.
Well, the attached I found

--
Toralf


Attachments:
config-5.2.20 (104.40 kB)
config-5.4.23 (103.14 kB)
Download all attachments

2020-03-30 09:14:59

by Toralf Förster

[permalink] [raw]
Subject: Re: why does "mem auto-init: clearing system memory may take some time..." takes about 14 sec under 5.4.17 but only few msec under 5.5.1?

On 3/30/20 4:55 AM, Randy Dunlap wrote:
> Hi > Toralf,
>
> Curious/odd.
>
> Do you have the kernel .config files for 5.4.17 and 5.5.1?
> Looks like it would have to be a config difference AFAICT.

Sry,

attached the wrong configs at my previous mail. Here are 2 configs from the affected server attached.


--
Toralf


Attachments:
config-5.4.17 (77.26 kB)
config-5.5.8 (80.00 kB)
Download all attachments

2020-04-03 01:49:57

by Randy Dunlap

[permalink] [raw]
Subject: Re: why does "mem auto-init: clearing system memory may take some time..." takes about 14 sec under 5.4.17 but only few msec under 5.5.1?

On 3/30/20 2:12 AM, Toralf Förster wrote:
> On 3/30/20 4:55 AM, Randy Dunlap wrote:
>> Hi > Toralf,
>>
>> Curious/odd.
>>
>> Do you have the kernel .config files for 5.4.17 and 5.5.1?
>> Looks like it would have to be a config difference AFAICT.
>
> Sry,
>
> attached the wrong configs at my previous mail. Here are 2 configs from the affected server attached.

Hi Toralf,

There's not much difference in the kernel config files, although
the one for 5.5.8 does have CONFIG_DEBUG_KERNEL=y while it's not set
in 5.4.17.

I built both kernels and booted them. I don't see a big time difference
like you reported. Here's what I get:

5.4.17:

[ 0.112274] mem auto-init: stack:off, heap alloc:on, heap free:on
[ 0.112275] mem auto-init: clearing system memory may take some time...
[ 0.621019] Memory: 3935312K/4095412K available (10243K kernel code, 1427K rwdata, 1924K rodata, 968K init, 768K bss, 160100K reserved, 0K cma-reserved)

and 5.5.8:

[ 0.114455] mem auto-init: stack:off, heap alloc:on, heap free:on
[ 0.114456] mem auto-init: clearing system memory may take some time...
[ 0.622989] Memory: 3933200K/4095412K available (12291K kernel code, 1438K rwdata, 1952K rodata, 964K init, 708K bss, 162212K reserved, 0K cma-reserved)

but then a lot of the timestamps in your 5.5.8 log are 0.

--
~Randy