Blame view

scripts/bootgraph.pl 5.62 KB
aa5d9151f   Arjan van de Ven   tracing/fastboot:...
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
  #!/usr/bin/perl
  
  # Copyright 2008, Intel Corporation
  #
  # This file is part of the Linux kernel
  #
  # This program file is free software; you can redistribute it and/or modify it
  # under the terms of the GNU General Public License as published by the
  # Free Software Foundation; version 2 of the License.
  #
  # This program is distributed in the hope that it will be useful, but WITHOUT
  # ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
  # FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
  # for more details.
  #
  # You should have received a copy of the GNU General Public License
  # along with this program in a file named COPYING; if not, write to the
  # Free Software Foundation, Inc.,
  # 51 Franklin Street, Fifth Floor,
  # Boston, MA 02110-1301 USA
  #
  # Authors:
  # 	Arjan van de Ven <arjan@linux.intel.com>
  
  
  #
  # This script turns a dmesg output into a SVG graphic that shows which
  # functions take how much time. You can view SVG graphics with various
  # programs, including Inkscape, The Gimp and Firefox.
  #
  #
  # For this script to work, the kernel needs to be compiled with the
  # CONFIG_PRINTK_TIME configuration option enabled, and with
  # "initcall_debug" passed on the kernel command line.
  #
  # usage:
  # 	dmesg | perl scripts/bootgraph.pl > output.svg
  #
2a813f8cd   Alan Jenkins   tracing/fastboot:...
39
40
41
42
  use strict;
  
  my %start;
  my %end;
d3f8ddea4   Arjan van de Ven   bootgraph: make t...
43
  my %type;
aa5d9151f   Arjan van de Ven   tracing/fastboot:...
44
  my $done = 0;
aa5d9151f   Arjan van de Ven   tracing/fastboot:...
45
  my $maxtime = 0;
c443453c6   Andrew Murray   bootgraph.pl: rel...
46
  my $firsttime = 99999;
aa5d9151f   Arjan van de Ven   tracing/fastboot:...
47
  my $count = 0;
ddc7a01aa   Frederic Weisbecker   tracing/fastboot:...
48
  my %pids;
d3f8ddea4   Arjan van de Ven   bootgraph: make t...
49
  my %pidctr;
ddc7a01aa   Frederic Weisbecker   tracing/fastboot:...
50

aa5d9151f   Arjan van de Ven   tracing/fastboot:...
51
52
  while (<>) {
  	my $line = $_;
0bb98e231   Michael Neuling   bootgraph: fix fo...
53
  	if ($line =~ /([0-9\.]+)\] calling  ([a-zA-Z0-9\_\.]+)\+/) {
aa5d9151f   Arjan van de Ven   tracing/fastboot:...
54
55
56
  		my $func = $2;
  		if ($done == 0) {
  			$start{$func} = $1;
d3f8ddea4   Arjan van de Ven   bootgraph: make t...
57
  			$type{$func} = 0;
80a398a55   Arjan van de Ven   tracing/fastboot:...
58
59
60
  			if ($1 < $firsttime) {
  				$firsttime = $1;
  			}
aa5d9151f   Arjan van de Ven   tracing/fastboot:...
61
  		}
aa5d9151f   Arjan van de Ven   tracing/fastboot:...
62
  		if ($line =~ /\@ ([0-9]+)/) {
ddc7a01aa   Frederic Weisbecker   tracing/fastboot:...
63
  			$pids{$func} = $1;
aa5d9151f   Arjan van de Ven   tracing/fastboot:...
64
65
66
  		}
  		$count = $count + 1;
  	}
d3f8ddea4   Arjan van de Ven   bootgraph: make t...
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
  	if ($line =~ /([0-9\.]+)\] async_waiting @ ([0-9]+)/) {
  		my $pid = $2;
  		my $func;
  		if (!defined($pidctr{$pid})) {
  			$func = "wait_" . $pid . "_1";
  			$pidctr{$pid} = 1;
  		} else {
  			$pidctr{$pid} = $pidctr{$pid} + 1;
  			$func = "wait_" . $pid . "_" . $pidctr{$pid};
  		}
  		if ($done == 0) {
  			$start{$func} = $1;
  			$type{$func} = 1;
  			if ($1 < $firsttime) {
  				$firsttime = $1;
  			}
  		}
  		$pids{$func} = $pid;
  		$count = $count + 1;
  	}
