Minimal Solaris: Boot chart with help of DTrace and Python

Anonymous tracing allows to receive more interesting information about Solaris booting process. I use a simple D-script (boot.d):


#!/usr/sbin/dtrace -Cs
#pragma D option quiet
/* I need process pid, his forks and life time */ 
proc:::create
{
 printf("<fork ppid=%d cpid=%d execname=%s time=%d />\n",
         pid,args[0]->pr_pid,execname,`lbolt*10/ `hz);
}

proc:::exec-success
{
 printf("<process pid=%d execname=%s time=%d />\n",
         pid,execname,`lbolt*10/ `hz);
}

proc:::exit
{

 printf("<end pid=%d execname=%s time=%d />\n", 
         pid, execname,`lbolt*10/ `hz);
}

Then I enable anonymous tracing:


dtrace -AFs /boot/boot.d
reboot

After reboot I write a logfile and disable anonymous tracing:


dtrace -ae -o bootlog
dtrace -A

Logfile looks like this:


CPU FUNCTION                                                                                                                                                 
  0 | exec_common:exec-success <process pid=1 execname=init time=63 />                                                                        
  0 | cfork:create             <fork ppid=1 cpid=4 execname=init time=66 />                                                                   
  0 | exec_common:exec-success <process pid=4 execname=ksh93 time=67 />                                                                       
  0 | exec_common:exec-success <process pid=4 execname=autopush time=87 />                                                                    
  0 | proc_exit:exit           <end pid=4 execname=autopush time=92 />                                                                        
  0 | cfork:create             <fork ppid=1 cpid=5 execname=init time=92 />                                                                   
  0 | exec_common:exec-success <process pid=5 execname=ksh93 time=92 />                                                                       
  0 | exec_common:exec-success <process pid=5 execname=soconfig time=94 /> 
...

Now by help of a python it's possible to parse logfile. I've written a small script bootchart.py for parsing and chart construction. It would be great to trace and draw the cpu part but this is not implemented yet.
To create boot chart you need run bootchart.py with logfile as an argument:


bootchart.py bootlog

This is a boot chart example for OpenSolaris 2008.11:

5 comments:

UnknownMay 6, 2009 at 8:22 AM
Talk about understatement! This is slick; thank you for sharing it.
M. BehrensAugust 24, 2010 at 9:45 PM
Could this be used to monitor a specific process - say to capture the performance of a particular process over a period of time? I'm new to dtrace...how could a specific PID be used to manually capture the stats of a running process (as apposed to all the processes)? Good stuff - thanks.
alhazredAugust 25, 2010 at 12:08 AM
It's easy to make on already loaded system. To create the boot chart is probably just need to find the desired command from the file and make the graph only for it
UnknownAugust 31, 2010 at 12:29 PM
Just tried this on snv_134 and got the following:

line 7: failed to resolve `lbolt: Unknown symbol name

Looking through /dev/ksyms, I see a multitude of local <...>_lbolt objects, but no global lbolt object.
alhazredAugust 31, 2010 at 11:17 PM
It seems this is due clock driven lbolt migration. Not tested, but I think now need use next function:
fbt:genunix:ddi_get_lbolt:return
{
lbolt = args[1];
}

Monday, January 12, 2009

Boot chart with help of DTrace and Python

5 comments: