Page 1 of 1

Boot process timing.

Posted: Wed Nov 25, 2015 9:49 pm
by nassausky
Anyone here ever try debugging the boot process up to and including X?

Here is my scenario:

Installed a few packages from the original live distro bork 32bit and ran the install bbqinstall.

Boot speed time is about 15 seconds which is very nice on the hard drive. I then created a snapshot of this install and the boot time takes about a full minute to boot the new ISO image.

Looked at dmesg and all looks fine and shows the boot time of each process between the brackets and ends about a little after 8 seconds.

How can see what's holding it up after dmesg.?

Re: Boot process timing.

Posted: Thu Nov 26, 2015 3:19 am
by machinebacon
bootchart (with pybootchartgui) should help. Install them, reboot you machine, and then check /var/log/bootchart/ where you find a PNG image of your boot analysis.

Post it here if you can't identify the problem. My guess is that DHCP takes around 25-30 seconds to get an IP assigned. You can circumvent by adding a static IP address to your machine.

Re: Boot process timing.

Posted: Thu Nov 26, 2015 8:34 am
by Snap
DHCP is not very fast either. Faster than static but it still takes a few seconds.

Re: Boot process timing.

Posted: Thu Nov 26, 2015 8:36 am
by machinebacon
^ read again, please.

Edit: DHCP is not faster in assigning an IP address to the computer's network card than giving it a static IP in /etc/network/interfaces. In case of DHCP, it takes a few seconds (in my case 23 seconds in the last boot) for the router to go through the channels and interrupts. OP might have DHCP turned on (it is turned off on the Live CD, for obvious reasons), and this /might/ explain the longer boot time.

Re: Boot process timing.

Posted: Thu Nov 26, 2015 8:21 pm
by nassausky
Thanks @machinebacon "bootchart (with pybootchartgui)"

I actually found a note about using those tools a little bit before you gave me the suggestion. I was digging around yesterday quite a bit longer and sometimes I wonder why items like this aren't easier to find.

I am going to give it a try. I tried it for a moment last night before I had to take off but my first look in the /var/log folder didn't show up and .png image like the person noted. I did see about 4 .gz files but I'm going to give it a try again in a few minutes.



BTW I don't think it is dhcp related since i made a bunch of snapshots and never saw the problem before.

Thanks will keep you posted.

Re: Boot process timing.

Posted: Thu Nov 26, 2015 9:56 pm
by nassausky
OK got the bootchart working.
adding just init=/sbin/bootchartd was not enough to get it to work. had to also add

initcall_debug printk.time=y

so the full command line was

Code: Select all

initcall_debug printk.time=y quiet init=/sbin/bootchartd
to the grub command line boot args /etc/default/grub and can't forget update-grub

Running out again but have to see if that has the full boot process up to X or if I have to add what some people say are some kind of plugin....

Re: Boot process timing.

