Description of problem: Kernel takes over 9 seconds to boot.
Version-Release number of selected component (if applicable): 3.12.7-300, 3.11.10-301
How reproducible: Always
Steps to Reproduce:
1. Boot laptop
2. After login, type 'systemd-analyze' at cmd prompt.
Actual results: Shows approx 9.8 seconds for kernel
Expected results: 1-2 seconds for kernel
Additional info: This is not a regression on the two kernels mentioned above - it has always been slow on this laptop (approx 2 months old).
Booting with 'acpi_no_auto_ssdt' resolves the boot time issue, but the laptop won't sleep when lid shut.
Created attachment 852430 [details]
Output of dmesg
I installed 'kernel-debug' in order to try and use the acpi.debug_level and acpi.debug_layer, but strangely enough, when I boot with this kernel there is no delay!
I've rebooted many times in succession and the result is the same - normal kernel has a delay, while the debug kernel doesn't. This is with the 3.12.8-300 kernel which arrived today on my laptop.
Could you show dmesg on debug-kernel and on normal kernel with acpi_no_auto_ssdt option ?
Created attachment 855155 [details]
dmesg for normal kernel with acpi_no_auto_ssdt option
Created attachment 855156 [details]
dmesg for debug kernel with acpi_no_auto_ssdt option
I could not find reason of the delay examining source code (ACPICA is terrible mess). Let's try to debug it.
I build standard kernel with just CONFIG_ACPI_DEBUG=y, since all other debug options are disabled, perhaps bug will manifest itself on that kernel:
If bug is reproducible on it, please provide log output with "acpi.debug_layer=0xffffffff acip.debug_level=0x0307ff4f" . If that will generate too match or too less output, we will have to tune those mask, but for now let's try them.
I've managed to install the kernel and boot with it. I had to set log_buf_len=128M to get data (32M was too small - 64M might have worked).
I had to zip the dmesg file to make it under the 20000Kb limit, but even then, it failed to upload. I've therefore uploaded the zip to my Dropbox account. It is available here:- https://dl.dropboxusercontent.com/u/90149727/dmesg.zip
It consists of the dmesg as you requested and dmesg with no extra boot parameters. I've been using 'grep Interpreter\ Enabled' to spot the delay. You'll notice that there is a delay of about 6 seconds on the standard boot but no delay with the boot options you requested (presumably the 1.8 seconds is due to the extra logging). In desperation, I tried booting with acpi.debug_level and acpi.debug_layer set to 0x0, but that still had the delay.
If you need any more info, just shout!
Thanks for the logs. I hoped that verbose prints will show us where the delay is, but unfortunately they do not. It looks like this is strange race condition, not reproducible if we enable debugging, i.e. when slow down execution of some functions. Let's try to debug mutexes only, perhaps this give some more light on the issue. Please provide logs with "acpi.debug_layer=0xffffffff acip.debug_level=0x03000000"
All done. As before, dmesg is zipped and available at https://dl.dropboxusercontent.com/u/90149727/dmesg_mutex.zip
Unfortunately it does not show reason of delay. I'm run out of ideas now, let's report problem to upstream maintainers. They might ask you to install upstream vanilla kernel test patches (or even do bisection maybe), but I not see any other chance to fix the problem. I'll write email to proper maintainers and CC you.
Thank you for all your help so far. I've been contemplating installing another distro as a dual-boot in order to check this. I'll go ahead and install Arch Linux and see what happens there. I believe that they use vanilla kernels in Arch, so that may shed a light on the issue.
*********** MASS BUG UPDATE **************
We apologize for the inconvenience. There is a large number of bugs to go through and several of them have gone stale. Due to this, we are doing a mass bug update across all of the Fedora 20 kernel bugs.
Fedora 20 has now been rebased to 3.14.4-200.fc20. Please test this kernel update (or newer) and let us know if you issue has been resolved or if it is still present with the newer kernel.
If you experience different issues, please open a new bug report for those.
I've just booted with kernel 3.14.4-200 and the kernel took 7.562 seconds. dmesg showed the delay of 5 seconds at the same point, so the newer kernel hasn't fixed the issue.
Bug 70891 hasn't been worked on for two months. I've asked for an update...
After some great support from Lv Zheng, the upstream bug has been marked as RESOLVED_CODE_FIX and will no doubt filter it's way down to Fedora sometime soon.
Thanks for all your help.