0bb98e231   Michael Neuling   bootgraph: fix fo...
87
  	if ($line =~ /([0-9\.]+)\] initcall ([a-zA-Z0-9\_\.]+)\+.*returned/) {
aa5d9151f   Arjan van de Ven   tracing/fastboot:...
88
89
90
91
92
  		if ($done == 0) {
  			$end{$2} = $1;
  			$maxtime = $1;
  		}
  	}
d3f8ddea4   Arjan van de Ven   bootgraph: make t...
93
94
95
96
97
98
99
  
  	if ($line =~ /([0-9\.]+)\] async_continuing @ ([0-9]+)/) {
  		my $pid = $2;
  		my $func =  "wait_" . $pid . "_" . $pidctr{$pid};
  		$end{$func} = $1;
  		$maxtime = $1;
  	}
aa5d9151f   Arjan van de Ven   tracing/fastboot:...
100
101
102
  	if ($line =~ /Write protecting the/) {
  		$done = 1;
  	}
80a398a55   Arjan van de Ven   tracing/fastboot:...
103
104
105
  	if ($line =~ /Freeing unused kernel memory/) {
  		$done = 1;
  	}
aa5d9151f   Arjan van de Ven   tracing/fastboot:...
106
107
108
  }
  
  if ($count == 0) {
d1aaf8cf8   Stephen Hemminger   tracing/fastboot:...
109
110
111
112
113
114
115
      print STDERR <<END;
  No data found in the dmesg. Make sure that 'printk.time=1' and
  'initcall_debug' are passed on the kernel command line.
  Usage:
        dmesg | perl scripts/bootgraph.pl > output.svg
  END
      exit 1;
aa5d9151f   Arjan van de Ven   tracing/fastboot:...
116
117
118
119
  }
  
  print "<?xml version=\"1.0\" standalone=\"no\"?> 
  ";
40c8c85a4   Arjan van de Ven   bootchart: improv...
120
121
  print "<svg width=\"2000\" height=\"100%\" version=\"1.1\" xmlns=\"http://www.w3.org/2000/svg\">
  ";
aa5d9151f   Arjan van de Ven   tracing/fastboot:...
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
  
  my @styles;
  
  $styles[0] = "fill:rgb(0,0,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)";
  $styles[1] = "fill:rgb(0,255,0);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)";
  $styles[2] = "fill:rgb(255,0,20);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)";
  $styles[3] = "fill:rgb(255,255,20);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)";
  $styles[4] = "fill:rgb(255,0,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)";
  $styles[5] = "fill:rgb(0,255,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)";
  $styles[6] = "fill:rgb(0,128,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)";
  $styles[7] = "fill:rgb(0,255,128);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)";
  $styles[8] = "fill:rgb(255,0,128);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)";
  $styles[9] = "fill:rgb(255,255,128);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)";
  $styles[10] = "fill:rgb(255,128,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)";
  $styles[11] = "fill:rgb(128,255,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)";
d3f8ddea4   Arjan van de Ven   bootgraph: make t...
137
  my $style_wait = "fill:rgb(128,128,128);fill-opacity:0.5;stroke-width:0;stroke:rgb(0,0,0)";
40c8c85a4   Arjan van de Ven   bootchart: improv...
138
139
140
  my $mult = 1950.0 / ($maxtime - $firsttime);
  my $threshold2 = ($maxtime - $firsttime) / 120.0;
  my $threshold = $threshold2/10;
aa5d9151f   Arjan van de Ven   tracing/fastboot:...
141
  my $stylecounter = 0;
ddc7a01aa   Frederic Weisbecker   tracing/fastboot:...
142
143
  my %rows;
  my $rowscount = 1;
06d1cd267   Alan Jenkins   tracing/fastboot:...
144
  my @initcalls = sort { $start{$a} <=> $start{$b} } keys(%start);
