View previous topic :: View next topic |
Author |
Message |
Adel Ahmed Veteran
Joined: 21 Sep 2012 Posts: 1510
|
Posted: Sat May 25, 2013 6:50 pm Post subject: very long boot process |
|
|
gentoo starts in 37 seconds(not counting bios and grub)
the process generally takes 18 seconds until gnome starts loading whcih takes up the rest
I looked around for a bit and tried many solutions like modularizing unnecessary components of the kernel(wasn't helpful at all), starting service in parallel, disabling some services from the default and boot time...etc
here's my boot tree:
alsasound | boot
bootmisc | boot
dbus | default
devfs | sysinit
dmesg | sysinit
fsck | boot
hostname | boot
killprocs | shutdown
local | default
localmount | boot
modules | boot
mount-ro | shutdown
mtab | boot
net.lo | boot
procfs | boot
root | boot
savecache | shutdown
sshd | default
swapfiles | boot
sysctl | boot
sysfs | sysinit
termencoding | boot
tmpfiles.setup | boot
udev | sysinit
udev-mount | sysinit
urandom | boot
wicd | boot
xdm | boot
and here's my rc.log:
http://pastebin.com/mDSy953g
I'm open to suggestions
thanks in advance |
|
Back to top |
|
|
_______0 Guru
Joined: 15 Oct 2012 Posts: 521
|
Posted: Sat May 25, 2013 7:09 pm Post subject: |
|
|
try fluxbox or other light windows manager. |
|
Back to top |
|
|
Adel Ahmed Veteran
Joined: 21 Sep 2012 Posts: 1510
|
Posted: Tue May 28, 2013 3:38 pm Post subject: |
|
|
well the gnome panel doesn't work well with other window managers
I'll try working things out with the panel but I'll look for other things to speed up the boot process for now |
|
Back to top |
|
|
Ant P. Watchman
Joined: 18 Apr 2009 Posts: 6920
|
Posted: Tue May 28, 2013 7:33 pm Post subject: |
|
|
You might find app-benchmarks/bootchart2 and sys-fs/e4rat useful. One will show you where the slowness is coming from, the other preloads files for the boot process (and can optionally defragment them). |
|
Back to top |
|
|
Adel Ahmed Veteran
Joined: 21 Sep 2012 Posts: 1510
|
Posted: Tue Jun 04, 2013 10:28 am Post subject: |
|
|
I have problems with the /proc/kmsg so i cannot audit my system |
|
Back to top |
|
|
creaker l33t
Joined: 14 Jul 2012 Posts: 651
|
Posted: Tue Jun 04, 2013 7:39 pm Post subject: |
|
|
What a hardware do you use? How fast is your drive (hdparm -tT)?
18 secs until starting gnome is not a very bad if you do not using ssd drive, but 20 secs for gnome starting - it is too much.
I think it is not a kernel/modules issue. |
|
Back to top |
|
|
Adel Ahmed Veteran
Joined: 21 Sep 2012 Posts: 1510
|
Posted: Wed Jun 05, 2013 6:32 am Post subject: |
|
|
hdparm indicates bu buffered write speed is 55 mb/s ~
I agree the boot process itself is not so bad, must be something with gnome
Ill try looking around gnome and see if something seems to be taking up all htis time |
|
Back to top |
|
|
creaker l33t
Joined: 14 Jul 2012 Posts: 651
|
Posted: Wed Jun 05, 2013 8:32 am Post subject: |
|
|
It is a very fast boot for 55 mb/s read speed disk.
Especially since you are using bloated gnome (assuming it is gnome3).
You can try to reduce your 37 secs, try out e4rat. For slow disks it gives a good improvement. |
|
Back to top |
|
|
Adel Ahmed Veteran
Joined: 21 Sep 2012 Posts: 1510
|
Posted: Wed Jun 05, 2013 8:35 am Post subject: |
|
|
well e4rat failed to audit my system(problems with proc/kmsg)
I'm using gnome 2.3 and Ive emerge the lightpackage gnome-light |
|
Back to top |
|
|
Adel Ahmed Veteran
Joined: 21 Sep 2012 Posts: 1510
|
Posted: Wed Jun 05, 2013 8:51 am Post subject: |
|
|
well i though thee problem was I didnt't have have kmsg compiled in my kernel
after adding kmsg I'm still getting this error:
Cannot open audit socket
Press 'Ctrl-C' to stop collecting files
Cannot disable audit socket
Cannot disable current pid
0 file(s) collected
Cannot dump log messages: /dev/kmsg: Bad file descriptor
Discard 3 unwritten log message(s). |
|
Back to top |
|
|
TomWij Retired Dev
Joined: 04 Jul 2012 Posts: 1553
|
Posted: Thu Jun 06, 2013 6:05 pm Post subject: |
|
|
Please paste the output of `dmesg -d` so we can look into your kernel; as for the boot, please produce a bootchart2 image.
If you experience any bugs in producing this information (eg. /dev/kmsg) please report these at our Bugzilla (https://bugs.gentoo.org). |
|
Back to top |
|
|
Adel Ahmed Veteran
Joined: 21 Sep 2012 Posts: 1510
|
|
Back to top |
|
|
TomWij Retired Dev
Joined: 04 Jul 2012 Posts: 1553
|
Posted: Thu Jun 06, 2013 7:18 pm Post subject: |
|
|
I see you have systemd, can you run `systemd-analyze blame` and `systemd-analyze critical-chain`; for more details you can opt to run `systemd-analyze plot` and `systemd-analyze dot`, though running the former critical-chain command after optimizing something makes the latter two unnecessary (they are more handy for a good overview).
Quote: | [ 1.598220 < 0.073749>] EXT4-fs (sda2): INFO: recovery required on readonly filesystem
[ 1.598224 < 0.000004>] EXT4-fs (sda2): write access will be enabled during recovery
...
[ 3.661687 < 1.490165>] EXT4-fs (sda2): orphan cleanup on readonly fs
[ 3.661696 < 0.000009>] EXT4-fs (sda2): ext4_orphan_cleanup: deleting unreferenced inode 131679
[ 3.661770 < 0.000074>] EXT4-fs (sda2): ext4_orphan_cleanup: deleting unreferenced inode 131621
[ 3.661826 < 0.000056>] EXT4-fs (sda2): ext4_orphan_cleanup: deleting unreferenced inode 525038
[ 3.661874 < 0.000048>] EXT4-fs (sda2): ext4_orphan_cleanup: deleting unreferenced inode 524964
[ 3.661890 < 0.000016>] EXT4-fs (sda2): ext4_orphan_cleanup: deleting unreferenced inode 131495
[ 3.661934 < 0.000044>] EXT4-fs (sda2): ext4_orphan_cleanup: deleting unreferenced inode 131489
[ 3.661952 < 0.000018>] EXT4-fs (sda2): ext4_orphan_cleanup: deleting unreferenced inode 131480
[ 3.661974 < 0.000022>] EXT4-fs (sda2): ext4_orphan_cleanup: deleting unreferenced inode 131152
[ 3.661982 < 0.000008>] EXT4-fs (sda2): ext4_orphan_cleanup: deleting unreferenced inode 524833
[ 3.661998 < 0.000016>] EXT4-fs (sda2): ext4_orphan_cleanup: deleting unreferenced inode 524787
[ 3.662023 < 0.000025>] EXT4-fs (sda2): 10 orphan inodes deleted
[ 3.662025 < 0.000002>] EXT4-fs (sda2): recovery complete
[ 3.806241 < 0.144216>] EXT4-fs (sda2): mounted filesystem with ordered data mode. Opts: (null) |
First concern is that there is a cleanup going on on your ext4, you probably wil want to investigate this if this happens every boot; possibly start a separate topic about it if Google doesn't yield details. I'm not sure how the messages are positioned in time relative to the cleanup, but it appears almost two seconds are lost around here, the orphan cleanup itself indicating it took 1.490165 seconds.
Quote: | [ 0.156993 < 0.000810>] libata version 3.00 loaded.
[ 0.287117 < 0.000092>] ata1: SATA max UDMA/133 abar m2048@0xf4504000 port 0xf4504100 irq 46
[ 0.287121 < 0.000004>] ata2: SATA max UDMA/133 abar m2048@0xf4504000 port 0xf4504180 irq 46
[ 0.287123 < 0.000002>] ata3: DUMMY
[ 0.287124 < 0.000001>] ata4: DUMMY
[ 0.593112 < 0.140973>] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
[ 0.621395 < 0.028283>] ata1.00: ATA-8: WDC WD3200BEVS-08VAT2, 14.01A14, max UDMA/133
[ 0.621400 < 0.000005>] ata1.00: 625142448 sectors, multi 16: LBA48 NCQ (depth 31/32), AA
[ 0.623959 < 0.002559>] ata1.00: configured for UDMA/133
[ 0.929122 < 0.191090>] ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
[ 0.932698 < 0.003576>] ata2.00: ATAPI: HL-DT-ST DVDRAM GSA-T50N, RV06, max UDMA/133
[ 0.937539 < 0.004841>] ata2.00: configured for UDMA/133 |
At least half of a second is lost by synchroneously probing your drives, since you only have one HDD and one DVD drive this can be done asynchroneously.
The reason this is synchroneously is because on systems with much more drives spinning them up all at once can possibly cause a power spike;
I have two HDDs and one DVD drive and have this asynchroneously myself, I have not experienced any problems and it made my boot a bit faster.
You can turn this from synchrneously to asynchroneously using `sed -e 's/ahci_ignore_sss/true/g' -i /usr/src/linux/drivers/ata/ahci.c`.
Quote: | [ 0.157000 < 0.000007>] ACPI: bus type usb registered
[ 0.157011 < 0.000011>] usbcore: registered new interface driver usbfs
[ 0.157011 < 0.000000>] usbcore: registered new interface driver hub
[ 0.157011 < 0.000000>] usbcore: registered new device driver usb
[ 0.322563 < 0.000060>] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[ 0.322599 < 0.000007>] ehci_hcd 0000:00:1a.7: new USB bus registered, assigned bus number 1
[ 0.332018 < 0.005402>] ehci_hcd 0000:00:1a.7: USB 2.0 started, EHCI 1.00
[ 0.332210 < 0.000192>] hub 1-0:1.0: USB hub found
[ 0.332215 < 0.000005>] hub 1-0:1.0: 6 ports detected
[ 0.332301 < 0.000006>] ehci_hcd 0000:00:1d.7: new USB bus registered, assigned bus number 2
[ 0.342015 < 0.005792>] ehci_hcd 0000:00:1d.7: USB 2.0 started, EHCI 1.00
[ 0.342164 < 0.000149>] hub 2-0:1.0: USB hub found
[ 0.342169 < 0.000005>] hub 2-0:1.0: 6 ports detected
[ 0.342262 < 0.000093>] uhci_hcd: USB Universal Host Controller Interface driver
[ 0.342291 < 0.000006>] uhci_hcd 0000:00:1a.0: new USB bus registered, assigned bus number 3
[ 0.342497 < 0.000170>] hub 3-0:1.0: USB hub found
[ 0.342502 < 0.000005>] hub 3-0:1.0: 2 ports detected
[ 0.342571 < 0.000005>] uhci_hcd 0000:00:1a.1: new USB bus registered, assigned bus number 4
[ 0.342775 < 0.000169>] hub 4-0:1.0: USB hub found
[ 0.342779 < 0.000004>] hub 4-0:1.0: 2 ports detected
[ 0.342847 < 0.000005>] uhci_hcd 0000:00:1a.2: new USB bus registered, assigned bus number 5
[ 0.343050 < 0.000174>] hub 5-0:1.0: USB hub found
[ 0.343054 < 0.000004>] hub 5-0:1.0: 2 ports detected
[ 0.343126 < 0.000005>] uhci_hcd 0000:00:1d.0: new USB bus registered, assigned bus number 6
[ 0.343315 < 0.000163>] hub 6-0:1.0: USB hub found
[ 0.343320 < 0.000005>] hub 6-0:1.0: 2 ports detected
[ 0.343394 < 0.000006>] uhci_hcd 0000:00:1d.1: new USB bus registered, assigned bus number 7
[ 0.343595 < 0.000164>] hub 7-0:1.0: USB hub found
[ 0.343600 < 0.000005>] hub 7-0:1.0: 2 ports detected
[ 0.343667 < 0.000005>] uhci_hcd 0000:00:1d.2: new USB bus registered, assigned bus number 8
[ 0.343866 < 0.000162>] hub 8-0:1.0: USB hub found
[ 0.343871 < 0.000005>] hub 8-0:1.0: 2 ports detected
[ 0.406073 < 0.000911>] usbcore: registered new interface driver usbhid
[ 0.406075 < 0.000002>] usbhid: USB HID core driver
[ 0.738032 < 0.104777>] usb 1-5: new high-speed USB device number 3 using ehci_hcd
[ 1.007048 < 0.069509>] usb 2-3: new high-speed USB device number 2 using ehci_hcd
[ 1.632059 < 0.033835>] usb 3-1: new full-speed USB device number 2 using uhci_hcd
[ 2.001050 < 0.368991>] usb 5-2: new low-speed USB device number 2 using uhci_hcd
[ 2.171306 < 0.170256>] input: USB Mouse as /devices/pci0000:00/0000:00:1a.2/usb5/5-2/5-2:1.0/input/input6
[ 2.171522 < 0.000216>] hid-generic 0003:15D9:0A33.0001: input,hidraw0: USB HID v1.10 Mouse [USB Mouse] on usb-0000:00:1a.2-2/input0 |
If you don't need USB in order to mount root, you can make sure everything that is USB related is a module so it loads after the kernel mounts root; you likely win half a second here. Generally making things modules instead of built-in where you can is good advice; since I don't directly see something else that spares at least half a second, I suggest you to turn things into modules to win another half second.
So, that covers how you can turn the kernel down to almost under a second; if you share the other information (remember the suggested commands at the top of this post) we can look into the rest. |
|
Back to top |
|
|
TomWij Retired Dev
Joined: 04 Jul 2012 Posts: 1553
|
Posted: Thu Jun 06, 2013 7:21 pm Post subject: |
|
|
Ah, I see you have edited your post; for the bootchart image, there's something going wrong there not covering your entire boot, unless you can fix that please run the systemd suggestions from my previous post instead. |
|
Back to top |
|
|
Adel Ahmed Veteran
Joined: 21 Sep 2012 Posts: 1510
|
Posted: Thu Jun 06, 2013 7:31 pm Post subject: |
|
|
the ext4 was just a coincidence because there was a power outage
I can't run the above command , and emerging systemd will result in udev being removed
ill try modularizeing everything usb related, I also enabled asynchronous driver probing
my boot is now at:
37 seconds
another question though
i thought loading modules was slower if you are going to load the module everytime you boot.
also would an initrd be faster? I've tried one before and it was extremely slow, just thought Id check though |
|
Back to top |
|
|
TomWij Retired Dev
Joined: 04 Jul 2012 Posts: 1553
|
Posted: Thu Jun 06, 2013 7:53 pm Post subject: |
|
|
blakdeath wrote: | the ext4 was just a coincidence because there was a power outage |
Ouch, I see.
blakdeath wrote: | I can't run the above command , and emerging systemd will result in udev being removed |
Oh right, that's just udev I'm seeing; yeah, since systemd comes with udev you'd have to unmerge the standalone udev.
blakdeath wrote: | ill try modularizeing everything usb related, I also enabled asynchronous driver probing
my boot is now at:
37 seconds |
Yeah, that's as far as the kernel goes; most seems to be attributable to the rest of your boot, without more troubleshooting information it's hard to know where the issue lies.
blakdeath wrote: | another question though
i thought loading modules was slower if you are going to load the module everytime you boot.
also would an initrd be faster? I've tried one before and it was extremely slow, just thought Id check though |
Loading modules is asynchroneous, by building into the kernel you force them to be loaded before the (re)mount of the root partition; by doing this in the initrd, it gets even worse.
Though, the majority of time that can be improved is after the kernel; I hope you can obtain troubleshooting information for that. |
|
Back to top |
|
|
Adel Ahmed Veteran
Joined: 21 Sep 2012 Posts: 1510
|
Posted: Fri Jun 07, 2013 12:41 am Post subject: |
|
|
well thanks for all your help so far, I still believe gnome is the main reason this process takes alot of time
so Ill start looking around gnome services and config files |
|
Back to top |
|
|
|