| View previous topic :: View next topic |
| Author |
Message |
lesnik
n00b
Joined: 04 Oct 2016
Posts: 17
|
 Posted: Thu Apr 20, 2017 7:37 pm Post subject: troubleshoot long init process |
 |
|
Like I said, init process takes too long.
I have installed gentoo several months ago, the problem persists ever since.
Now I have latest kernel 4.9.16, openrc 0.24.2, lightdm display manager, MATE desktop, all packages updated.
NVIDIA+Intel video card (that Optimus thing), latest nvidia drivers. I tried to follow https://wiki.gentoo.org/wiki/NVIDIA/Optimus guide when configuring it.
Everything starts smoothly on boot: in about 20 seconds I get login prompt. Then display manager starts and display gets black for about 40 seconds. Eventually display manager produces login screen, I type login/password, MATE desktop starts smoothly, but network is disabled. In about 1 minute wi-fi activates. Total 2 minutes 10 seconds from "power-up" to "network-started".
What I want is an advice how to troubleshoot this problem. I want to understand how my system works as deeply as possible (that's why I installed Gentoo), but so far I am far from my goal. What I have done so far was looking into several log files.
I have looked into /var/log/meaasges. There are several errors there:
| Code: | Apr 19 21:05:03 glorx530 kernel: [ 0.659253] acpi PNP0A08:00: _OSC failed (AE_SUPPORT); disabling ASPM
|
well, so far I can live without Active-State Power Management
| Code: | Apr 19 21:05:03 glorx530 kernel: [ 1.974364] iwlwifi 0000:03:00.0: Direct firmware load for iwlwifi-6000-6.ucode failed with error -2
...
Apr 19 21:05:45 glorx530 kernel: [ 62.482773] iwlwifi 0000:03:00.0: Direct firmware load for iwlwifi-6000-5.ucode failed with error -2
|
As I understand kernel tries to load firmware for my network hardware. Why does it try to load versions 6 and 5? /lib/firmware directory contains iwlwifi-6000-4.ucode. This file was brought by sys-kernel/linux-firmware package. Like I said, it's updated to latest stable version (20161205 at the moment). How can I make sure if the absence of these iwlwifi-firmware files is the reason why network starts for so long?
Finally correct firmware is loaded and about this time network actually starts:
| Code: | Apr 19 21:06:47 glorx530 kernel: [ 123.941117] iwlwifi 0000:03:00.0: loaded firmware version 9.221.4.1 build 25532 op_mode iwldvm
|
There are no more errors in /var/log/messages. There are no records at all during the period between 17 and 62 seconds (the period when the screen is black).
/var/log/daemon.log does not contain any records for this "black" period as well:
| Code: | Apr 19 21:05:04 glorx530 ModemManager[2309]: <info> Couldn't check support for device at '/sys/devices/pci0000:00/0000:00:19.0': not supported by any plugin
Apr 19 21:05:06 glorx530 NetworkManager[2293]: <info> [1492625106.3884] manager: startup complete
Apr 19 21:05:07 glorx530 accounts-daemon[2484]: started daemon version 0.6.43
Apr 19 21:05:07 glorx530 dbus[2267]: [system] Successfully activated service 'org.freedesktop.Accounts'
Apr 19 21:05:46 glorx530 acpid: client connected from 2482[0:0]
Apr 19 21:05:46 glorx530 acpid: 1 client rule loaded
|
/var/log/Xorg.0.log contains some error, and again, no records during "black" period:
| Code: | [ 23.589] (II) LoadModule: "i915"
[ 23.590] (WW) Warning, couldn't open module i915
[ 23.590] (II) UnloadModule: "i915"
[ 23.590] (II) Unloading i915
[ 23.590] (EE) Failed to load module "i915" (module does not exist, 0)
...
[ 23.916] (**) NVIDIA(0): Option "DPI" "120 x 120"
[ 23.916] (**) NVIDIA(0): Option "AllowEmptyInitialConfiguration"
[ 23.916] (**) NVIDIA(0): Option "RegistryDwords" "EnableBrightnessControl=1"
[ 23.916] (**) NVIDIA(0): Enabling 2D acceleration
[ 62.768] (--) NVIDIA(0): Valid display device(s) on GPU-0 at PCI:1:0:0
[ 62.768] (--) NVIDIA(0): CRT-0
[ 62.768] (--) NVIDIA(0): DFP-0 (boot)
[ 62.768] (--) NVIDIA(0): DFP-1
[ 62.768] (--) NVIDIA(0): DFP-2
|
I could find out the names of my network and video cards, then google out a guide how to configure it, then run instructions from this guide one by one, google some other guide because the first one did not work for me and hope sooner or later everything will work. But I did it before, results are not very good. |
|
| Back to top |
|
 |
eccerr0r
Watchman
Joined: 01 Jul 2004
Posts: 9691
Location: almost Mile High in the USA
|
| Posted: Mon Apr 24, 2017 9:11 pm Post subject: |
|
|
Curious, is this a mechanical disk or SSD?
How long does X start if you start it manually (xinit or startx), not through a display manager?
A lot of these times these inexplicable startup delays are due to hostname lookups that fail due to network being down and the lookup being unnecessary. Ideally you'd remove all these hostname lookups, but it's kind of tough finding which applications are generating these lookups.
You might want to change the topic, this does not sound like an init problem because your login prompt shows up in 20 seconds. By that point init has pretty much done its job, and it's up to the display manager to finish the rest of the startup routine.
_________________
Intel Core i7 2700K/Radeon R7 250/24GB DDR3/256GB SSD
What am I supposed watching? |
|
| Back to top |
|
|
lesnik
n00b
Joined: 04 Oct 2016
Posts: 17
|
| Posted: Tue Apr 25, 2017 3:47 pm Post subject: |
|
|
Thanks for reply!
| eccerr0r wrote: | | Curious, is this a mechanical disk or SSD? |
I have a mechanical disk.
Looks like I have "fixed" this problem. I found description of the problem here: https://bugs.launchpad.net/ubuntu/+source/systemd/+bug/1398458
Two approaches were suggested there. One is to disable CONFIG_FW_LOADER_USER_HELPER in kernel, the other is to create /etc/udev/rules.d/50-firmware.rules file with a following contents:
| Code: | | SUBSYSTEM=="firmware", ACTION=="add", ATTR{loading}="-1" |
First approach did not help me (X would start fast, but the network wouldn't start at all). Second one solved both issues.
I have little understanding what happened 
When I disabled CONFIG_FW_LOADER_USER_HELPER network wouldn't start at all with the following messages in /var/log/messages:
| Code: | Apr 22 22:28:34 glorx530 kernel: [ 1.962533] iwlwifi 0000:03:00.0: Direct firmware load for iwlwifi-6000-6.ucode failed with error -2
Apr 22 22:28:34 glorx530 kernel: [ 1.962832] iwlwifi 0000:03:00.0: Direct firmware load for iwlwifi-6000-5.ucode failed with error -2
Apr 22 22:28:34 glorx530 kernel: [ 1.963128] iwlwifi 0000:03:00.0: Direct firmware load for iwlwifi-6000-4.ucode failed with error -2 |
I assume none of the mentioned firmware's is suitable for my card.
But what the second approach does is that it "Provide's a userspace loader stub which immediately fails" so that there would be no 1 minute timeout between firmware load attempts. Still firmware is somehow found. I can see the attempts to load firmware, but there is no huge timeout:
| Code: |
Apr 22 22:40:32 glorx530 kernel: [ 2.028579] iwlwifi 0000:03:00.0: Direct firmware load for iwlwifi-6000-6.ucode failed with error -2
...
Apr 22 22:40:32 glorx530 kernel: [ 9.921376] iwlwifi 0000:03:00.0: Direct firmware load for iwlwifi-6000-5.ucode failed with error -2
...
Apr 22 22:40:32 glorx530 kernel: [ 10.087401] iwlwifi 0000:03:00.0: loaded firmware version 9.221.4.1 build 25532 op_mode iwldvm |
Where did the suitable firmware come from? No idea. I tried to use `modinfo` command to find this out, but iwlwifi is not actually a module (it's compiled into my kernel), so that wouldn't help. |
|
| Back to top |
|
|
cboldt
Veteran
Joined: 24 Aug 2005
Posts: 1046
|
| Posted: Tue Apr 25, 2017 3:55 pm Post subject: |
|
|
Is there a iwlwifi-6000-6.ucode anyplace on your system?
| Code: | | locate iwlwifi-6000-6.ucode |
Heh ... I just did `locate .ucode`, and there is a whole family of iwlwifi files in /lib/firmware, NONE of them is EXACTLY iwlwifi-6000-6.ucode, but two of them are close (and two are close to iwlwifi-6000-5).
| Code: | /lib/firmware/iwlwifi-6000g2a-5.ucode
/lib/firmware/iwlwifi-6000g2a-6.ucode
/lib/firmware/iwlwifi-6000g2b-5.ucode
/lib/firmware/iwlwifi-6000g2b-6.ucode |
You might be able to get rid of a couple of those error messages and save a few seconds by removing, renaming, or relocating those iwlwif-6000g2* files |
|
| Back to top |
|
|
lesnik
n00b
Joined: 04 Oct 2016
Posts: 17
|
| Posted: Tue Apr 25, 2017 5:26 pm Post subject: |
|
|
| cboldt wrote: | | Heh ... I just did `locate .ucode`, and there is a whole family of iwlwifi files in /lib/firmware, NONE of them is EXACTLY iwlwifi-6000-6.ucode, but two of them are close (and two are close to iwlwifi-6000-5). |
same situation here!
| cboldt wrote: | | You might be able to get rid of a couple of those error messages and save a few seconds by removing, renaming, or relocating those iwlwif-6000g2* files |
This is what I was going to do. But I can't understand which firmware file is good for me! It's not mentioned in logs. |
|
| Back to top |
|
|
cboldt
Veteran
Joined: 24 Aug 2005
Posts: 1046
|
| Posted: Tue Apr 25, 2017 5:48 pm Post subject: |
|
|
iwlwifi firmware version 9.221.4.1 is embodied in iwlwifi-6000-4.ucode
http://linuxwireless.org/en/users/Drivers/iwlwifi/__v24.html
The other iwlwifi microcode files are cruft, on your system. I don't know the mechanism the kernel uses to choose, try, reject, repeat until success, but there is no harm in removing the microcode files your system isn't trying to use. |
|
| Back to top |
|
|
lesnik
n00b
Joined: 04 Oct 2016
Posts: 17
|
| Posted: Tue Apr 25, 2017 6:22 pm Post subject: |
|
|
| cboldt wrote: | | iwlwifi firmware version 9.221.4.1 is embodied in iwlwifi-6000-4.ucode. |
One of the first things I tried was that I copied iwlwifi-6000-4.ucode to iwlwifi-6000-6.ucode (all in /lib/firmware). And it did not help! I still had messages "Direct firmware load for iwlwifi-6000-6.ucode failed with error -2". |
|
| Back to top |
|
|
cboldt
Veteran
Joined: 24 Aug 2005
Posts: 1046
|
| Posted: Tue Apr 25, 2017 6:42 pm Post subject: |
|
|
I think if you want to get rid of the "Direct firmware load for iwlwifi-6000-6.ucode" error messages, you have to remove those files from the /lib/firmware directory. It would be easy to try, just mv them to /root or something.
I have iwlwifi running here (firmware version 18.168.6.1), no error messages, but iwlwifi is a module, not built into the kernel, and it is built to support e1000e. |
|
| Back to top |
|
|
NeddySeagoon
Administrator
Joined: 05 Jul 2003
Posts: 54317
Location: 56N 3W
|
| Posted: Tue Apr 25, 2017 7:32 pm Post subject: |
|
|
lesnik,
When Xorg starts, it wants to talk to itself over the network. When the network is not up, there is a timeout you need to wait.
You will need to wait for it twice, once when Xorg shows you the login screen and again when Xorg is restarted.
The traditional way to fix this is to have an entry in /etc/hosts so name resolution for your hostname always works.
That's not very practical unless you have a static IP.
Edit /etc/rc.conf to add
| Code: | | rc_depend_strict="NO" |
See the comments.
The existing default entry is commented out, so don't just change the existing entry.
This allows the network service to be up before Xorg starts. It will be provided by lo.
Xorg is quite happy to talk to itself on lo, so you save the timeouts.
_________________
Regards,
NeddySeagoon
Computer users fall into two groups:-
those that do backups
those that have never had a hard drive fail. |
|
| Back to top |
|
|
szatox
Advocate
Joined: 27 Aug 2013
Posts: 3151
|
| Posted: Tue Apr 25, 2017 9:26 pm Post subject: |
|
|
| Quote: | The traditional way to fix this is to have an entry in /etc/hosts so name resolution for your hostname always works.
That's not very practical unless you have a static IP. |
I really don't understand this part. Sounds like 127.0.0.1 wasn't static enough.
Also, I'd say that binding X to any interface other than lo is a bad idea.
Well.. Actually I don't get the part regarding launch order of services either. As far as I know, X has always been considered more optional than network. Even before dependency based init systems, network would always start first.
How does now X suddenly start before network and then wait for timeout because network is not ready yet? It's a recipe for a deadlock. |
|
| Back to top |
|
|
eccerr0r
Watchman
Joined: 01 Jul 2004
Posts: 9691
Location: almost Mile High in the USA
|
| Posted: Tue Apr 25, 2017 9:42 pm Post subject: |
|
|
Networkmanager and wifi is (potentially) the problem - since it lets you asynchronously start the network and let other init proceed, including letting you start you gettys and xdm.
Perhaps there should be a requirement for network for xdm, if there is not one already. Then again, it still does not remove the delay as you still have to wait for network.
However: ideally X should not be looking up remote hosts in the first place... at most it should look up localhost which safely can belong in /etc/hosts, then again X authentication cookies and stuff like that is a whole another ball of wax.
_________________
Intel Core i7 2700K/Radeon R7 250/24GB DDR3/256GB SSD
What am I supposed watching? |
|
| Back to top |
|
|
bunder
Bodhisattva
Joined: 10 Apr 2004
Posts: 5934
|
| Posted: Wed Apr 26, 2017 10:26 am Post subject: Re: troubleshoot long init process |
|
|
| lesnik wrote: | | Code: | Apr 19 21:05:03 glorx530 kernel: [ 1.974364] iwlwifi 0000:03:00.0: Direct firmware load for iwlwifi-6000-6.ucode failed with error -2
...
Apr 19 21:05:45 glorx530 kernel: [ 62.482773] iwlwifi 0000:03:00.0: Direct firmware load for iwlwifi-6000-5.ucode failed with error -2
|
As I understand kernel tries to load firmware for my network hardware. Why does it try to load versions 6 and 5? /lib/firmware directory contains iwlwifi-6000-4.ucode. This file was brought by sys-kernel/linux-firmware package. Like I said, it's updated to latest stable version (20161205 at the moment). How can I make sure if the absence of these iwlwifi-firmware files is the reason why network starts for so long? |
known issue, you can fix that by symlinking -6 and -5 to the existing -4. i think this happened because intel intended to release newer firmware for that chip, but never actually did.
| Code: | chris@arrandale ~ $ ls -l /lib/firmware/iwlwifi-6000*
-rw-r--r-- 1 root root 454608 Jan 30 00:17 /lib/firmware/iwlwifi-6000-4.ucode
lrwxrwxrwx 1 root root 20 May 6 2016 /lib/firmware/iwlwifi-6000-5.ucode -> iwlwifi-6000-4.ucode
lrwxrwxrwx 1 root root 20 May 6 2016 /lib/firmware/iwlwifi-6000-6.ucode -> iwlwifi-6000-4.ucode
|
|
|
| Back to top |
|
|
|
|
You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum
You cannot vote in polls in this forum
|
|
Other Things Gentoo
