Back to home page

LXR

 
 

    


0001 #!/usr/bin/perl
0002 
0003 # Copyright 2008, Intel Corporation
0004 #
0005 # This file is part of the Linux kernel
0006 #
0007 # This program file is free software; you can redistribute it and/or modify it
0008 # under the terms of the GNU General Public License as published by the
0009 # Free Software Foundation; version 2 of the License.
0010 #
0011 # This program is distributed in the hope that it will be useful, but WITHOUT
0012 # ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
0013 # FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
0014 # for more details.
0015 #
0016 # You should have received a copy of the GNU General Public License
0017 # along with this program in a file named COPYING; if not, write to the
0018 # Free Software Foundation, Inc.,
0019 # 51 Franklin Street, Fifth Floor,
0020 # Boston, MA 02110-1301 USA
0021 #
0022 # Authors:
0023 #   Arjan van de Ven <arjan@linux.intel.com>
0024 
0025 
0026 #
0027 # This script turns a dmesg output into a SVG graphic that shows which
0028 # functions take how much time. You can view SVG graphics with various
0029 # programs, including Inkscape, The Gimp and Firefox.
0030 #
0031 #
0032 # For this script to work, the kernel needs to be compiled with the
0033 # CONFIG_PRINTK_TIME configuration option enabled, and with
0034 # "initcall_debug" passed on the kernel command line.
0035 #
0036 # usage:
0037 #   dmesg | perl scripts/bootgraph.pl > output.svg
0038 #
0039 
0040 use strict;
0041 use Getopt::Long;
0042 my $header = 0;
0043 
0044 sub help {
0045     my $text = << "EOM";
0046 Usage:
0047 1) dmesg | perl scripts/bootgraph.pl [OPTION] > output.svg
0048 2) perl scripts/bootgraph.pl -h
0049 
0050 Options:
0051     -header Insert kernel version and date
0052 EOM
0053     my $std=shift;
0054     if ($std == 1) {
0055         print STDERR $text;
0056     } else {
0057         print $text;
0058     }
0059     exit;
0060 }
0061 
0062 GetOptions(
0063     'h|help'    =>\&help,
0064     'header'    =>\$header
0065 );
0066 
0067 my %start;
0068 my %end;
0069 my %type;
0070 my $done = 0;
0071 my $maxtime = 0;
0072 my $firsttime = 99999;
0073 my $count = 0;
0074 my %pids;
0075 my %pidctr;
0076 
0077 my $headerstep = 20;
0078 my $xheader = 15;
0079 my $yheader = 25;
0080 my $cyheader = 0;
0081 
0082 while (<>) {
0083     my $line = $_;
0084     if ($line =~ /([0-9\.]+)\] calling  ([a-zA-Z0-9\_\.]+)\+/) {
0085         my $func = $2;
0086         if ($done == 0) {
0087             $start{$func} = $1;
0088             $type{$func} = 0;
0089             if ($1 < $firsttime) {
0090                 $firsttime = $1;
0091             }
0092         }
0093         if ($line =~ /\@ ([0-9]+)/) {
0094             $pids{$func} = $1;
0095         }
0096         $count = $count + 1;
0097     }
0098 
0099     if ($line =~ /([0-9\.]+)\] async_waiting @ ([0-9]+)/) {
0100         my $pid = $2;
0101         my $func;
0102         if (!defined($pidctr{$pid})) {
0103             $func = "wait_" . $pid . "_1";
0104             $pidctr{$pid} = 1;
0105         } else {
0106             $pidctr{$pid} = $pidctr{$pid} + 1;
0107             $func = "wait_" . $pid . "_" . $pidctr{$pid};
0108         }
0109         if ($done == 0) {
0110             $start{$func} = $1;
0111             $type{$func} = 1;
0112             if ($1 < $firsttime) {
0113                 $firsttime = $1;
0114             }
0115         }
0116         $pids{$func} = $pid;
0117         $count = $count + 1;
0118     }
0119 
0120     if ($line =~ /([0-9\.]+)\] initcall ([a-zA-Z0-9\_\.]+)\+.*returned/) {
0121         if ($done == 0) {
0122             $end{$2} = $1;
0123             $maxtime = $1;
0124         }
0125     }
0126 
0127     if ($line =~ /([0-9\.]+)\] async_continuing @ ([0-9]+)/) {
0128         my $pid = $2;
0129         my $func =  "wait_" . $pid . "_" . $pidctr{$pid};
0130         $end{$func} = $1;
0131         $maxtime = $1;
0132     }
0133     if ($line =~ /Write protecting the/) {
0134         $done = 1;
0135     }
0136     if ($line =~ /Freeing unused kernel memory/) {
0137         $done = 1;
0138     }
0139 }
0140 
0141 if ($count == 0) {
0142     print STDERR <<END;
0143 No data found in the dmesg. Make sure that 'printk.time=1' and
0144 'initcall_debug' are passed on the kernel command line.
0145 END
0146     help(1);
0147     exit 1;
0148 }
0149 
0150 print "<?xml version=\"1.0\" standalone=\"no\"?> \n";
0151 print "<svg width=\"2000\" height=\"100%\" version=\"1.1\" xmlns=\"http://www.w3.org/2000/svg\">\n";
0152 
0153 
0154 if ($header) {
0155     my $version = `uname -a`;
0156     my $date = `date`;
0157     print "<text transform=\"translate($xheader,$yheader)\">Kernel version: $version</text>\n";
0158     $cyheader = $yheader+$headerstep;
0159     print "<text transform=\"translate($xheader,$cyheader)\">Date: $date</text>\n";
0160 }
0161 
0162 my @styles;
0163 
0164 $styles[0] = "fill:rgb(0,0,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)";
0165 $styles[1] = "fill:rgb(0,255,0);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)";
0166 $styles[2] = "fill:rgb(255,0,20);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)";
0167 $styles[3] = "fill:rgb(255,255,20);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)";
0168 $styles[4] = "fill:rgb(255,0,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)";
0169 $styles[5] = "fill:rgb(0,255,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)";
0170 $styles[6] = "fill:rgb(0,128,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)";
0171 $styles[7] = "fill:rgb(0,255,128);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)";
0172 $styles[8] = "fill:rgb(255,0,128);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)";
0173 $styles[9] = "fill:rgb(255,255,128);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)";
0174 $styles[10] = "fill:rgb(255,128,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)";
0175 $styles[11] = "fill:rgb(128,255,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)";
0176 
0177 my $style_wait = "fill:rgb(128,128,128);fill-opacity:0.5;stroke-width:0;stroke:rgb(0,0,0)";
0178 
0179 my $mult = 1950.0 / ($maxtime - $firsttime);
0180 my $threshold2 = ($maxtime - $firsttime) / 120.0;
0181 my $threshold = $threshold2/10;
0182 my $stylecounter = 0;
0183 my %rows;
0184 my $rowscount = 1;
0185 my @initcalls = sort { $start{$a} <=> $start{$b} } keys(%start);
0186 
0187 foreach my $key (@initcalls) {
0188     my $duration = $end{$key} - $start{$key};
0189 
0190     if ($duration >= $threshold) {
0191         my ($s, $s2, $s3, $e, $w, $y, $y2, $style);
0192         my $pid = $pids{$key};
0193 
0194         if (!defined($rows{$pid})) {
0195             $rows{$pid} = $rowscount;
0196             $rowscount = $rowscount + 1;
0197         }
0198         $s = ($start{$key} - $firsttime) * $mult;
0199         $s2 = $s + 6;
0200         $s3 = $s + 1;
0201         $e = ($end{$key} - $firsttime) * $mult;
0202         $w = $e - $s;
0203 
0204         $y = $rows{$pid} * 150;
0205         $y2 = $y + 4;
0206 
0207         $style = $styles[$stylecounter];
0208         $stylecounter = $stylecounter + 1;
0209         if ($stylecounter > 11) {
0210             $stylecounter = 0;
0211         };
0212 
0213         if ($type{$key} == 1) {
0214             $y = $y + 15;
0215             print "<rect x=\"$s\" width=\"$w\" y=\"$y\" height=\"115\" style=\"$style_wait\"/>\n";
0216         } else {
0217             print "<rect x=\"$s\" width=\"$w\" y=\"$y\" height=\"145\" style=\"$style\"/>\n";
0218             if ($duration >= $threshold2) {
0219                 print "<text transform=\"translate($s2,$y2) rotate(90)\">$key</text>\n";
0220             } else {
0221                 print "<text transform=\"translate($s3,$y2) rotate(90)\" font-size=\"3pt\">$key</text>\n";
0222             }
0223         }
0224     }
0225 }
0226 
0227 
0228 # print the time line on top
0229 my $time = $firsttime;
0230 my $step = ($maxtime - $firsttime) / 15;
0231 while ($time < $maxtime) {
0232     my $s3 = ($time - $firsttime) * $mult;
0233     my $tm = int($time * 100) / 100.0;
0234     print "<text transform=\"translate($s3,89) rotate(90)\">$tm</text>\n";
0235     $time = $time + $step;
0236 }
0237 
0238 print "</svg>\n";