Re: delay before desktop loads

[Erwan David]

Le 30 juillet 2018 1:35:41 AM Frank McCormick  a 
écrit :




  I'm afraid patching the kernel is a little bit beyond my abilities :)



When I had identified the application, I used ltrace to identify the
library causing the problem.

What is your kernel version?


  4.17.0-1-amd64
  Previous kernel, 4.16.0-2-amd64 boots fine and does not have the problem.


Kind regards,


Frank


If you look at a recent thread about sddm, you'll see that installing 
haveged package is a correct workaround.
However upstream dev should have a reflection whether /dev/random is really 
needed by their software since urandom is not bad, even at start.

Re: delay before desktop loads

[Frank McCormick]

On 07/29/2018 06:58 PM, Ben Caradoc-Davies wrote:

On 30/07/18 07:07, Frank McCormick wrote:

I've been experiencing a long delay - upwards of 2 minutes before
the desktop on my Debian Sid loads and displays.
This happens no matter what desktop I try, Cinnamon,Mate or Icewm.

[...]

I enter my
name and password into the lightdm logon window, the wait is upwards 
of 2 minutes before the desktop loads.

[...]

Jul 29 12:06:49 franklin kernel: random: crng init done

[...]
Strangely if I click the mouse on the blank desktop several times, 
then it will start loading, but

if I don't touch it, the 2 minute delay starts
This started a couple of weeks ago, before that all desktops loaded 
quickly.

How can I debug this ?


Frank, this sounds very much like a hang on an uninitialised kernel 
crng. Does this only happen after a fresh boot, but the hang stops if 
you wiggle the mouse? 


   Yup!!



If so, you might be impacted by the change to make
the blocking getrandom kernel syscall really block until sufficient 
entropy is available. Here are some reports I made of other applications 
that were affected by this change, with detailed analysis and fixes:

//snip//

  I'm afraid patching the kernel is a little bit beyond my abilities :)



When I had identified the application, I used ltrace to identify the 
library causing the problem.


What is your kernel version?



  4.17.0-1-amd64
  Previous kernel, 4.16.0-2-amd64 boots fine and does not have the problem.


Kind regards,



Frank

Re: delay before desktop loads

[Ben Caradoc-Davies]

On 30/07/18 07:07, Frank McCormick wrote:

I've been experiencing a long delay - upwards of 2 minutes before
the desktop on my Debian Sid loads and displays.
This happens no matter what desktop I try, Cinnamon,Mate or Icewm.

[...]

I enter my
name and password into the lightdm logon window, the wait is upwards of 
2 minutes before the desktop loads.

[...]

Jul 29 12:06:49 franklin kernel: random: crng init done

[...]
Strangely if I click the mouse on the blank desktop several times, then 
it will start loading, but

if I don't touch it, the 2 minute delay starts
This started a couple of weeks ago, before that all desktops loaded 
quickly.

How can I debug this ?


Frank, this sounds very much like a hang on an uninitialised kernel 
crng. Does this only happen after a fresh boot, but the hang stops if 
you wiggle the mouse? If so, you might be impacted by the change to make 
the blocking getrandom kernel syscall really block until sufficient 
entropy is available. Here are some reports I made of other applications 
that were affected by this change, with detailed analysis and fixes:

https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=897572
https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=899080

To identify whether this is the problem, you could patch your kernel. 
Here are the patches I used:

https://github.com/bencaradocdavies/linux/commit/f0dfb0b7b72e38093aeaa67fe1116b409c1db3dc
https://github.com/bencaradocdavies/linux/commit/19e47d7049c6ca94b98cf8c00bbeb2384a9c43b9

When I had identified the application, I used ltrace to identify the 
library causing the problem.


What is your kernel version?

Kind regards,

--
Ben Caradoc-Davies 
Director
Transient Software Limited 
New Zealand

Re: delay before desktop loads

[Frank McCormick]

On 07/29/2018 05:28 PM, Frank McCormick wrote:



On 07/29/2018 05:05 PM, Matthew Crews wrote:

On 7/29/18 12:07 PM, Frank McCormick wrote:

This is an extract of the journalctl log showing the long delay.

Jul 29 12:04:45 franklin ntpd[652]: Soliciting pool server 
144.217.252.208

