Re: Very slow boot and sluggish when SERVER changes 4.9 to 4.19

> 
> You don't have the following bits of a normal boot; I'd assume that 
> Devuan doesn't run the correct init script there:
> [    7.022171] random: fast init done
> [   12.916705] random: crng init done
> 
> This still doesn't explain why a server kernel change introduces this 
> though.
> 

Sorry, overzealous pruning of the dmesg. Both those bits do appear (logs 
below).

I checked for entropy on client and server with 'cat 
/proc/sys/kernel/random/entropy_avail' and both seemed okay, but 
installed 'haveged' on the client and server anyway.


DMESG for 4.19 chroot, 4.9 server:
[    0.000000] Linux version 4.19.0-4-amd64 
([email protected]) (gcc version 8.3.0 (Debian 8.3.0-2)) #1 
SMP Debian 4.19.28-2 (2019-03-15)
[    0.000000] Command line: BOOT_IMAGE=vmlinuz-4.19.0-4-amd64 ro 
initrd=initrd.img-4.19.0-4-amd64 init=/sbin/init-ltsp quiet 
root=/dev/nfs ip=dhcp boot=nfs BOOTIF=[IP ADDRESS HIDDEN]
...
[    2.432691] hid-generic 0003:04F2:0402.0003: input,hiddev0,hidraw2: 
USB HID v1.11 Device [Chicony USB Keyboard] on usb-0000:00:1a.0-1.2/input1
[    4.882700] r8169 0000:02:00.0 eth0: Link is Up - 1Gbps/Full - flow 
control rx/tx
[    4.882710] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[    5.873810] FS-Cache: Loaded
[    5.890401] RPC: Registered named UNIX socket transport module.
[    5.890403] RPC: Registered udp transport module.
[    5.890404] RPC: Registered tcp transport module.
[    5.890404] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    5.905740] FS-Cache: Netfs 'nfs' registered for caching
[    5.972674] random: fast init done
[    6.429544] urandom_read: 1 callbacks suppressed
[    6.429546] random: mktemp: uninitialized urandom read (10 bytes read)
[    8.408730] udevd[561]: starting version 3.2.7
[    8.570264] random: udevd: uninitialized urandom read (16 bytes read)
[    8.574816] random: udevd: uninitialized urandom read (16 bytes read)
[    8.574839] random: udevd: uninitialized urandom read (16 bytes read)
[    8.588026] udevd[561]: specified group 'kvm' unknown
[    8.702769] udevd[561]: starting eudev-3.2.7
...
[    9.098815] random: crng init done
[    9.098816] random: 2 urandom warning(s) missed due to ratelimiting
...
[   17.045533] Installing knfsd (copyright (C) 1996 [email protected]).
[   23.035162] elogind-daemon[2126]: New seat seat0.
[   35.100732] fuse init (API version 7.27)



DMESG for 4.19 chroot, 4.19 server:
[    0.000000] Linux version 4.19.0-4-amd64 
([email protected]) (gcc version 8.3.0 (Debian 8.3.0-2)) #1 
SMP Debian 4.19.28-2 (2019-03-15)
[    0.000000] Command line: BOOT_IMAGE=vmlinuz-4.19.0-4-amd64 ro 
initrd=initrd.img-4.19.0-4-amd64 init=/sbin/init-ltsp quiet 
root=/dev/nfs ip=dhcp boot=nfs BOOTIF=[IP ADDRESS HIDDEN]
...
[    2.528667] hid-generic 0003:04F2:0402.0003: input,hiddev0,hidraw2: 
USB HID v1.11 Device [Chicony USB Keyboard] on usb-0000:00:1a.0-1.2/input1
[    5.134887] r8169 0000:02:00.0 eth0: Link is Up - 1Gbps/Full - flow 
control rx/tx
[    5.134896] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[    5.909957] FS-Cache: Loaded
[    5.926807] RPC: Registered named UNIX socket transport module.
[    5.926809] RPC: Registered udp transport module.
[    5.926810] RPC: Registered tcp transport module.
[    5.926810] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    5.939861] FS-Cache: Netfs 'nfs' registered for caching
[    6.450234] random: fast init done
[   18.093974] urandom_read: 1 callbacks suppressed
[   18.093976] random: mktemp: uninitialized urandom read (10 bytes read)
[   39.902701] udevd[559]: starting version 3.2.7
[   40.083513] random: udevd: uninitialized urandom read (16 bytes read)
[   40.089447] random: udevd: uninitialized urandom read (16 bytes read)
[   40.089470] random: udevd: uninitialized urandom read (16 bytes read)
[   40.135699] udevd[559]: specified group 'kvm' unknown
[   40.435964] udevd[559]: starting eudev-3.2.7
...
[   41.322721] random: crng init done
[   41.322723] random: 2 urandom warning(s) missed due to ratelimiting
...
[  103.808955] Installing knfsd (copyright (C) 1996 [email protected]).
[  185.153199] elogind-daemon[2137]: New seat seat0.
[  317.835217] fuse init (API version 7.27)



So clearly the 'random' part is causing an initial pause but the whole 
boot process is sluggish by a factor of about 5, and this sluggishness 
continues post login. And the 'random' issue is clearly not entirely 
happy but the messages between the two startups are identical so I don't 
think it's a newly introduced issue - sorry for any noise caused. 
Monitoring the network load between client and server during bootup and 
usage shows nothing odd, nowhere near the bandwidth so it's not a 
spurious process flooding the network link. And server load is never 
troubled.

So I'm now thinking that for some reason the server is serving the 
client much slower under 4.19 compared to 4.9. That would explain why 
the change of server kernel does have an impact for an unchanged chroot. 
And the first variance in the timestamps comes when the client network 
is brought up - 5.13sec (4.19) versus 4.88sec (4.9).

So I'm not sure where to poke next. For the moment I'll stay with 4.9 on 
the server as I have a working system and see if others experience any 
similar issues as 4.19 rolls out in the next Debian (and Devuan) release.

Nick.



_____________________________________________________________________
Ltsp-discuss mailing list.   To un-subscribe, or change prefs, goto:
      https://lists.sourceforge.net/lists/listinfo/ltsp-discuss
For additional LTSP help,   try #ltsp channel on irc.freenode.net