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
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
|
From 77e9695b9d5c9ce761dedc193045d9cb64b8e245 Mon Sep 17 00:00:00 2001
From: Arjan van de Ven <arjan@linux.intel.com>
Date: Sat, 13 Sep 2008 09:36:06 -0700
Subject: [PATCH] Add a script to visualize the kernel boot process / time
When optimizing the kernel boot time, it's very valuable to visualize
what is going on at which time. In addition, with the fastboot asynchronous
initcall level, it's very valuable to see which initcall gets run where
and when.
This patch adds a script to turn a dmesg into a SVG graph (that can be
shown with tools such as InkScape, Gimp or Firefox) and a small change
to the initcall code to print the PID of the thread calling the initcall
(so that the script can work out the parallelism).
Signed-off-by: Arjan van de Ven <arjan@linux.intel.com>
---
init/main.c | 1
scripts/bootgraph.pl | 138 +++++++++++++++++++++++++++++++++++++++++++++++++++
2 files changed, 139 insertions(+)
create mode 100644 scripts/bootgraph.pl
Index: linux-2.6.27/init/main.c
===================================================================
--- linux-2.6.27.orig/init/main.c 2008-10-14 17:02:46.000000000 +0200
+++ linux-2.6.27/init/main.c 2008-10-14 17:05:23.000000000 +0200
@@ -709,6 +709,7 @@ int do_one_initcall(initcall_t fn)
if (initcall_debug) {
printk("calling %pF\n", fn);
+ printk(" @ %i\n", task_pid_nr(current));
t0 = ktime_get();
}
Index: linux-2.6.27/scripts/bootgraph.pl
===================================================================
--- /dev/null 1970-01-01 00:00:00.000000000 +0000
+++ linux-2.6.27/scripts/bootgraph.pl 2008-10-14 17:03:34.000000000 +0200
@@ -0,0 +1,138 @@
+#!/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
+#
+
+my @rows;
+my %start, %end, %row;
+my $done = 0;
+my $rowcount = 0;
+my $maxtime = 0;
+my $count = 0;
+while (<>) {
+ my $line = $_;
+ if ($line =~ /([0-9\.]+)\] calling ([a-zA-Z\_]+)\+/) {
+ my $func = $2;
+ if ($done == 0) {
+ $start{$func} = $1;
+ }
+ $row{$func} = 1;
+ if ($line =~ /\@ ([0-9]+)/) {
+ my $pid = $1;
+ if (!defined($rows[$pid])) {
+ $rowcount = $rowcount + 1;
+ $rows[$pid] = $rowcount;
+ }
+ $row{$func} = $rows[$pid];
+ }
+ $count = $count + 1;
+ }
+
+ if ($line =~ /([0-9\.]+)\] initcall ([a-zA-Z\_]+)\+.*returned/) {
+ if ($done == 0) {
+ $end{$2} = $1;
+ $maxtime = $1;
+ }
+ }
+ if ($line =~ /Write protecting the/) {
+ $done = 1;
+ }
+}
+
+if ($count == 0) {
+ print "No data found in the dmesg. Make sure CONFIG_PRINTK_TIME is enabled and\n";
+ print "that initcall_debug is passed on the kernel command line.\n\n";
+ print "Usage: \n";
+ print " dmesg | perl scripts/bootgraph.pl > output.svg\n\n";
+ exit;
+}
+
+print "<?xml version=\"1.0\" standalone=\"no\"?> \n";
+print "<svg width=\"1000\" height=\"100%\" version=\"1.1\" xmlns=\"http://www.w3.org/2000/svg\">\n";
+
+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)";
+
+my $mult = 950.0 / $maxtime;
+my $threshold = 0.0500 / $maxtime;
+my $stylecounter = 0;
+while (($key,$value) = each %start) {
+ my $duration = $end{$key} - $start{$key};
+
+ if ($duration >= $threshold) {
+ my $s, $s2, $e, $y;
+ $s = $value * $mult;
+ $s2 = $s + 6;
+ $e = $end{$key} * $mult;
+ $w = $e - $s;
+
+ $y = $row{$key} * 150;
+ $y2 = $y + 4;
+
+ $style = $styles[$stylecounter];
+ $stylecounter = $stylecounter + 1;
+ if ($stylecounter > 11) {
+ $stylecounter = 0;
+ };
+
+ print "<rect x=\"$s\" width=\"$w\" y=\"$y\" height=\"145\" style=\"$style\"/>\n";
+ print "<text transform=\"translate($s2,$y2) rotate(90)\">$key</text>\n";
+ }
+}
+
+
+# print the time line on top
+my $time = 0.0;
+while ($time < $maxtime) {
+ my $s2 = $time * $mult;
+ print "<text transform=\"translate($s2,89) rotate(90)\">$time</text>\n";
+ $time = $time + 0.1;
+}
+
+print "</svg>\n";
|
