Bug 723923 - F15 takes 2 additional minutes to boot on AMD Athlon X2
Summary: F15 takes 2 additional minutes to boot on AMD Athlon X2
Keywords:
Status: CLOSED NOTABUG
Alias: None
Product: Fedora
Classification: Fedora
Component: kernel
Version: 15
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Kernel Maintainer List
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2011-07-21 14:50 UTC by Anil Seth
Modified: 2011-10-18 04:13 UTC (History)
6 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2011-10-14 13:35:29 UTC
Type: ---


Attachments (Terms of Use)
Dmesg output with initcall_debug set (122.48 KB, text/plain)
2011-07-22 08:16 UTC, Anil Seth
no flags Details
Dmesg output with rdinitdebug and initcall_debug set (121.41 KB, application/octet-stream)
2011-07-24 16:02 UTC, Anil Seth
no flags Details
Bootchart output when VirtualBox-4.1 is installed. (1.28 MB, image/png)
2011-10-14 09:01 UTC, Anil Seth
no flags Details
Bootchart output after removing VirtualBox-4.1 (944.12 KB, image/png)
2011-10-14 09:03 UTC, Anil Seth
no flags Details

Description Anil Seth 2011-07-21 14:50:29 UTC
Description of problem:
System takes over 2 additional minutes to boot after updating to kernel 2.6.38.8-35

Version-Release number of selected component (if applicable):
2.6.38.8-35

How reproducible:
Almost every time on powering on. However, only on my AMD Athlon(tm) 64 X2 Dual Core Processor 4200+ (2 cpu cores) (version 2.20.00)

It works fine on a Lenovo Netbook with Intel Atom CPUN475.

Steps to Reproduce:
1.Power on the system with kernel 2.6.38.8-35
2.
3.
  
Actual results:
Extract from dmesg:

[   64.343759] multipathd (1870): /proc/1870/oom_adj is deprecated, please use /proc/1870/oom_score_adj instead.
[   65.161650] forcedeth 0000:00:07.0: irq 43 for MSI/MSI-X
[   75.602026] eth0: no IPv6 routers present
[  223.928729] powernow-k8: Found 1 AMD Athlon(tm) 64 X2 Dual Core Processor 4200+ (2 cpu cores) (version 2.20.00)
[  223.928791] powernow-k8:    0 : fid 0xe (2200 MHz), vid 0xe
[  223.928795] powernow-k8:    1 : fid 0xc (2000 MHz), vid 0x10
[  223.928797] powernow-k8:    2 : fid 0xa (1800 MHz), vid 0x10
[  223.928800] powernow-k8:    3 : fid 0x2 (1000 MHz), vid 0x12


Expected results:

Extract from dmesg with kernel 2.6.38.8-32

[   22.512363] multipathd (1868): /proc/1868/oom_adj is deprecated, please use /proc/1868/oom_score_adj instead.
[   23.371884] forcedeth 0000:00:07.0: irq 43 for MSI/MSI-X
[   25.735194] powernow-k8: Found 1 AMD Athlon(tm) 64 X2 Dual Core Processor 4200+ (2 cpu cores) (version 2.20.00)
[   25.735267] powernow-k8:    0 : fid 0xe (2200 MHz), vid 0xe
[   25.735270] powernow-k8:    1 : fid 0xc (2000 MHz), vid 0x10
[   25.735273] powernow-k8:    2 : fid 0xa (1800 MHz), vid 0x10
[   25.735276] powernow-k8:    3 : fid 0x2 (1000 MHz), vid 0x12

Additional info: It appears to be taking a long time to identify the cpu.

Comment 1 Dave Jones 2011-07-22 02:35:48 UTC
can you boot with initcall_debug=1 and attach the dmesg ?
That might show what's happening in more detail.

Comment 2 Anil Seth 2011-07-22 08:16:21 UTC
Created attachment 514639 [details]
Dmesg output with initcall_debug set

Extract from the dmesg file with initcall_debug=1. No call seems to be taking long. So, hope the attached log helps.

[   22.177219] forcedeth 0000:00:07.0: irq 43 for MSI/MSI-X
[   32.346030] eth0: no IPv6 routers present
[  259.078209] calling  powernowk8_init+0x0/0x1bc [powernow_k8] @ 2132
[  259.078226] powernow-k8: Found 1 AMD Athlon(tm) 64 X2 Dual Core Processor 4200+ (2 cpu cores) (version 2.20.00)
[  259.078303] powernow-k8:    0 : fid 0xe (2200 MHz), vid 0xe
[  259.078306] powernow-k8:    1 : fid 0xc (2000 MHz), vid 0x10
[  259.078309] powernow-k8:    2 : fid 0xa (1800 MHz), vid 0x10
[  259.078311] powernow-k8:    3 : fid 0x2 (1000 MHz), vid 0x12
[  259.078598] initcall powernowk8_init+0x0/0x1bc [powernow_k8] returned 0 after 360 usecs

Comment 3 Dave Jones 2011-07-22 17:05:17 UTC
strange, we don't seem to be spending time in the kernel between 32s and 259s.  Try rdinitdebug. Perhaps that will show up something in the userspace initramfs.

Comment 4 Anil Seth 2011-07-24 16:02:11 UTC
Created attachment 514925 [details]
Dmesg output with rdinitdebug and initcall_debug set

Stranger still. The problem seems to disappear with rdinitdebug! 

[   22.882568] forcedeth 0000:00:07.0: irq 43 for MSI/MSI-X
[   24.968829] calling  powernowk8_init+0x0/0x1bc [powernow_k8] @ 2100
[   24.968844] powernow-k8: Found 1 AMD Athlon(tm) 64 X2 Dual Core Processor 4200+ (2 cpu cores) (version 2.20.00)

I have checked it a couple of times but will keep checking in case it shows up with rdinitdebug, If so, I will submit another dmesg log.

Comment 5 Josh Boyer 2011-10-11 15:52:06 UTC
Does this still happen with the 2.6.40.6 kernel update?

Comment 6 Anil Seth 2011-10-12 17:38:40 UTC
Sadly, yes. Dmesg extract:


[   18.663927] EXT4-fs (sda7): mounted filesystem with ordered data mode. Opts: (null)
[   19.499608] /usr/sbin/gpm[1793]: *** info [daemon/startup.c(136)]:
[   19.499622] /usr/sbin/gpm[1793]: Started gpm successfully. Entered daemon mode.
[   23.052986] ip6_tables: (C) 2000-2006 Netfilter Core Team
[   23.079778] multipathd (1893): /proc/1893/oom_adj is deprecated, please use /proc/1893/oom_score_adj instead.
[   23.320150] nf_conntrack version 0.5.0 (16384 buckets, 65536 max)
[   23.955204] forcedeth 0000:00:07.0: irq 43 for MSI/MSI-X
[   34.594020] eth0: no IPv6 routers present
[  105.500883] powernow-k8: Found 1 AMD Athlon(tm) 64 X2 Dual Core Processor 4200+ (2 cpu cores) (version 2.20.00)
[  105.500944] powernow-k8: fid 0xe (2200 MHz), vid 0xe
[  105.500947] powernow-k8: fid 0xc (2000 MHz), vid 0x10
[  105.500949] powernow-k8: fid 0xa (1800 MHz), vid 0x10
[  105.500951] powernow-k8: fid 0x2 (1000 MHz), vid 0x12

But now the symptoms seem to be present even with kernel options rdinitdebug initcall_debug=1

[   22.788681] calling  ip6_tables_init+0x0/0xaa [ip6_tables] @ 1898
[   22.788718] ip6_tables: (C) 2000-2006 Netfilter Core Team
[   22.788725] initcall ip6_tables_init+0x0/0xaa [ip6_tables] returned 0 after 33 usecs
[   22.881220] calling  ip6table_filter_init+0x0/0x6c [ip6table_filter] @ 1900
[   22.881255] initcall ip6table_filter_init+0x0/0x6c [ip6table_filter] returned 0 after 25 usecs
[   22.956126] calling  nf_conntrack_standalone_init+0x0/0x12 [nf_conntrack] @ 1903
[   22.956136] nf_conntrack version 0.5.0 (16384 buckets, 65536 max)
[   22.956570] initcall nf_conntrack_standalone_init+0x0/0x12 [nf_conntrack] returned 0 after 418 usecs
[   22.960901] calling  state_mt_init+0x0/0x12 [xt_state] @ 1903
[   22.960912] initcall state_mt_init+0x0/0x12 [xt_state] returned 0 after 2 usecs
[   22.973751] multipathd (1896): /proc/1896/oom_adj is deprecated, please use /proc/1896/oom_score_adj instead.
[   23.138626] calling  nf_defrag_init+0x0/0x51 [nf_defrag_ipv6] @ 1905
[   23.138656] initcall nf_defrag_init+0x0/0x51 [nf_defrag_ipv6] returned 0 after 19 usecs
[   23.144845] calling  nf_conntrack_l3proto_ipv6_init+0x0/0xfa [nf_conntrack_ipv6] @ 1905
[   23.144878] initcall nf_conntrack_l3proto_ipv6_init+0x0/0xfa [nf_conntrack_ipv6] returned 0 after 24 usecs
[   23.328360] calling  reject_tg6_init+0x0/0x12 [ip6t_REJECT] @ 1914
[   23.328374] initcall reject_tg6_init+0x0/0x12 [ip6t_REJECT] returned 0 after 3 usecs
[   23.835191] forcedeth 0000:00:07.0: irq 43 for MSI/MSI-X
[   33.930019] eth0: no IPv6 routers present
[  105.478112] calling  powernowk8_init+0x0/0x1b7 [powernow_k8] @ 2345
[  105.478128] powernow-k8: Found 1 AMD Athlon(tm) 64 X2 Dual Core Processor 4200+ (2 cpu cores) (version 2.20.00)
[  105.478182] powernow-k8: fid 0xe (2200 MHz), vid 0xe
[  105.478185] powernow-k8: fid 0xc (2000 MHz), vid 0x10
[  105.478187] powernow-k8: fid 0xa (1800 MHz), vid 0x10
[  105.478189] powernow-k8: fid 0x2 (1000 MHz), vid 0x12
[  105.478427] initcall powernowk8_init+0x0/0x1b7 [powernow_k8] returned 0 after 297 usecs