Posted: Fri Nov 27, 2015 2:59 am
by machinebacon
usually the step from TTY login to X is managed by ~/.xinitrc (provided you don't add a login manager)

First /etc/inittab tells the TTYs to execute a certain command (/bin/login it is), then ~/.bash_profile is read, which eg. includes the command "startx", which in turn reads the .xsession and .xinitrc files.

If you comment all lines in ~/.bash_profile, you will be dropped to TTY login after boot sequence. Logging in an entering "startx" shows you how slow/quick the jump to X is -- if you want to separate it in this way.

Simply post your bootchart, we will analyse it.

Forgot to add: IF you are using systemd, it uses "systemd-analyze blame" t show how long each service needs to start.

Re: Boot process timing.

Posted: Fri Nov 27, 2015 7:09 am
by rhowaldt
that's smart, to separate things out like that. hadn't thought about that one.

in general nassau, i've found the boot process to be hard to actually get a proper hold on. i've only had moderate success in getting a more detailed boot log. then again, i'm a bit of a noob with this stuff, so it is entirely possible i just did something wrong. the bootchart is good shit though, very informative, once you get it to work.

Re: Boot process timing.

Posted: Fri Nov 27, 2015 11:24 am
by wuxmedia
...make tea while it boots?
any boot slowness I've had is it waiting for DHCP when it wasn't going to happen, so yeah what Bacon said.

Re: Boot process timing.

Posted: Fri Nov 27, 2015 1:07 pm
by dkeg
^ yep, me too.

Re: Boot process timing.

Posted: Fri Nov 27, 2015 10:51 pm
by arnold
agreed - probably networking issue

Re: Boot process timing.

Posted: Tue Dec 01, 2015 1:50 am
by nassausky
File attached.

I'm thinking it's something inside /etc/inittab like maybe one of the services starting up from the call s1::sysint:/etc/init.d/rcS

It seems to be after the dmesg's end and before X starts up.

When I stop X from starting up by removing it from the ~/.bashprofile I notice that doesn't help and it still takes much longer to bootup than it used to.

Guessing an application service I installed which is loading from init.d???

Re: Boot process timing.

Posted: Tue Dec 01, 2015 7:59 am
by wuxmedia
Well, move them out one by one? make sure all your USB shit is unplugged.
Why does the boot options indicate 'live' surely that's never going to be super fast?

Re: Boot process timing.

Posted: Tue Dec 01, 2015 10:39 am
by machinebacon
Right, try booting without attached USBs, that would be my first suggestion.

But I see mysql is loaded, do you use the setup as server/client, or do you connect to an internal network/samba/fuse at boot? How does /etc/fstab look like? Only these things spring to mind right now.

Re: Boot process timing.

Posted: Tue Dec 01, 2015 2:32 pm
by nassausky
Basically I'm working on 2 bootable Live ISO disc images. They will be a print and time management Live ISO server disc and client Live ISO disc that I will offer to neighboring libraries. If they choose, I will give them instructions on how to install these Live ISOs to their PC's. Their current system has been nothing but problems. The Live ISO server disc which I am working on now needs the mysql server installed hence you see it in the list booted services. What gets me is that there must be some difference in the boot sequence from booting from the print and time management HDD install and booting from the supposedly identical remastered bbqsnapshot since:
The complete boot from the HDD takes about 15 seconds
The complete boot from the CD takes about 1 minute and 15
Both take about 8 seconds to finish the boot cycle before something mysterious happens on the Live ISO before X windows starts. On the ISO the boot pauses for maybe a minute before it actually starts up X which then boots up quickly after that.

I made quite a few Live ISO's in the past and never had this issue where the Live ISO would stall like it is now. Hmmm might uninstall mysql to test if that's it. Just takes a while each time I create a bbqsnapshot and then test it out.

Thanks for all the suggestions so far.
I am going to be working on it again later and see if I can figure that out. There are no attached USB drives during boot and when I get in I will look at the fstab but my first guess is that it might be identical to the fast booting HDD that the image was made from.

Update :
The fstab on HDD install has

Code: Select all

proc            /proc    proc    defaults                  0    0
/dev/sda1   /           ext4     defaults,noatime    0    1
The fstab on the Live ISO has

Code: Select all

aufs      /    aufs     rw                     0    0
tmpfs    /    tmpfs   nosuid,nodev    0    0
I am looking at another Live ISO bork 32 bit disk I created which has the same fstab and boots up fine just about the same time it boots from the HDD. I don't think it's fstab related ..

Re: Boot process timing.

Posted: Tue Dec 01, 2015 5:20 pm
by nassausky
Ok there is a difference which I didn't realize I must have disabled mysql service on the HDD after I created the bbqsnapshot. The problem is half solved. Most of the delay is starting mysql. I was focusing mainly on the ISO and didn't reboot the HDD install in a while.

The interesting thing that I'd like to get solved but is not critical but nice to know is how to show the mysql process starting up in the bbqsnapshot ISO. The boot looks basically the same on both installs up to the text being displayed on bootup:

Code: Select all

[ ok ] Cleaning up temporary files....
[info] Setting console screen modes.
[ ok ] Setting up console font and keymap....done.
[ ok ] Setting up ALSA...done (none loaded).
[ ok ] Setting up X socket directories... /tmp/.X11-unix /tmp/.ICE-unix.
INIT: Entering runlevel: 2
[ ok ] Starting system message bus: dbus.
[....] Starting MySQL database server: mysqldNo directory, logging in with Home=/
. . . . . . . . . . . . . . . . . .
None of the above text displays during the Live ISO boot up sequence

Re: Boot process timing.

Posted: Tue Dec 01, 2015 6:20 pm
by nassausky
OK during this process of figuring out why boot up is so slow, I found 2 bugs if that's what I may call them. (EDIT: don' think 1st is a problem)

The first is whomever created the debian installer for mysql-server didn't create a folder called /var/log/mysql which then had to be changed owners to mysql as such:

Code: Select all

chmod mysql:mysql /var/log/mysql
otherwise the mysql server doesn't start and doesn't log the error message and just takes the boot process 30 seconds to a minute to fail and skip ahead to finish the boot
(Edit, if you read my post below I don't think the install skipped creating the /var/log/mysql folder with it's correct permissions too but I think it was using bbqinstall to install it to the hdd which erased the folder)




The second is less of a bug but a heads up. bbqsnapshot has a nice exclude list located at /usr/lib/bbqsnapshot/snapshot_exclude.list which includes items or directories not going to be included on the snapshot ISO. Don't know the reason but on the original snapshot_exclude.list the folders that begin with the letters c & g are the only folders included in the snapshot ISO burn. I just replaced

Code: Select all

- /var/log/[h-z]*
with the following to allow the myql log folder to remain in the final bbqsnapshot ISO burn:

Code: Select all

- /var/log/[h-l]*
- /var/log/[n-z]*
but still would like to know how to show the service loading message while booting the Live ISO just like it shows on the HDD install bootup as mentioned above on the previous post

Re: Boot process timing.

Posted: Wed Dec 02, 2015 8:11 am
by wuxmedia
like circus style plate spinning :)
good digging though.

I think you'd find quite a lot of unhappy sysadmins if the debian installer failed to make the basic log folder, yes removed in the exclude list.

err, maybe verbose on the kernel options?
HDD is likely grub, USB is likely syslinux?

Re: Boot process timing.

Posted: Wed Dec 02, 2015 9:33 pm
by nassausky
Hmmm crazy that I learn something new every day but forget 2 things a day and in this case grub & syslinux haha. I have to take my limited time and research more before I respond. Basically after the fact of my saying it was the installer, I think it was more than that.

I love booting a live CD and installing items then burning another ISO or then mounting them onto a HDD. This case (and probably a few more cases) it was a bad idea. I will try it when I get a moment but I think what happened that it probably installed the /var/log/mysql folder fine during the install but when I ran bbqinstall it didn't copy over that folder so my newly created HDD didn't start mysql and then from that every bbqsnapshot I made after that didn't work out either.

Oh man.. Anybody know of a good white out to fix my assumption above. I am going to go edit it now ...

Thanks