| xj | b04a402 | 2021-11-25 15:01:52 +0800 | [diff] [blame] | 1 | #!/usr/bin/env perl | 
|  | 2 |  | 
|  | 3 | # Copyright 2008, Intel Corporation | 
|  | 4 | # | 
|  | 5 | # This file is part of the Linux kernel | 
|  | 6 | # | 
|  | 7 | # This program file is free software; you can redistribute it and/or modify it | 
|  | 8 | # under the terms of the GNU General Public License as published by the | 
|  | 9 | # Free Software Foundation; version 2 of the License. | 
|  | 10 | # | 
|  | 11 | # This program is distributed in the hope that it will be useful, but WITHOUT | 
|  | 12 | # ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or | 
|  | 13 | # FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License | 
|  | 14 | # for more details. | 
|  | 15 | # | 
|  | 16 | # You should have received a copy of the GNU General Public License | 
|  | 17 | # along with this program in a file named COPYING; if not, write to the | 
|  | 18 | # Free Software Foundation, Inc., | 
|  | 19 | # 51 Franklin Street, Fifth Floor, | 
|  | 20 | # Boston, MA 02110-1301 USA | 
|  | 21 | # | 
|  | 22 | # Authors: | 
|  | 23 | # 	Arjan van de Ven <arjan@linux.intel.com> | 
|  | 24 |  | 
|  | 25 |  | 
|  | 26 | # | 
|  | 27 | # This script turns a dmesg output into a SVG graphic that shows which | 
|  | 28 | # functions take how much time. You can view SVG graphics with various | 
|  | 29 | # programs, including Inkscape, The Gimp and Firefox. | 
|  | 30 | # | 
|  | 31 | # | 
|  | 32 | # For this script to work, the kernel needs to be compiled with the | 
|  | 33 | # CONFIG_PRINTK_TIME configuration option enabled, and with | 
|  | 34 | # "initcall_debug" passed on the kernel command line. | 
|  | 35 | # | 
|  | 36 | # usage: | 
|  | 37 | # 	dmesg | perl scripts/bootgraph.pl > output.svg | 
|  | 38 | # | 
|  | 39 |  | 
|  | 40 | use strict; | 
|  | 41 | use Getopt::Long; | 
|  | 42 | my $header = 0; | 
|  | 43 |  | 
|  | 44 | sub help { | 
|  | 45 | my $text = << "EOM"; | 
|  | 46 | Usage: | 
|  | 47 | 1) dmesg | perl scripts/bootgraph.pl [OPTION] > output.svg | 
|  | 48 | 2) perl scripts/bootgraph.pl -h | 
|  | 49 |  | 
|  | 50 | Options: | 
|  | 51 | -header	Insert kernel version and date | 
|  | 52 | EOM | 
|  | 53 | my $std=shift; | 
|  | 54 | if ($std == 1) { | 
|  | 55 | print STDERR $text; | 
|  | 56 | } else { | 
|  | 57 | print $text; | 
|  | 58 | } | 
|  | 59 | exit; | 
|  | 60 | } | 
|  | 61 |  | 
|  | 62 | GetOptions( | 
|  | 63 | 'h|help'	=>\&help, | 
|  | 64 | 'header'	=>\$header | 
|  | 65 | ); | 
|  | 66 |  | 
|  | 67 | my %start; | 
|  | 68 | my %end; | 
|  | 69 | my %type; | 
|  | 70 | my $done = 0; | 
|  | 71 | my $maxtime = 0; | 
|  | 72 | my $firsttime = 99999; | 
|  | 73 | my $count = 0; | 
|  | 74 | my %pids; | 
|  | 75 | my %pidctr; | 
|  | 76 |  | 
|  | 77 | my $headerstep = 20; | 
|  | 78 | my $xheader = 15; | 
|  | 79 | my $yheader = 25; | 
|  | 80 | my $cyheader = 0; | 
|  | 81 |  | 
|  | 82 | while (<>) { | 
|  | 83 | my $line = $_; | 
|  | 84 | if ($line =~ /([0-9\.]+)\] calling  ([a-zA-Z0-9\_\.]+)\+/) { | 
|  | 85 | my $func = $2; | 
|  | 86 | if ($done == 0) { | 
|  | 87 | $start{$func} = $1; | 
|  | 88 | $type{$func} = 0; | 
|  | 89 | if ($1 < $firsttime) { | 
|  | 90 | $firsttime = $1; | 
|  | 91 | } | 
|  | 92 | } | 
|  | 93 | if ($line =~ /\@ ([0-9]+)/) { | 
|  | 94 | $pids{$func} = $1; | 
|  | 95 | } | 
|  | 96 | $count = $count + 1; | 
|  | 97 | } | 
|  | 98 |  | 
|  | 99 | if ($line =~ /([0-9\.]+)\] async_waiting @ ([0-9]+)/) { | 
|  | 100 | my $pid = $2; | 
|  | 101 | my $func; | 
|  | 102 | if (!defined($pidctr{$pid})) { | 
|  | 103 | $func = "wait_" . $pid . "_1"; | 
|  | 104 | $pidctr{$pid} = 1; | 
|  | 105 | } else { | 
|  | 106 | $pidctr{$pid} = $pidctr{$pid} + 1; | 
|  | 107 | $func = "wait_" . $pid . "_" . $pidctr{$pid}; | 
|  | 108 | } | 
|  | 109 | if ($done == 0) { | 
|  | 110 | $start{$func} = $1; | 
|  | 111 | $type{$func} = 1; | 
|  | 112 | if ($1 < $firsttime) { | 
|  | 113 | $firsttime = $1; | 
|  | 114 | } | 
|  | 115 | } | 
|  | 116 | $pids{$func} = $pid; | 
|  | 117 | $count = $count + 1; | 
|  | 118 | } | 
|  | 119 |  | 
|  | 120 | if ($line =~ /([0-9\.]+)\] initcall ([a-zA-Z0-9\_\.]+)\+.*returned/) { | 
|  | 121 | if ($done == 0) { | 
|  | 122 | $end{$2} = $1; | 
|  | 123 | $maxtime = $1; | 
|  | 124 | } | 
|  | 125 | } | 
|  | 126 |  | 
|  | 127 | if ($line =~ /([0-9\.]+)\] async_continuing @ ([0-9]+)/) { | 
|  | 128 | my $pid = $2; | 
|  | 129 | my $func =  "wait_" . $pid . "_" . $pidctr{$pid}; | 
|  | 130 | $end{$func} = $1; | 
|  | 131 | $maxtime = $1; | 
|  | 132 | } | 
|  | 133 | if ($line =~ /Write protecting the/) { | 
|  | 134 | $done = 1; | 
|  | 135 | } | 
|  | 136 | if ($line =~ /Freeing unused kernel memory/) { | 
|  | 137 | $done = 1; | 
|  | 138 | } | 
|  | 139 | } | 
|  | 140 |  | 
|  | 141 | if ($count == 0) { | 
|  | 142 | print STDERR <<END; | 
|  | 143 | No data found in the dmesg. Make sure that 'printk.time=1' and | 
|  | 144 | 'initcall_debug' are passed on the kernel command line. | 
|  | 145 | END | 
|  | 146 | help(1); | 
|  | 147 | exit 1; | 
|  | 148 | } | 
|  | 149 |  | 
|  | 150 | print "<?xml version=\"1.0\" standalone=\"no\"?> \n"; | 
|  | 151 | print "<svg width=\"2000\" height=\"100%\" version=\"1.1\" xmlns=\"http://www.w3.org/2000/svg\">\n"; | 
|  | 152 |  | 
|  | 153 |  | 
|  | 154 | if ($header) { | 
|  | 155 | my $version = `uname -a`; | 
|  | 156 | my $date = `date`; | 
|  | 157 | print "<text transform=\"translate($xheader,$yheader)\">Kernel version: $version</text>\n"; | 
|  | 158 | $cyheader = $yheader+$headerstep; | 
|  | 159 | print "<text transform=\"translate($xheader,$cyheader)\">Date: $date</text>\n"; | 
|  | 160 | } | 
|  | 161 |  | 
|  | 162 | my @styles; | 
|  | 163 |  | 
|  | 164 | $styles[0] = "fill:rgb(0,0,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; | 
|  | 165 | $styles[1] = "fill:rgb(0,255,0);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; | 
|  | 166 | $styles[2] = "fill:rgb(255,0,20);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; | 
|  | 167 | $styles[3] = "fill:rgb(255,255,20);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; | 
|  | 168 | $styles[4] = "fill:rgb(255,0,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; | 
|  | 169 | $styles[5] = "fill:rgb(0,255,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; | 
|  | 170 | $styles[6] = "fill:rgb(0,128,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; | 
|  | 171 | $styles[7] = "fill:rgb(0,255,128);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; | 
|  | 172 | $styles[8] = "fill:rgb(255,0,128);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; | 
|  | 173 | $styles[9] = "fill:rgb(255,255,128);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; | 
|  | 174 | $styles[10] = "fill:rgb(255,128,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; | 
|  | 175 | $styles[11] = "fill:rgb(128,255,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; | 
|  | 176 |  | 
|  | 177 | my $style_wait = "fill:rgb(128,128,128);fill-opacity:0.5;stroke-width:0;stroke:rgb(0,0,0)"; | 
|  | 178 |  | 
|  | 179 | my $mult = 1950.0 / ($maxtime - $firsttime); | 
|  | 180 | my $threshold2 = ($maxtime - $firsttime) / 120.0; | 
|  | 181 | my $threshold = $threshold2/10; | 
|  | 182 | my $stylecounter = 0; | 
|  | 183 | my %rows; | 
|  | 184 | my $rowscount = 1; | 
|  | 185 | my @initcalls = sort { $start{$a} <=> $start{$b} } keys(%start); | 
|  | 186 |  | 
|  | 187 | foreach my $key (@initcalls) { | 
|  | 188 | my $duration = $end{$key} - $start{$key}; | 
|  | 189 |  | 
|  | 190 | if ($duration >= $threshold) { | 
|  | 191 | my ($s, $s2, $s3, $e, $w, $y, $y2, $style); | 
|  | 192 | my $pid = $pids{$key}; | 
|  | 193 |  | 
|  | 194 | if (!defined($rows{$pid})) { | 
|  | 195 | $rows{$pid} = $rowscount; | 
|  | 196 | $rowscount = $rowscount + 1; | 
|  | 197 | } | 
|  | 198 | $s = ($start{$key} - $firsttime) * $mult; | 
|  | 199 | $s2 = $s + 6; | 
|  | 200 | $s3 = $s + 1; | 
|  | 201 | $e = ($end{$key} - $firsttime) * $mult; | 
|  | 202 | $w = $e - $s; | 
|  | 203 |  | 
|  | 204 | $y = $rows{$pid} * 150; | 
|  | 205 | $y2 = $y + 4; | 
|  | 206 |  | 
|  | 207 | $style = $styles[$stylecounter]; | 
|  | 208 | $stylecounter = $stylecounter + 1; | 
|  | 209 | if ($stylecounter > 11) { | 
|  | 210 | $stylecounter = 0; | 
|  | 211 | }; | 
|  | 212 |  | 
|  | 213 | if ($type{$key} == 1) { | 
|  | 214 | $y = $y + 15; | 
|  | 215 | print "<rect x=\"$s\" width=\"$w\" y=\"$y\" height=\"115\" style=\"$style_wait\"/>\n"; | 
|  | 216 | } else { | 
|  | 217 | print "<rect x=\"$s\" width=\"$w\" y=\"$y\" height=\"145\" style=\"$style\"/>\n"; | 
|  | 218 | if ($duration >= $threshold2) { | 
|  | 219 | print "<text transform=\"translate($s2,$y2) rotate(90)\">$key</text>\n"; | 
|  | 220 | } else { | 
|  | 221 | print "<text transform=\"translate($s3,$y2) rotate(90)\" font-size=\"3pt\">$key</text>\n"; | 
|  | 222 | } | 
|  | 223 | } | 
|  | 224 | } | 
|  | 225 | } | 
|  | 226 |  | 
|  | 227 |  | 
|  | 228 | # print the time line on top | 
|  | 229 | my $time = $firsttime; | 
|  | 230 | my $step = ($maxtime - $firsttime) / 15; | 
|  | 231 | while ($time < $maxtime) { | 
|  | 232 | my $s3 = ($time - $firsttime) * $mult; | 
|  | 233 | my $tm = int($time * 100) / 100.0; | 
|  | 234 | print "<text transform=\"translate($s3,89) rotate(90)\">$tm</text>\n"; | 
|  | 235 | $time = $time + $step; | 
|  | 236 | } | 
|  | 237 |  | 
|  | 238 | print "</svg>\n"; |