68f96c0c8   Stephen Hemminger   tracing/fastboot:...
145
146
  
  foreach my $key (@initcalls) {
aa5d9151f   Arjan van de Ven   tracing/fastboot:...
147
148
149
  	my $duration = $end{$key} - $start{$key};
  
  	if ($duration >= $threshold) {
40c8c85a4   Arjan van de Ven   bootchart: improv...
150
  		my ($s, $s2, $s3, $e, $w, $y, $y2, $style);
2a813f8cd   Alan Jenkins   tracing/fastboot:...
151
  		my $pid = $pids{$key};
07d189042   Frederic Weisbecker   tracing/fastboot:...
152
153
154
155
156
  
  		if (!defined($rows{$pid})) {
  			$rows{$pid} = $rowscount;
  			$rowscount = $rowscount + 1;
  		}
06d1cd267   Alan Jenkins   tracing/fastboot:...
157
  		$s = ($start{$key} - $firsttime) * $mult;
aa5d9151f   Arjan van de Ven   tracing/fastboot:...
158
  		$s2 = $s + 6;
40c8c85a4   Arjan van de Ven   bootchart: improv...
159
  		$s3 = $s + 1;
80a398a55   Arjan van de Ven   tracing/fastboot:...
160
  		$e = ($end{$key} - $firsttime) * $mult;
aa5d9151f   Arjan van de Ven   tracing/fastboot:...
161
  		$w = $e - $s;
ddc7a01aa   Frederic Weisbecker   tracing/fastboot:...
162
  		$y = $rows{$pid} * 150;
aa5d9151f   Arjan van de Ven   tracing/fastboot:...
163
164
165
166
167
168
169
  		$y2 = $y + 4;
  
  		$style = $styles[$stylecounter];
  		$stylecounter = $stylecounter + 1;
  		if ($stylecounter > 11) {
  			$stylecounter = 0;
  		};
d3f8ddea4   Arjan van de Ven   bootgraph: make t...
170
171
172
173
  		if ($type{$key} == 1) {
  			$y = $y + 15;
  			print "<rect x=\"$s\" width=\"$w\" y=\"$y\" height=\"115\" style=\"$style_wait\"/>
  ";
40c8c85a4   Arjan van de Ven   bootchart: improv...
174
  		} else {
d3f8ddea4   Arjan van de Ven   bootgraph: make t...
175
176
177
178
179
180
181
182
183
  			print "<rect x=\"$s\" width=\"$w\" y=\"$y\" height=\"145\" style=\"$style\"/>
  ";
  			if ($duration >= $threshold2) {
  				print "<text transform=\"translate($s2,$y2) rotate(90)\">$key</text>
  ";
  			} else {
  				print "<text transform=\"translate($s3,$y2) rotate(90)\" font-size=\"3pt\">$key</text>
  ";
  			}
40c8c85a4   Arjan van de Ven   bootchart: improv...
184
  		}
aa5d9151f   Arjan van de Ven   tracing/fastboot:...
185
186
187
188
189
  	}
  }
  
  
  # print the time line on top
80a398a55   Arjan van de Ven   tracing/fastboot:...
190
191
  my $time = $firsttime;
  my $step = ($maxtime - $firsttime) / 15;
aa5d9151f   Arjan van de Ven   tracing/fastboot:...
192
  while ($time < $maxtime) {
2a813f8cd   Alan Jenkins   tracing/fastboot:...
193
  	my $s3 = ($time - $firsttime) * $mult;
80a398a55   Arjan van de Ven   tracing/fastboot:...
194
  	my $tm = int($time * 100) / 100.0;
2a813f8cd   Alan Jenkins   tracing/fastboot:...
195
196
  	print "<text transform=\"translate($s3,89) rotate(90)\">$tm</text>
  ";
80a398a55   Arjan van de Ven   tracing/fastboot:...
197
  	$time = $time + $step;
aa5d9151f   Arjan van de Ven   tracing/fastboot:...
198
199
200
201
  }
  
  print "</svg>
  ";