By looking at the extract from the messages log, could it be somehow related to rpc?

Oct 12 22:53:40 amd rpc.statd[2352]: Version 1.2.4 starting
Oct 12 22:53:40 amd kernel: [  105.478128] powernow-k8: Found 1 AMD Athlon(tm) 64 X2 Dual Core Processor 4200+ (2 cpu cores)
 (version 2.20.00)
Oct 12 22:53:40 amd kernel: [  105.478182] powernow-k8: fid 0xe (2200 MHz), vid 0xe
Oct 12 22:53:40 amd kernel: [  105.478185] powernow-k8: fid 0xc (2000 MHz), vid 0x10
Oct 12 22:53:40 amd kernel: [  105.478187] powernow-k8: fid 0xa (1800 MHz), vid 0x10
Oct 12 22:53:40 amd kernel: [  105.478189] powernow-k8: fid 0x2 (1000 MHz), vid 0x12
Oct 12 22:53:40 amd kernel: [  105.676523] RPC: Registered named UNIX socket transport module.

Thanks & regards
Anil

Comment 7 Josh Boyer 2011-10-13 15:39:19 UTC
At the point where it hangs, the initramfs code has already switched to the on-disk rootfs so it's not hanging there.  It doesn't seem to really be hanging in the kernel itself, as Dave pointed out in comment #3.

Do you think you could install bootchart and get the output of a boot with that?  Perhaps a service is hanging waiting on something.

Comment 8 Anil Seth 2011-10-14 09:00:08 UTC
Thanks for the pointer. Bootchart creates very pretty pictures - nice to learn something new.

Looking at the picture, I recalled one of the kernel developers complaining about virtualbox driver. The system seemed to be taking a long time in ltspfs-entry.

Decided to un-install virtualbox-4.1 and the system now boots in 54 sec! 

I will attach the png files with virtualbox installed and after removing it in case it is of interest to anyone.

Comment 9 Anil Seth 2011-10-14 09:01:45 UTC
Created attachment 528174 [details]
Bootchart output when VirtualBox-4.1 is installed.

Comment 10 Anil Seth 2011-10-14 09:03:04 UTC
Created attachment 528175 [details]
Bootchart output after removing VirtualBox-4.1

Comment 11 Josh Boyer 2011-10-14 13:35:29 UTC
Thank you for the information.  This doesn't appear to be a kernel issue, as we've said before.  Given that things boot normally without VirtualBox installed, I'm going to close this bug out.  I've CC'd Frank from the VirtualBox team so they are aware.  You might want to discuss the issue with that team.

Comment 12 Frank Mehnert 2011-10-14 14:58:09 UTC
So far unable to reproduce. Have Fedora 15 here with VirtualBox 4.1.4 installed and it boots fine. Looks like a non-standard configuration but we will further try to analyze the problem.

Comment 13 Frank Mehnert 2011-10-14 15:00:51 UTC
Anil, do you have VirtualBox 4.1 on the Lenovo netbook installed as well? If so, can you provide any comments if the configuration of the Lenovo netbook differs from the AMD box?

Comment 14 Anil Seth 2011-10-15 04:30:07 UTC
Frank,

I tried VirtualBox 4.1 on Lenovo and no issues. Aside from more applications and services being installed (from the common Fedora repositories) on AMD desktop, there is no substantial difference in the two installations.

I was curious and tried VirtualBox 4.0 on the AMD machine and no problems! In the bootchart, the difference somehow seems to lie in the ltspfs_entry.

If there is any more information/data I can provide, I will be happy to file a bug report on the VirtualBox site. The 

Thanks

Comment 15 Frank Mehnert 2011-10-17 09:47:15 UTC
Anil, thanks for the additional information. It is still totally mysterious to us why it took so much longer to boot your AMD box when you had VirtualBox 4.1 installed. The ltspfs daemon seems to wait for the network interface getting up. But at this time it is actually too early to blame the VirtualBox modules so we think the problem you had vanished only by coincidence when you uninstalled VirtualBox 4.1.

If you have some minutes it would be a helpful test if you could try the following: Uninstall VirtualBox 4.0 and reinstall VirtualBox 4.1, then reboot to test if you get the long boot time again. Thanks in advance!

Comment 16 Anil Seth 2011-10-18 04:13:33 UTC
Frank, you are probably right that it was a coincidence. I replaced VirtualBox 4.0 by 4.1 and the problem hasn't shown up on 3 reboots. I hope whatever it was, it stays away.


Note You need to log in before you can comment on or make changes to this bug.