Gentoo Forums
Gentoo Forums
Gentoo Forums
Quick Search: in
very long boot process
View unanswered posts
View posts from last 24 hours

 
Reply to topic    Gentoo Forums Forum Index Other Things Gentoo
View previous topic :: View next topic  
Author Message
Adel Ahmed
Veteran
Veteran


Joined: 21 Sep 2012
Posts: 1510

PostPosted: Sat May 25, 2013 6:50 pm    Post subject: very long boot process Reply with quote

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
View user's profile Send private message
_______0
Guru
Guru


Joined: 15 Oct 2012
Posts: 521

PostPosted: Sat May 25, 2013 7:09 pm    Post subject: Reply with quote

try fluxbox or other light windows manager.
Back to top
View user's profile Send private message
Adel Ahmed
Veteran
Veteran


Joined: 21 Sep 2012
Posts: 1510

PostPosted: Tue May 28, 2013 3:38 pm    Post subject: Reply with quote

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
View user's profile Send private message
Ant P.
Watchman
Watchman


Joined: 18 Apr 2009
Posts: 6920

PostPosted: Tue May 28, 2013 7:33 pm    Post subject: Reply with quote

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
View user's profile Send private message
Adel Ahmed
Veteran
Veteran


Joined: 21 Sep 2012
Posts: 1510

PostPosted: Tue Jun 04, 2013 10:28 am    Post subject: Reply with quote

I have problems with the /proc/kmsg so i cannot audit my system
Back to top
View user's profile Send private message
creaker
l33t
l33t


Joined: 14 Jul 2012
Posts: 651

PostPosted: Tue Jun 04, 2013 7:39 pm    Post subject: Reply with quote

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
View user's profile Send private message
Adel Ahmed
Veteran
Veteran


Joined: 21 Sep 2012
Posts: 1510

PostPosted: Wed Jun 05, 2013 6:32 am    Post subject: Reply with quote

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
View user's profile Send private message
creaker
l33t
l33t


Joined: 14 Jul 2012
Posts: 651

PostPosted: Wed Jun 05, 2013 8:32 am    Post subject: Reply with quote

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
View user's profile Send private message
Adel Ahmed
Veteran
Veteran


Joined: 21 Sep 2012
Posts: 1510

PostPosted: Wed Jun 05, 2013 8:35 am    Post subject: Reply with quote

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
View user's profile Send private message
Adel Ahmed
Veteran
Veteran


Joined: 21 Sep 2012
Posts: 1510

PostPosted: Wed Jun 05, 2013 8:51 am    Post subject: Reply with quote

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
View user's profile Send private message
TomWij
Retired Dev
Retired Dev


Joined: 04 Jul 2012
Posts: 1553

PostPosted: Thu Jun 06, 2013 6:05 pm    Post subject: Reply with quote

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
View user's profile Send private message
Adel Ahmed
Veteran
Veteran


Joined: 21 Sep 2012
Posts: 1510

PostPosted: Thu Jun 06, 2013 6:34 pm    Post subject: Reply with quote

here's my dmesg -d :
http://pastebin.com/NAhqTr6r
and here's y bootchart:
http://www.4shared.com/photo/QGwX2fEN/bootchart.html
Back to top
View user's profile Send private message
TomWij
Retired Dev
Retired Dev


Joined: 04 Jul 2012
Posts: 1553

PostPosted: Thu Jun 06, 2013 7:18 pm    Post subject: Reply with quote

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
View user's profile Send private message
TomWij
Retired Dev
Retired Dev


Joined: 04 Jul 2012
Posts: 1553

PostPosted: Thu Jun 06, 2013 7:21 pm    Post subject: Reply with quote

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
View user's profile Send private message
Adel Ahmed
Veteran
Veteran


Joined: 21 Sep 2012
Posts: 1510

PostPosted: Thu Jun 06, 2013 7:31 pm    Post subject: Reply with quote

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
View user's profile Send private message
TomWij
Retired Dev
Retired Dev


Joined: 04 Jul 2012
Posts: 1553

PostPosted: Thu Jun 06, 2013 7:53 pm    Post subject: Reply with quote

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
View user's profile Send private message
Adel Ahmed
Veteran
Veteran


Joined: 21 Sep 2012
Posts: 1510

PostPosted: Fri Jun 07, 2013 12:41 am    Post subject: Reply with quote

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
View user's profile Send private message
Display posts from previous:   
Reply to topic    Gentoo Forums Forum Index Other Things Gentoo All times are GMT
Page 1 of 1

 
Jump to:  
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