Bug#914490: ifupdown: networking.service timeout due to /dev/crng initalization?
reassign 914490 wpasupplicant thanks On Fri, Nov 23, 2018 at 02:06:07PM -0800, Grant Grundler wrote: > I'm not sure why I didn't see this before, but it seems to be a "known > problem". Searching for > "wpa_supplicant crng" yields some helpful information. e.g.: > https://forums.gentoo.org/viewtopic-t-1081710-start-0.html [...] > Anyway, My guess is this report should be assigned to wpa_supplicant, > not ifupdown package. Reassigning. -- Met vriendelijke groet / with kind regards, Guus Sliepen signature.asc Description: PGP signature
Bug#914490: ifupdown: networking.service timeout due to /dev/crng initalization?
I'm not sure why I didn't see this before, but it seems to be a "known problem". Searching for "wpa_supplicant crng" yields some helpful information. e.g.: https://forums.gentoo.org/viewtopic-t-1081710-start-0.html Proposed solution to gentoo: "To solve this, one should merge sys-apps/rng-tools and add rngd to sysinit boot level to utilize hardware rng." Uhm...not quite sure how to translate that into "debian". But one part is obvious: apt-get install rng-tools but that "failed" in the install because this device doesn't export a HW Random Number Generator. :/ ... Selecting previously unselected package rng-tools. (Reading database ... 35727 files and directories currently installed.) Preparing to unpack .../rng-tools_2-unofficial-mt.14-1+b2_amd64.deb ... Unpacking rng-tools (2-unofficial-mt.14-1+b2) ... Setting up rng-tools (2-unofficial-mt.14-1+b2) ... Job for rng-tools.service failed because the control process exited with error code. See "systemctl status rng-tools.service" and "journalctl -xe" for details. invoke-rc.d: initscript rng-tools, action "start" failed. ● rng-tools.service Loaded: loaded (/etc/init.d/rng-tools; generated) Active: failed (Result: exit-code) since Fri 2018-11-23 14:02:41 PST; 9ms ago Docs: man:systemd-sysv-generator(8) Process: 1398 ExecStart=/etc/init.d/rng-tools start (code=exited, status=1/FAILURE) Nov 23 14:02:41 stoke systemd[1]: Starting rng-tools.service... Nov 23 14:02:41 stoke rng-tools[1398]: Starting Hardware RNG entropy gatherer daemon: (Hardware RNG device inode not found) Nov 23 14:02:41 stoke rng-tools[1398]: /etc/init.d/rng-tools: Cannot find a hardware RNG device to use. Nov 23 14:02:41 stoke systemd[1]: rng-tools.service: Control process exited, code=exited status=1 Nov 23 14:02:41 stoke systemd[1]: rng-tools.service: Failed with result 'exit-code'. Nov 23 14:02:41 stoke systemd[1]: Failed to start rng-tools.service. Processing triggers for systemd (239-13) ... Processing triggers for man-db (2.8.4-3) ... Anyway, My guess is this report should be assigned to wpa_supplicant, not ifupdown package. On Fri, Nov 23, 2018 at 12:57 PM Grant Grundler wrote: > > Package: ifupdown > Version: 0.8.32 > Severity: important > > Dear Maintainer, > > *** Reporter, please consider answering these questions, where appropriate *** > >* What led up to the situation? >* What exactly did you do (or not do) that was effective (or > ineffective)? >* What was the outcome of this action? >* What outcome did you expect instead? > > *** End of the template - remove these template lines *** > > > -- System Information: > Debian Release: buster/sid > APT prefers testing > APT policy: (500, 'testing') > Architecture: amd64 (x86_64) > > Kernel: Linux 4.18.0-2-amd64 (SMP w/2 CPU cores) > Locale: LANG=en_US.utf8, LC_CTYPE=en_US.utf8 (charmap=locale: Cannot set > LC_CTYPE to default locale: No such file or directory > locale: Cannot set LC_MESSAGES to default locale: No such file or directory > locale: Cannot set LC_ALL to default locale: No such file or directory > ANSI_X3.4-1968), LANGUAGE=en_US.utf8 (charmap=locale: Cannot set LC_CTYPE to > default locale: No such file or directory > locale: Cannot set LC_MESSAGES to default locale: No such file or directory > locale: Cannot set LC_ALL to default locale: No such file or directory > ANSI_X3.4-1968) > Shell: /bin/sh linked to /bin/dash > Init: systemd (via /run/systemd/system) > > Versions of packages ifupdown depends on: > ii adduser 3.118 > ii iproute2 4.18.0-2 > ii libc6 2.27-8 > ii lsb-base 9.20170808 > > Versions of packages ifupdown recommends: > ii isc-dhcp-client [dhcp-client] 4.3.5-4+b1 > > Versions of packages ifupdown suggests: > pn ppp > pn rdnssd > > -- Configuration Files: > /etc/default/networking changed [not included] > > > Note: Two NICs: PCIe r8169 configured statically and PCIe ath9k configured > via dhclient > > # cat /etc/network/interfaces > source /etc/network/interfaces.d/* > > # The loopback network interface > auto lo > iface lo inet loopback > > auto enp1s0 > iface enp1s0 inet static > address 192.168.100.1/24 > > auto wlp2s0 > iface wlp2s0 inet dhcp > wpa-ssid kroleks warren > wpa-psk PASSWORD > > enp1s0 is configured but networking.service times out (5 minutes). > But after logging in from console, networking comes up in < 20 seconds > by running: > systemctl stop networking.service > systemctl start networking.service > > I've looked at a bunch of other ifupdown reports and this one seems the > closest: > #832074 networking.service: Start operation timed out > > One theory presented in this bug is "problem with ifupdown <-> dhclient > interaction". > > My theory is dependency on /dev/crng since running the same commands > later works fine. I installed ifupdown2 and that suceeded after 7-8 > minutes (no timeout?!!!). > > Here is directly related snippets of daemon.log from the last run with >
Bug#914490: ifupdown: networking.service timeout due to /dev/crng initalization?
Package: ifupdown Version: 0.8.32 Severity: important Dear Maintainer, *** Reporter, please consider answering these questions, where appropriate *** * What led up to the situation? * What exactly did you do (or not do) that was effective (or ineffective)? * What was the outcome of this action? * What outcome did you expect instead? *** End of the template - remove these template lines *** -- System Information: Debian Release: buster/sid APT prefers testing APT policy: (500, 'testing') Architecture: amd64 (x86_64) Kernel: Linux 4.18.0-2-amd64 (SMP w/2 CPU cores) Locale: LANG=en_US.utf8, LC_CTYPE=en_US.utf8 (charmap=locale: Cannot set LC_CTYPE to default locale: No such file or directory locale: Cannot set LC_MESSAGES to default locale: No such file or directory locale: Cannot set LC_ALL to default locale: No such file or directory ANSI_X3.4-1968), LANGUAGE=en_US.utf8 (charmap=locale: Cannot set LC_CTYPE to default locale: No such file or directory locale: Cannot set LC_MESSAGES to default locale: No such file or directory locale: Cannot set LC_ALL to default locale: No such file or directory ANSI_X3.4-1968) Shell: /bin/sh linked to /bin/dash Init: systemd (via /run/systemd/system) Versions of packages ifupdown depends on: ii adduser 3.118 ii iproute2 4.18.0-2 ii libc6 2.27-8 ii lsb-base 9.20170808 Versions of packages ifupdown recommends: ii isc-dhcp-client [dhcp-client] 4.3.5-4+b1 Versions of packages ifupdown suggests: pn ppp pn rdnssd -- Configuration Files: /etc/default/networking changed [not included] Note: Two NICs: PCIe r8169 configured statically and PCIe ath9k configured via dhclient # cat /etc/network/interfaces source /etc/network/interfaces.d/* # The loopback network interface auto lo iface lo inet loopback auto enp1s0 iface enp1s0 inet static address 192.168.100.1/24 auto wlp2s0 iface wlp2s0 inet dhcp wpa-ssid kroleks warren wpa-psk PASSWORD enp1s0 is configured but networking.service times out (5 minutes). But after logging in from console, networking comes up in < 20 seconds by running: systemctl stop networking.service systemctl start networking.service I've looked at a bunch of other ifupdown reports and this one seems the closest: #832074 networking.service: Start operation timed out One theory presented in this bug is "problem with ifupdown <-> dhclient interaction". My theory is dependency on /dev/crng since running the same commands later works fine. I installed ifupdown2 and that suceeded after 7-8 minutes (no timeout?!!!). Here is directly related snippets of daemon.log from the last run with ifupdown2 installed: Nov 22 23:39:35 stoke systemd[1]: Starting ifupdown2 networking initialization... ... Nov 22 23:39:35 stoke systemd[1]: Started Load/Save RF Kill Switch Status. ... Nov 22 23:39:35 stoke wpa_supplicant[302]: Successfully initialized wpa_supplicant Nov 22 23:39:35 stoke networking[308]: networking: Configuring network interfaces Nov 22 23:39:36 stoke wpa_supplicant[425]: Successfully initialized wpa_supplicant Nov 22 23:47:15 stoke dhclient[446]: DHCPREQUEST of 192.168.86.23 on wlp2s0 to 255.255.255.255 port 67 Nov 22 23:47:18 stoke wpa_supplicant[437]: wlp2s0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN Nov 22 23:47:19 stoke wpa_supplicant[437]: wlp2s0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN Nov 22 23:47:19 stoke wpa_supplicant[437]: wlp2s0: SME: Trying to authenticate with f4:f2:6d:a9:1d:91 (SSID='kroleks warren' freq=5745 MHz) Nov 22 23:47:19 stoke wpa_supplicant[437]: wlp2s0: Trying to associate with f4:f2:6d:a9:1d:91 (SSID='kroleks warren' freq=5745 MHz) Nov 22 23:47:19 stoke wpa_supplicant[437]: wlp2s0: Associated with f4:f2:6d:a9:1d:91 Nov 22 23:47:19 stoke wpa_supplicant[437]: wlp2s0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Nov 22 23:47:19 stoke wpa_supplicant[437]: wlp2s0: WPA: Key negotiation completed with f4:f2:6d:a9:1d:91 [PTK=CCMP GTK=CCMP] Nov 22 23:47:19 stoke wpa_supplicant[437]: wlp2s0: CTRL-EVENT-CONNECTED - Connection to f4:f2:6d:a9:1d:91 completed [id=0 id_str=] Nov 22 23:47:21 stoke dhclient[446]: DHCPREQUEST of 192.168.86.23 on wlp2s0 to 255.255.255.255 port 67 Nov 22 23:47:21 stoke dhclient[446]: DHCPACK of 192.168.86.23 from 192.168.86.1 Nov 22 23:47:21 stoke dhclient[446]: bound to 192.168.86.23 -- renewal in 36571 seconds. Nov 22 23:47:21 stoke systemd[1]: Started ifupdown2 networking initialization. Nov 22 23:47:21 stoke systemd[1]: Reached target Network. OBVIOUS QUESTION: What caused 7:39 delay between wpa_supplicant successfully starting and sending out DHCPREQUEST? I suspect if I had increased the networking.service timeout to 10 minutes, it likely would have "succeeded" as well. Around the same time, kern.log has: ... Nov 22 23:39:36 stoke kernel: [5.026394] r8169 :01:00.0: firmware: direct-loading firmware rtl_nic/rtl8168g-2.fw Nov 22 23:39:36 stoke kernel: [5.098167] r8169
