[btrfs] slow boot

[sk]

Bootup from power on to login prompt takes several minutes. In the bootchart I can see that there is sometimes a lot of IO while other times there is no cpu usage and no io. I cannot identify the reason for this. Several updates doesn't change anything. I assumed that upstart will boot rather fast.

ProblemType: Bug
DistroRelease: Ubuntu 13.04
Package: linux-image-3.8.0-29-generic 3.8.0-29.42
ProcVersionSignature: Ubuntu 3.8.0-29.42-generic 3.8.13.5
Uname: Linux 3.8.0-29-generic x86_64
ApportVersion: 2.9.2-0ubuntu8.3
Architecture: amd64
AudioDevicesInUse:
 USER PID ACCESS COMMAND
 /dev/snd/controlC0: sk 2509 F.... pulseaudio
 /dev/snd/pcmC0D0p: sk 2509 F...m pulseaudio
CRDA:
 country DE:
  (2400 - 2483 @ 40), (N/A, 20)
  (5150 - 5250 @ 40), (N/A, 20), NO-OUTDOOR
  (5250 - 5350 @ 40), (N/A, 20), NO-OUTDOOR, DFS
  (5470 - 5725 @ 40), (N/A, 26), DFS
Date: Thu Aug 29 21:03:20 2013
HibernationDevice: RESUME=UUID=5274008d-3a15-49c7-a73b-fa52766ce0f6
InstallationDate: Installed on 2011-01-25 (946 days ago)
InstallationMedia: Ubuntu 10.10 "Maverick Meerkat" - Release amd64 (20101007)
MachineType: MICRO-STAR INTERNATIONAL CO.,LTD MS-7501
MarkForUpload: True
ProcFB: 0 radeondrmfb
ProcKernelCmdLine: BOOT_IMAGE=/vmlinuz-3.8.0-29-generic root=UUID=c726ed97-45de-4169-bdcd-781676da75cf ro nosplash
RelatedPackageVersions:
 linux-restricted-modules-3.8.0-29-generic N/A
 linux-backports-modules-3.8.0-29-generic N/A
 linux-firmware 1.106
RfKill:
 0: phy0: Wireless LAN
  Soft blocked: no
  Hard blocked: no
SourcePackage: linux
UpgradeStatus: Upgraded to raring on 2013-05-03 (118 days ago)
dmi.bios.date: 09/02/2008
dmi.bios.vendor: American Megatrends Inc.
dmi.bios.version: V1.5B1
dmi.board.asset.tag: To Be Filled By O.E.M.
dmi.board.name: MS-7501
dmi.board.vendor: MICRO-STAR INTERNATIONAL CO.,LTD
dmi.board.version: 1.0
dmi.chassis.asset.tag: To Be Filled By O.E.M.
dmi.chassis.type: 3
dmi.chassis.vendor: MICRO-STAR INTERNATIONAL CO.,LTD
dmi.chassis.version: 1.0
dmi.modalias: dmi:bvnAmericanMegatrendsInc.:bvrV1.5B1:bd09/02/2008:svnMICRO-STARINTERNATIONALCO.,LTD:pnMS-7501:pvr1.0:rvnMICRO-STARINTERNATIONALCO.,LTD:rnMS-7501:rvr1.0:cvnMICRO-STARINTERNATIONALCO.,LTD:ct3:cvr1.0:
dmi.product.name: MS-7501
dmi.product.version: 1.0
dmi.sys.vendor: MICRO-STAR INTERNATIONAL CO.,LTD

[Joseph Salisbury (jsalisbury)]

Did this issue start happening after an update/upgrade? Was there a kernel version where you were not having this particular problem? This will help determine if the problem you are seeing is the result of the introduction of a regression, and when this regression was introduced. If this is a regression, we can perform a kernel bisect to identify the commit that introduced the problem.

[Brad Figg (brad-figg)]

This change was made by a bot.

[sk (s-karrmann)]

This issue starts long ago, maybe even at the first ubuntu version I used. That was about 2011-04 or earlier.

[Steve Langasek (vorlon)]

your bootchart shows:

- blkid takes 29 seconds to identify your root filesystem from the initramfs.
- the initramfs spends another 5 seconds looking for a hibernate image on swap. It doesn't find it, presumably either because the wrong UUID is encoded in /etc/initramfs-tools or because the initramfs is having trouble finding your swap partition too.
- Once booted to the rootfs, it takes 15 seconds for the system to run an fsck on an ext3 partition.
- ... and then it takes another 6 seconds to mount it.

udev doesn't even start until 59 seconds after boot, and then its helpers again spend a lot of time in disk I/O for simple tasks.

None of this points to an upstart problem. You either have a broken/failing/slow disk, or you have some other kernel issue slowing things down.

It appears that you are running btrfs, with a very complicated partition scheme (29 partitions on sda, 20 on sdb?) Since the partition detection works without a hitch, I suspect your problem is that the btrfs volumes have gotten themselves into an unholy state and are slowing the system down.

[sk (s-karrmann)]

My speed tests shows:

# hdparm -tT /dev/sd[ab]

/dev/sda:
 Timing cached reads: 1544 MB in 2.00 seconds = 771.83 MB/sec
 Timing buffered disk reads: 170 MB in 3.02 seconds = 56.28 MB/sec

/dev/sdb:
 Timing cached reads: 956 MB in 2.00 seconds = 477.70 MB/sec
 Timing buffered disk reads: 106 MB in 3.04 seconds = 34.91 MB/sec