1aa5d9151SArjan van de Ven#!/usr/bin/perl 2aa5d9151SArjan van de Ven 3aa5d9151SArjan van de Ven# Copyright 2008, Intel Corporation 4aa5d9151SArjan van de Ven# 5aa5d9151SArjan van de Ven# This file is part of the Linux kernel 6aa5d9151SArjan van de Ven# 7aa5d9151SArjan van de Ven# This program file is free software; you can redistribute it and/or modify it 8aa5d9151SArjan van de Ven# under the terms of the GNU General Public License as published by the 9aa5d9151SArjan van de Ven# Free Software Foundation; version 2 of the License. 10aa5d9151SArjan van de Ven# 11aa5d9151SArjan van de Ven# This program is distributed in the hope that it will be useful, but WITHOUT 12aa5d9151SArjan van de Ven# ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or 13aa5d9151SArjan van de Ven# FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License 14aa5d9151SArjan van de Ven# for more details. 15aa5d9151SArjan van de Ven# 16aa5d9151SArjan van de Ven# You should have received a copy of the GNU General Public License 17aa5d9151SArjan van de Ven# along with this program in a file named COPYING; if not, write to the 18aa5d9151SArjan van de Ven# Free Software Foundation, Inc., 19aa5d9151SArjan van de Ven# 51 Franklin Street, Fifth Floor, 20aa5d9151SArjan van de Ven# Boston, MA 02110-1301 USA 21aa5d9151SArjan van de Ven# 22aa5d9151SArjan van de Ven# Authors: 23aa5d9151SArjan van de Ven# Arjan van de Ven <arjan@linux.intel.com> 24aa5d9151SArjan van de Ven 25aa5d9151SArjan van de Ven 26aa5d9151SArjan van de Ven# 27aa5d9151SArjan van de Ven# This script turns a dmesg output into a SVG graphic that shows which 28aa5d9151SArjan van de Ven# functions take how much time. You can view SVG graphics with various 29aa5d9151SArjan van de Ven# programs, including Inkscape, The Gimp and Firefox. 30aa5d9151SArjan van de Ven# 31aa5d9151SArjan van de Ven# 32aa5d9151SArjan van de Ven# For this script to work, the kernel needs to be compiled with the 33aa5d9151SArjan van de Ven# CONFIG_PRINTK_TIME configuration option enabled, and with 34aa5d9151SArjan van de Ven# "initcall_debug" passed on the kernel command line. 35aa5d9151SArjan van de Ven# 36aa5d9151SArjan van de Ven# usage: 37aa5d9151SArjan van de Ven# dmesg | perl scripts/bootgraph.pl > output.svg 38aa5d9151SArjan van de Ven# 39aa5d9151SArjan van de Ven 402a813f8cSAlan Jenkinsuse strict; 41*67554faaSFabian Frederickuse Getopt::Long; 42*67554faaSFabian Frederickmy $header = 0; 43*67554faaSFabian Frederick 44*67554faaSFabian Fredericksub help { 45*67554faaSFabian Frederick my $text = << "EOM"; 46*67554faaSFabian FrederickUsage: 47*67554faaSFabian Frederick1) dmesg | perl scripts/bootgraph.pl [OPTION] > output.svg 48*67554faaSFabian Frederick2) perl scripts/bootgraph.pl -h 49*67554faaSFabian Frederick 50*67554faaSFabian FrederickOptions: 51*67554faaSFabian Frederick -header Insert kernel version and date 52*67554faaSFabian FrederickEOM 53*67554faaSFabian Frederick my $std=shift; 54*67554faaSFabian Frederick if ($std == 1) { 55*67554faaSFabian Frederick print STDERR $text; 56*67554faaSFabian Frederick } else { 57*67554faaSFabian Frederick print $text; 58*67554faaSFabian Frederick } 59*67554faaSFabian Frederick exit; 60*67554faaSFabian Frederick} 61*67554faaSFabian Frederick 62*67554faaSFabian FrederickGetOptions( 63*67554faaSFabian Frederick 'h|help' =>\&help, 64*67554faaSFabian Frederick 'header' =>\$header 65*67554faaSFabian Frederick); 662a813f8cSAlan Jenkins 672a813f8cSAlan Jenkinsmy %start; 682a813f8cSAlan Jenkinsmy %end; 69d3f8ddeaSArjan van de Venmy %type; 70aa5d9151SArjan van de Venmy $done = 0; 71aa5d9151SArjan van de Venmy $maxtime = 0; 72c443453cSAndrew Murraymy $firsttime = 99999; 73aa5d9151SArjan van de Venmy $count = 0; 74ddc7a01aSFrederic Weisbeckermy %pids; 75d3f8ddeaSArjan van de Venmy %pidctr; 76ddc7a01aSFrederic Weisbecker 77*67554faaSFabian Frederickmy $headerstep = 20; 78*67554faaSFabian Frederickmy $xheader = 15; 79*67554faaSFabian Frederickmy $yheader = 25; 80*67554faaSFabian Frederickmy $cyheader = 0; 81*67554faaSFabian Frederick 82aa5d9151SArjan van de Venwhile (<>) { 83aa5d9151SArjan van de Ven my $line = $_; 840bb98e23SMichael Neuling if ($line =~ /([0-9\.]+)\] calling ([a-zA-Z0-9\_\.]+)\+/) { 85aa5d9151SArjan van de Ven my $func = $2; 86aa5d9151SArjan van de Ven if ($done == 0) { 87aa5d9151SArjan van de Ven $start{$func} = $1; 88d3f8ddeaSArjan van de Ven $type{$func} = 0; 8980a398a5SArjan van de Ven if ($1 < $firsttime) { 9080a398a5SArjan van de Ven $firsttime = $1; 9180a398a5SArjan van de Ven } 92aa5d9151SArjan van de Ven } 93aa5d9151SArjan van de Ven if ($line =~ /\@ ([0-9]+)/) { 94ddc7a01aSFrederic Weisbecker $pids{$func} = $1; 95aa5d9151SArjan van de Ven } 96aa5d9151SArjan van de Ven $count = $count + 1; 97aa5d9151SArjan van de Ven } 98aa5d9151SArjan van de Ven 99d3f8ddeaSArjan van de Ven if ($line =~ /([0-9\.]+)\] async_waiting @ ([0-9]+)/) { 100d3f8ddeaSArjan van de Ven my $pid = $2; 101d3f8ddeaSArjan van de Ven my $func; 102d3f8ddeaSArjan van de Ven if (!defined($pidctr{$pid})) { 103d3f8ddeaSArjan van de Ven $func = "wait_" . $pid . "_1"; 104d3f8ddeaSArjan van de Ven $pidctr{$pid} = 1; 105d3f8ddeaSArjan van de Ven } else { 106d3f8ddeaSArjan van de Ven $pidctr{$pid} = $pidctr{$pid} + 1; 107d3f8ddeaSArjan van de Ven $func = "wait_" . $pid . "_" . $pidctr{$pid}; 108d3f8ddeaSArjan van de Ven } 109d3f8ddeaSArjan van de Ven if ($done == 0) { 110d3f8ddeaSArjan van de Ven $start{$func} = $1; 111d3f8ddeaSArjan van de Ven $type{$func} = 1; 112d3f8ddeaSArjan van de Ven if ($1 < $firsttime) { 113d3f8ddeaSArjan van de Ven $firsttime = $1; 114d3f8ddeaSArjan van de Ven } 115d3f8ddeaSArjan van de Ven } 116d3f8ddeaSArjan van de Ven $pids{$func} = $pid; 117d3f8ddeaSArjan van de Ven $count = $count + 1; 118d3f8ddeaSArjan van de Ven } 119d3f8ddeaSArjan van de Ven 1200bb98e23SMichael Neuling if ($line =~ /([0-9\.]+)\] initcall ([a-zA-Z0-9\_\.]+)\+.*returned/) { 121aa5d9151SArjan van de Ven if ($done == 0) { 122aa5d9151SArjan van de Ven $end{$2} = $1; 123aa5d9151SArjan van de Ven $maxtime = $1; 124aa5d9151SArjan van de Ven } 125aa5d9151SArjan van de Ven } 126d3f8ddeaSArjan van de Ven 127d3f8ddeaSArjan van de Ven if ($line =~ /([0-9\.]+)\] async_continuing @ ([0-9]+)/) { 128d3f8ddeaSArjan van de Ven my $pid = $2; 129d3f8ddeaSArjan van de Ven my $func = "wait_" . $pid . "_" . $pidctr{$pid}; 130d3f8ddeaSArjan van de Ven $end{$func} = $1; 131d3f8ddeaSArjan van de Ven $maxtime = $1; 132d3f8ddeaSArjan van de Ven } 133aa5d9151SArjan van de Ven if ($line =~ /Write protecting the/) { 134aa5d9151SArjan van de Ven $done = 1; 135aa5d9151SArjan van de Ven } 13680a398a5SArjan van de Ven if ($line =~ /Freeing unused kernel memory/) { 13780a398a5SArjan van de Ven $done = 1; 13880a398a5SArjan van de Ven } 139aa5d9151SArjan van de Ven} 140aa5d9151SArjan van de Ven 141aa5d9151SArjan van de Venif ($count == 0) { 142d1aaf8cfSStephen Hemminger print STDERR <<END; 143d1aaf8cfSStephen HemmingerNo data found in the dmesg. Make sure that 'printk.time=1' and 144d1aaf8cfSStephen Hemminger'initcall_debug' are passed on the kernel command line. 145d1aaf8cfSStephen HemmingerEND 146*67554faaSFabian Frederick help(1); 147d1aaf8cfSStephen Hemminger exit 1; 148aa5d9151SArjan van de Ven} 149aa5d9151SArjan van de Ven 150aa5d9151SArjan van de Venprint "<?xml version=\"1.0\" standalone=\"no\"?> \n"; 15140c8c85aSArjan van de Venprint "<svg width=\"2000\" height=\"100%\" version=\"1.1\" xmlns=\"http://www.w3.org/2000/svg\">\n"; 152aa5d9151SArjan van de Ven 153*67554faaSFabian Frederick 154*67554faaSFabian Frederickif ($header) { 155*67554faaSFabian Frederick my $version = `uname -a`; 156*67554faaSFabian Frederick my $date = `date`; 157*67554faaSFabian Frederick print "<text transform=\"translate($xheader,$yheader)\">Kernel version: $version</text>\n"; 158*67554faaSFabian Frederick $cyheader = $yheader+$headerstep; 159*67554faaSFabian Frederick print "<text transform=\"translate($xheader,$cyheader)\">Date: $date</text>\n"; 160*67554faaSFabian Frederick} 161*67554faaSFabian Frederick 162aa5d9151SArjan van de Venmy @styles; 163aa5d9151SArjan van de Ven 164aa5d9151SArjan van de Ven$styles[0] = "fill:rgb(0,0,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; 165aa5d9151SArjan van de Ven$styles[1] = "fill:rgb(0,255,0);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; 166aa5d9151SArjan van de Ven$styles[2] = "fill:rgb(255,0,20);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; 167aa5d9151SArjan van de Ven$styles[3] = "fill:rgb(255,255,20);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; 168aa5d9151SArjan van de Ven$styles[4] = "fill:rgb(255,0,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; 169aa5d9151SArjan van de Ven$styles[5] = "fill:rgb(0,255,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; 170aa5d9151SArjan van de Ven$styles[6] = "fill:rgb(0,128,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; 171aa5d9151SArjan van de Ven$styles[7] = "fill:rgb(0,255,128);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; 172aa5d9151SArjan van de Ven$styles[8] = "fill:rgb(255,0,128);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; 173aa5d9151SArjan van de Ven$styles[9] = "fill:rgb(255,255,128);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; 174aa5d9151SArjan van de Ven$styles[10] = "fill:rgb(255,128,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; 175aa5d9151SArjan van de Ven$styles[11] = "fill:rgb(128,255,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; 176aa5d9151SArjan van de Ven 177d3f8ddeaSArjan van de Venmy $style_wait = "fill:rgb(128,128,128);fill-opacity:0.5;stroke-width:0;stroke:rgb(0,0,0)"; 178d3f8ddeaSArjan van de Ven 17940c8c85aSArjan van de Venmy $mult = 1950.0 / ($maxtime - $firsttime); 18040c8c85aSArjan van de Venmy $threshold2 = ($maxtime - $firsttime) / 120.0; 18140c8c85aSArjan van de Venmy $threshold = $threshold2/10; 182aa5d9151SArjan van de Venmy $stylecounter = 0; 183ddc7a01aSFrederic Weisbeckermy %rows; 184ddc7a01aSFrederic Weisbeckermy $rowscount = 1; 18506d1cd26SAlan Jenkinsmy @initcalls = sort { $start{$a} <=> $start{$b} } keys(%start); 18668f96c0cSStephen Hemminger 18768f96c0cSStephen Hemmingerforeach my $key (@initcalls) { 188aa5d9151SArjan van de Ven my $duration = $end{$key} - $start{$key}; 189aa5d9151SArjan van de Ven 190aa5d9151SArjan van de Ven if ($duration >= $threshold) { 19140c8c85aSArjan van de Ven my ($s, $s2, $s3, $e, $w, $y, $y2, $style); 1922a813f8cSAlan Jenkins my $pid = $pids{$key}; 19307d18904SFrederic Weisbecker 19407d18904SFrederic Weisbecker if (!defined($rows{$pid})) { 19507d18904SFrederic Weisbecker $rows{$pid} = $rowscount; 19607d18904SFrederic Weisbecker $rowscount = $rowscount + 1; 19707d18904SFrederic Weisbecker } 19806d1cd26SAlan Jenkins $s = ($start{$key} - $firsttime) * $mult; 199aa5d9151SArjan van de Ven $s2 = $s + 6; 20040c8c85aSArjan van de Ven $s3 = $s + 1; 20180a398a5SArjan van de Ven $e = ($end{$key} - $firsttime) * $mult; 202aa5d9151SArjan van de Ven $w = $e - $s; 203aa5d9151SArjan van de Ven 204ddc7a01aSFrederic Weisbecker $y = $rows{$pid} * 150; 205aa5d9151SArjan van de Ven $y2 = $y + 4; 206aa5d9151SArjan van de Ven 207aa5d9151SArjan van de Ven $style = $styles[$stylecounter]; 208aa5d9151SArjan van de Ven $stylecounter = $stylecounter + 1; 209aa5d9151SArjan van de Ven if ($stylecounter > 11) { 210aa5d9151SArjan van de Ven $stylecounter = 0; 211aa5d9151SArjan van de Ven }; 212aa5d9151SArjan van de Ven 213d3f8ddeaSArjan van de Ven if ($type{$key} == 1) { 214d3f8ddeaSArjan van de Ven $y = $y + 15; 215d3f8ddeaSArjan van de Ven print "<rect x=\"$s\" width=\"$w\" y=\"$y\" height=\"115\" style=\"$style_wait\"/>\n"; 216d3f8ddeaSArjan van de Ven } else { 217aa5d9151SArjan van de Ven print "<rect x=\"$s\" width=\"$w\" y=\"$y\" height=\"145\" style=\"$style\"/>\n"; 21840c8c85aSArjan van de Ven if ($duration >= $threshold2) { 219aa5d9151SArjan van de Ven print "<text transform=\"translate($s2,$y2) rotate(90)\">$key</text>\n"; 22040c8c85aSArjan van de Ven } else { 22140c8c85aSArjan van de Ven print "<text transform=\"translate($s3,$y2) rotate(90)\" font-size=\"3pt\">$key</text>\n"; 22240c8c85aSArjan van de Ven } 223aa5d9151SArjan van de Ven } 224aa5d9151SArjan van de Ven } 225d3f8ddeaSArjan van de Ven} 226aa5d9151SArjan van de Ven 227aa5d9151SArjan van de Ven 228aa5d9151SArjan van de Ven# print the time line on top 22980a398a5SArjan van de Venmy $time = $firsttime; 23080a398a5SArjan van de Venmy $step = ($maxtime - $firsttime) / 15; 231aa5d9151SArjan van de Venwhile ($time < $maxtime) { 2322a813f8cSAlan Jenkins my $s3 = ($time - $firsttime) * $mult; 23380a398a5SArjan van de Ven my $tm = int($time * 100) / 100.0; 2342a813f8cSAlan Jenkins print "<text transform=\"translate($s3,89) rotate(90)\">$tm</text>\n"; 23580a398a5SArjan van de Ven $time = $time + $step; 236aa5d9151SArjan van de Ven} 237aa5d9151SArjan van de Ven 238aa5d9151SArjan van de Venprint "</svg>\n"; 239