Jul 29 12:04:45 franklin ntpd[652]: Soliciting pool server 144.217.75.74
Jul 29 12:04:46 franklin ntpd[652]: Soliciting pool server
2607:5300:61:c0c::1
Jul 29 12:04:46 franklin ntpd[652]: Soliciting pool server 129.128.12.20
Jul 29 12:06:39 franklin kernel: logitech-hidpp-device
0003:046D:401B.0004: HID++ 2.0 device connected.
Jul 29 12:06:40 franklin upowerd[580]: treating change event as add on
/sys/devices/pci:00/:00:1d.0/usb2/2-1/2-1.7/2-1.7:1.2/00
Jul 29 12:06:49 franklin kernel: random: crng init done



  What are these pool servers you are trying to connect to? I suspect
that may be the problem.




    I have no idea. I assume they are picked automatically by ntpd when
the debian package ntpd was installed by me a long time ago.

I think they are/were related to the ntp time program which I had 
installed to keep the system clock accurate.

However, after purging ntp and it's related programs there is no change.

here's the systemd log extract:

Jul 29 18:24:34 franklin systemd[815]: Startup finished in 94ms.
Jul 29 18:24:34 franklin systemd[1]: Started User Manager for UID 1000.
Jul 29 18:24:46 franklin systemd-timesyncd[529]: Synchronized to time 
server 206.108.0.133:123 (2.debian.pool.ntp.org).


Jul 29 18:28:31 franklin kernel: logitech-hidpp-device 
0003:046D:401B.0004: HID++ 2.0 device connected.


^^^
The big delay now is the kernel connecting my Logitech wireless keyboard.
Perhaps it's borked? But it seems to work well still. A kernel bug???

[SOLVED] Re: delay before desktop loads

[Frank McCormick]

On 07/29/2018 06:38 PM, Frank McCormick wrote:



On 07/29/2018 05:28 PM, Frank McCormick wrote:



On 07/29/2018 05:05 PM, Matthew Crews wrote:

On 7/29/18 12:07 PM, Frank McCormick wrote:

This is an extract of the journalctl log showing the long delay.

Jul 29 12:04:45 franklin ntpd[652]: Soliciting pool server 
144.217.252.208
Jul 29 12:04:45 franklin ntpd[652]: Soliciting pool server 
144.217.75.74

Jul 29 12:04:46 franklin ntpd[652]: Soliciting pool server
2607:5300:61:c0c::1
Jul 29 12:04:46 franklin ntpd[652]: Soliciting pool server 
129.128.12.20

Jul 29 12:06:39 franklin kernel: logitech-hidpp-device
0003:046D:401B.0004: HID++ 2.0 device connected.
Jul 29 12:06:40 franklin upowerd[580]: treating change event as add on
/sys/devices/pci:00/:00:1d.0/usb2/2-1/2-1.7/2-1.7:1.2/00
Jul 29 12:06:49 franklin kernel: random: crng init done



  What are these pool servers you are trying to connect to? I suspect
that may be the problem.




    I have no idea. I assume they are picked automatically by ntpd when
the debian package ntpd was installed by me a long time ago.

     I think they are/were related to the ntp time program which I had 
installed to keep the system clock accurate.

However, after purging ntp and it's related programs there is no change.

here's the systemd log extract:

Jul 29 18:24:34 franklin systemd[815]: Startup finished in 94ms.
Jul 29 18:24:34 franklin systemd[1]: Started User Manager for UID 1000.
Jul 29 18:24:46 franklin systemd-timesyncd[529]: Synchronized to time 
server 206.108.0.133:123 (2.debian.pool.ntp.org).


Jul 29 18:28:31 franklin kernel: logitech-hidpp-device 
0003:046D:401B.0004: HID++ 2.0 device connected.


^^^
The big delay now is the kernel connecting my Logitech wireless keyboard.
Perhaps it's borked? But it seems to work well still. A kernel bug???






   Solved my own problem for now anyway. Booted into the previous
kernedl 4-16-02 and the delay is gone. The latest kernel is having
some sort of problem with my wireless keyboard/mouse combo.

Re: delay before desktop loads

[Frank McCormick]

On 07/29/2018 05:05 PM, Matthew Crews wrote:

On 7/29/18 12:07 PM, Frank McCormick wrote:

This is an extract of the journalctl log showing the long delay.

Jul 29 12:04:45 franklin ntpd[652]: Soliciting pool server 144.217.252.208
Jul 29 12:04:45 franklin ntpd[652]: Soliciting pool server 144.217.75.74
Jul 29 12:04:46 franklin ntpd[652]: Soliciting pool server
2607:5300:61:c0c::1
Jul 29 12:04:46 franklin ntpd[652]: Soliciting pool server 129.128.12.20
Jul 29 12:06:39 franklin kernel: logitech-hidpp-device
0003:046D:401B.0004: HID++ 2.0 device connected.
Jul 29 12:06:40 franklin upowerd[580]: treating change event as add on
/sys/devices/pci:00/:00:1d.0/usb2/2-1/2-1.7/2-1.7:1.2/00
Jul 29 12:06:49 franklin kernel: random: crng init done



  What are these pool servers you are trying to connect to? I suspect
that may be the problem.




   I have no idea. I assume they are picked automatically by ntpd when
the debian package ntpd was installed by me a long time ago.

Re: delay before desktop loads

[Matthew Crews]

On 7/29/18 12:07 PM, Frank McCormick wrote:
> This is an extract of the journalctl log showing the long delay.
> 
> Jul 29 12:04:45 franklin ntpd[652]: Soliciting pool server 144.217.252.208
> Jul 29 12:04:45 franklin ntpd[652]: Soliciting pool server 144.217.75.74
> Jul 29 12:04:46 franklin ntpd[652]: Soliciting pool server
> 2607:5300:61:c0c::1
> Jul 29 12:04:46 franklin ntpd[652]: Soliciting pool server 129.128.12.20
> Jul 29 12:06:39 franklin kernel: logitech-hidpp-device
> 0003:046D:401B.0004: HID++ 2.0 device connected.
> Jul 29 12:06:40 franklin upowerd[580]: treating change event as add on
> /sys/devices/pci:00/:00:1d.0/usb2/2-1/2-1.7/2-1.7:1.2/00
> Jul 29 12:06:49 franklin kernel: random: crng init done
> 

 What are these pool servers you are trying to connect to? I suspect
that may be the problem.

delay before desktop loads

[Frank McCormick]

I've been experiencing a long delay - upwards of 2 minutes before

the desktop on my Debian Sid loads and displays.

This happens no matter what desktop I try, Cinnamon,Mate or Icewm.

This is my hardware.

frank@franklin:~$ inxi

CPU: Dual Core Intel Core i5 660 (-MT MCP-) speed/min/max: 
1453/1197/3326 MHz Kernel: 4.17.0-1-amd64 x86_64
Up: 25m Mem: 266.0/3623.2 MiB (7.3%) Storage: 931.52 GiB (2.1% used) 
Procs: 158 Shell: bash 4.4.23 inxi: 3.0.18



I have disabled apparmor, which I suspected but there is no change. Once 
I enter my
name and password into the lightdm logon window, the wait is upwards of  
2 minutes before the desktop loads.


This is an extract of the journalctl log showing the long delay.

Jul 29 12:04:45 franklin ntpd[652]: Soliciting pool server 144.217.252.208
Jul 29 12:04:45 franklin ntpd[652]: Soliciting pool server 144.217.75.74
Jul 29 12:04:46 franklin ntpd[652]: Soliciting pool server 
2607:5300:61:c0c::1

Jul 29 12:04:46 franklin ntpd[652]: Soliciting pool server 129.128.12.20
Jul 29 12:06:39 franklin kernel: logitech-hidpp-device 
0003:046D:401B.0004: HID++ 2.0 device connected.
Jul 29 12:06:40 franklin upowerd[580]: treating change event as add on 
/sys/devices/pci:00/:00:1d.0/usb2/2-1/2-1.7/2-1.7:1.2/00

Jul 29 12:06:49 franklin kernel: random: crng init done

check the times... 12:04.46 .12:06:39

Purged ntpd, no change so I reinstalled.

Strangely if I click the mouse on the blank desktop several times, then 
it will start loading, but

if I don't touch it, the 2 minute delay starts

This started a couple of weeks ago, before that all desktops loaded quickly.

How can I debug this ?

Thanks