Kamil Rytarowski | cb77f0d | 2017-05-07 23:25:26 +0200 | [diff] [blame] | 1 | #!/usr/bin/env perl |
Thomas Gleixner | c2e3011 | 2019-05-31 01:09:49 -0700 | [diff] [blame] | 2 | # SPDX-License-Identifier: GPL-2.0-only |
Arjan van de Ven | aa5d915 | 2008-09-13 09:36:06 -0700 | [diff] [blame] | 3 | |
| 4 | # Copyright 2008, Intel Corporation |
| 5 | # |
| 6 | # This file is part of the Linux kernel |
| 7 | # |
Arjan van de Ven | aa5d915 | 2008-09-13 09:36:06 -0700 | [diff] [blame] | 8 | # Authors: |
| 9 | # Arjan van de Ven <arjan@linux.intel.com> |
| 10 | |
| 11 | |
| 12 | # |
| 13 | # This script turns a dmesg output into a SVG graphic that shows which |
| 14 | # functions take how much time. You can view SVG graphics with various |
| 15 | # programs, including Inkscape, The Gimp and Firefox. |
| 16 | # |
| 17 | # |
| 18 | # For this script to work, the kernel needs to be compiled with the |
| 19 | # CONFIG_PRINTK_TIME configuration option enabled, and with |
| 20 | # "initcall_debug" passed on the kernel command line. |
| 21 | # |
| 22 | # usage: |
| 23 | # dmesg | perl scripts/bootgraph.pl > output.svg |
| 24 | # |
| 25 | |
Alan Jenkins | 2a813f8 | 2008-10-14 14:18:07 +0100 | [diff] [blame] | 26 | use strict; |
Fabian Frederick | 67554fa | 2014-04-02 21:39:52 +0200 | [diff] [blame] | 27 | use Getopt::Long; |
| 28 | my $header = 0; |
| 29 | |
| 30 | sub help { |
| 31 | my $text = << "EOM"; |
| 32 | Usage: |
| 33 | 1) dmesg | perl scripts/bootgraph.pl [OPTION] > output.svg |
| 34 | 2) perl scripts/bootgraph.pl -h |
| 35 | |
| 36 | Options: |
| 37 | -header Insert kernel version and date |
| 38 | EOM |
| 39 | my $std=shift; |
| 40 | if ($std == 1) { |
| 41 | print STDERR $text; |
| 42 | } else { |
| 43 | print $text; |
| 44 | } |
| 45 | exit; |
| 46 | } |
| 47 | |
| 48 | GetOptions( |
| 49 | 'h|help' =>\&help, |
| 50 | 'header' =>\$header |
| 51 | ); |
Alan Jenkins | 2a813f8 | 2008-10-14 14:18:07 +0100 | [diff] [blame] | 52 | |
| 53 | my %start; |
| 54 | my %end; |
Arjan van de Ven | d3f8dde | 2009-01-10 10:03:05 -0800 | [diff] [blame] | 55 | my %type; |
Arjan van de Ven | aa5d915 | 2008-09-13 09:36:06 -0700 | [diff] [blame] | 56 | my $done = 0; |
Arjan van de Ven | aa5d915 | 2008-09-13 09:36:06 -0700 | [diff] [blame] | 57 | my $maxtime = 0; |
Andrew Murray | c443453 | 2011-06-09 22:40:10 +0100 | [diff] [blame] | 58 | my $firsttime = 99999; |
Arjan van de Ven | aa5d915 | 2008-09-13 09:36:06 -0700 | [diff] [blame] | 59 | my $count = 0; |
Frederic Weisbecker | ddc7a01 | 2008-10-04 21:35:48 +0200 | [diff] [blame] | 60 | my %pids; |
Arjan van de Ven | d3f8dde | 2009-01-10 10:03:05 -0800 | [diff] [blame] | 61 | my %pidctr; |
Frederic Weisbecker | ddc7a01 | 2008-10-04 21:35:48 +0200 | [diff] [blame] | 62 | |
Fabian Frederick | 67554fa | 2014-04-02 21:39:52 +0200 | [diff] [blame] | 63 | my $headerstep = 20; |
| 64 | my $xheader = 15; |
| 65 | my $yheader = 25; |
| 66 | my $cyheader = 0; |
| 67 | |
Arjan van de Ven | aa5d915 | 2008-09-13 09:36:06 -0700 | [diff] [blame] | 68 | while (<>) { |
| 69 | my $line = $_; |
Michael Neuling | 0bb98e2 | 2009-02-15 10:20:30 +0100 | [diff] [blame] | 70 | if ($line =~ /([0-9\.]+)\] calling ([a-zA-Z0-9\_\.]+)\+/) { |
Arjan van de Ven | aa5d915 | 2008-09-13 09:36:06 -0700 | [diff] [blame] | 71 | my $func = $2; |
| 72 | if ($done == 0) { |
| 73 | $start{$func} = $1; |
Arjan van de Ven | d3f8dde | 2009-01-10 10:03:05 -0800 | [diff] [blame] | 74 | $type{$func} = 0; |
Arjan van de Ven | 80a398a | 2008-09-14 15:30:52 -0700 | [diff] [blame] | 75 | if ($1 < $firsttime) { |
| 76 | $firsttime = $1; |
| 77 | } |
Arjan van de Ven | aa5d915 | 2008-09-13 09:36:06 -0700 | [diff] [blame] | 78 | } |
Arjan van de Ven | aa5d915 | 2008-09-13 09:36:06 -0700 | [diff] [blame] | 79 | if ($line =~ /\@ ([0-9]+)/) { |
Frederic Weisbecker | ddc7a01 | 2008-10-04 21:35:48 +0200 | [diff] [blame] | 80 | $pids{$func} = $1; |
Arjan van de Ven | aa5d915 | 2008-09-13 09:36:06 -0700 | [diff] [blame] | 81 | } |
| 82 | $count = $count + 1; |
| 83 | } |
| 84 | |
Arjan van de Ven | d3f8dde | 2009-01-10 10:03:05 -0800 | [diff] [blame] | 85 | if ($line =~ /([0-9\.]+)\] async_waiting @ ([0-9]+)/) { |
| 86 | my $pid = $2; |
| 87 | my $func; |
| 88 | if (!defined($pidctr{$pid})) { |
| 89 | $func = "wait_" . $pid . "_1"; |
| 90 | $pidctr{$pid} = 1; |
| 91 | } else { |
| 92 | $pidctr{$pid} = $pidctr{$pid} + 1; |
| 93 | $func = "wait_" . $pid . "_" . $pidctr{$pid}; |
| 94 | } |
| 95 | if ($done == 0) { |
| 96 | $start{$func} = $1; |
| 97 | $type{$func} = 1; |
| 98 | if ($1 < $firsttime) { |
| 99 | $firsttime = $1; |
| 100 | } |
| 101 | } |
| 102 | $pids{$func} = $pid; |
| 103 | $count = $count + 1; |
| 104 | } |
| 105 | |
Michael Neuling | 0bb98e2 | 2009-02-15 10:20:30 +0100 | [diff] [blame] | 106 | if ($line =~ /([0-9\.]+)\] initcall ([a-zA-Z0-9\_\.]+)\+.*returned/) { |
Arjan van de Ven | aa5d915 | 2008-09-13 09:36:06 -0700 | [diff] [blame] | 107 | if ($done == 0) { |
| 108 | $end{$2} = $1; |
| 109 | $maxtime = $1; |
| 110 | } |
| 111 | } |
Arjan van de Ven | d3f8dde | 2009-01-10 10:03:05 -0800 | [diff] [blame] | 112 | |
| 113 | if ($line =~ /([0-9\.]+)\] async_continuing @ ([0-9]+)/) { |
| 114 | my $pid = $2; |
| 115 | my $func = "wait_" . $pid . "_" . $pidctr{$pid}; |
| 116 | $end{$func} = $1; |
| 117 | $maxtime = $1; |
| 118 | } |
Arjan van de Ven | aa5d915 | 2008-09-13 09:36:06 -0700 | [diff] [blame] | 119 | if ($line =~ /Write protecting the/) { |
| 120 | $done = 1; |
| 121 | } |
Arjan van de Ven | 80a398a | 2008-09-14 15:30:52 -0700 | [diff] [blame] | 122 | if ($line =~ /Freeing unused kernel memory/) { |
| 123 | $done = 1; |
| 124 | } |
Arjan van de Ven | aa5d915 | 2008-09-13 09:36:06 -0700 | [diff] [blame] | 125 | } |
| 126 | |
| 127 | if ($count == 0) { |
Stephen Hemminger | d1aaf8c | 2008-11-13 08:33:00 -0800 | [diff] [blame] | 128 | print STDERR <<END; |
| 129 | No data found in the dmesg. Make sure that 'printk.time=1' and |
| 130 | 'initcall_debug' are passed on the kernel command line. |
Stephen Hemminger | d1aaf8c | 2008-11-13 08:33:00 -0800 | [diff] [blame] | 131 | END |
Fabian Frederick | 67554fa | 2014-04-02 21:39:52 +0200 | [diff] [blame] | 132 | help(1); |
Stephen Hemminger | d1aaf8c | 2008-11-13 08:33:00 -0800 | [diff] [blame] | 133 | exit 1; |
Arjan van de Ven | aa5d915 | 2008-09-13 09:36:06 -0700 | [diff] [blame] | 134 | } |
| 135 | |
| 136 | print "<?xml version=\"1.0\" standalone=\"no\"?> \n"; |
Arjan van de Ven | 40c8c85 | 2009-01-04 07:16:38 -0800 | [diff] [blame] | 137 | print "<svg width=\"2000\" height=\"100%\" version=\"1.1\" xmlns=\"http://www.w3.org/2000/svg\">\n"; |
Arjan van de Ven | aa5d915 | 2008-09-13 09:36:06 -0700 | [diff] [blame] | 138 | |
Fabian Frederick | 67554fa | 2014-04-02 21:39:52 +0200 | [diff] [blame] | 139 | |
| 140 | if ($header) { |
| 141 | my $version = `uname -a`; |
| 142 | my $date = `date`; |
| 143 | print "<text transform=\"translate($xheader,$yheader)\">Kernel version: $version</text>\n"; |
| 144 | $cyheader = $yheader+$headerstep; |
| 145 | print "<text transform=\"translate($xheader,$cyheader)\">Date: $date</text>\n"; |
| 146 | } |
| 147 | |
Arjan van de Ven | aa5d915 | 2008-09-13 09:36:06 -0700 | [diff] [blame] | 148 | my @styles; |
| 149 | |
| 150 | $styles[0] = "fill:rgb(0,0,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; |
| 151 | $styles[1] = "fill:rgb(0,255,0);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; |
| 152 | $styles[2] = "fill:rgb(255,0,20);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; |
| 153 | $styles[3] = "fill:rgb(255,255,20);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; |
| 154 | $styles[4] = "fill:rgb(255,0,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; |
| 155 | $styles[5] = "fill:rgb(0,255,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; |
| 156 | $styles[6] = "fill:rgb(0,128,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; |
| 157 | $styles[7] = "fill:rgb(0,255,128);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; |
| 158 | $styles[8] = "fill:rgb(255,0,128);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; |
| 159 | $styles[9] = "fill:rgb(255,255,128);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; |
| 160 | $styles[10] = "fill:rgb(255,128,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; |
| 161 | $styles[11] = "fill:rgb(128,255,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; |
| 162 | |
Arjan van de Ven | d3f8dde | 2009-01-10 10:03:05 -0800 | [diff] [blame] | 163 | my $style_wait = "fill:rgb(128,128,128);fill-opacity:0.5;stroke-width:0;stroke:rgb(0,0,0)"; |
| 164 | |
Arjan van de Ven | 40c8c85 | 2009-01-04 07:16:38 -0800 | [diff] [blame] | 165 | my $mult = 1950.0 / ($maxtime - $firsttime); |
| 166 | my $threshold2 = ($maxtime - $firsttime) / 120.0; |
| 167 | my $threshold = $threshold2/10; |
Arjan van de Ven | aa5d915 | 2008-09-13 09:36:06 -0700 | [diff] [blame] | 168 | my $stylecounter = 0; |
Frederic Weisbecker | ddc7a01 | 2008-10-04 21:35:48 +0200 | [diff] [blame] | 169 | my %rows; |
| 170 | my $rowscount = 1; |
Alan Jenkins | 06d1cd2 | 2008-10-14 14:19:15 +0100 | [diff] [blame] | 171 | my @initcalls = sort { $start{$a} <=> $start{$b} } keys(%start); |
Stephen Hemminger | 68f96c0 | 2008-11-12 10:21:01 -0800 | [diff] [blame] | 172 | |
| 173 | foreach my $key (@initcalls) { |
Arjan van de Ven | aa5d915 | 2008-09-13 09:36:06 -0700 | [diff] [blame] | 174 | my $duration = $end{$key} - $start{$key}; |
| 175 | |
| 176 | if ($duration >= $threshold) { |
Arjan van de Ven | 40c8c85 | 2009-01-04 07:16:38 -0800 | [diff] [blame] | 177 | my ($s, $s2, $s3, $e, $w, $y, $y2, $style); |
Alan Jenkins | 2a813f8 | 2008-10-14 14:18:07 +0100 | [diff] [blame] | 178 | my $pid = $pids{$key}; |
Frederic Weisbecker | 07d1890 | 2008-10-04 21:35:48 +0200 | [diff] [blame] | 179 | |
| 180 | if (!defined($rows{$pid})) { |
| 181 | $rows{$pid} = $rowscount; |
| 182 | $rowscount = $rowscount + 1; |
| 183 | } |
Alan Jenkins | 06d1cd2 | 2008-10-14 14:19:15 +0100 | [diff] [blame] | 184 | $s = ($start{$key} - $firsttime) * $mult; |
Arjan van de Ven | aa5d915 | 2008-09-13 09:36:06 -0700 | [diff] [blame] | 185 | $s2 = $s + 6; |
Arjan van de Ven | 40c8c85 | 2009-01-04 07:16:38 -0800 | [diff] [blame] | 186 | $s3 = $s + 1; |
Arjan van de Ven | 80a398a | 2008-09-14 15:30:52 -0700 | [diff] [blame] | 187 | $e = ($end{$key} - $firsttime) * $mult; |
Arjan van de Ven | aa5d915 | 2008-09-13 09:36:06 -0700 | [diff] [blame] | 188 | $w = $e - $s; |
| 189 | |
Frederic Weisbecker | ddc7a01 | 2008-10-04 21:35:48 +0200 | [diff] [blame] | 190 | $y = $rows{$pid} * 150; |
Arjan van de Ven | aa5d915 | 2008-09-13 09:36:06 -0700 | [diff] [blame] | 191 | $y2 = $y + 4; |
| 192 | |
| 193 | $style = $styles[$stylecounter]; |
| 194 | $stylecounter = $stylecounter + 1; |
| 195 | if ($stylecounter > 11) { |
| 196 | $stylecounter = 0; |
| 197 | }; |
| 198 | |
Arjan van de Ven | d3f8dde | 2009-01-10 10:03:05 -0800 | [diff] [blame] | 199 | if ($type{$key} == 1) { |
| 200 | $y = $y + 15; |
| 201 | print "<rect x=\"$s\" width=\"$w\" y=\"$y\" height=\"115\" style=\"$style_wait\"/>\n"; |
Arjan van de Ven | 40c8c85 | 2009-01-04 07:16:38 -0800 | [diff] [blame] | 202 | } else { |
Arjan van de Ven | d3f8dde | 2009-01-10 10:03:05 -0800 | [diff] [blame] | 203 | print "<rect x=\"$s\" width=\"$w\" y=\"$y\" height=\"145\" style=\"$style\"/>\n"; |
| 204 | if ($duration >= $threshold2) { |
| 205 | print "<text transform=\"translate($s2,$y2) rotate(90)\">$key</text>\n"; |
| 206 | } else { |
| 207 | print "<text transform=\"translate($s3,$y2) rotate(90)\" font-size=\"3pt\">$key</text>\n"; |
| 208 | } |
Arjan van de Ven | 40c8c85 | 2009-01-04 07:16:38 -0800 | [diff] [blame] | 209 | } |
Arjan van de Ven | aa5d915 | 2008-09-13 09:36:06 -0700 | [diff] [blame] | 210 | } |
| 211 | } |
| 212 | |
| 213 | |
| 214 | # print the time line on top |
Arjan van de Ven | 80a398a | 2008-09-14 15:30:52 -0700 | [diff] [blame] | 215 | my $time = $firsttime; |
| 216 | my $step = ($maxtime - $firsttime) / 15; |
Arjan van de Ven | aa5d915 | 2008-09-13 09:36:06 -0700 | [diff] [blame] | 217 | while ($time < $maxtime) { |
Alan Jenkins | 2a813f8 | 2008-10-14 14:18:07 +0100 | [diff] [blame] | 218 | my $s3 = ($time - $firsttime) * $mult; |
Arjan van de Ven | 80a398a | 2008-09-14 15:30:52 -0700 | [diff] [blame] | 219 | my $tm = int($time * 100) / 100.0; |
Alan Jenkins | 2a813f8 | 2008-10-14 14:18:07 +0100 | [diff] [blame] | 220 | print "<text transform=\"translate($s3,89) rotate(90)\">$tm</text>\n"; |
Arjan van de Ven | 80a398a | 2008-09-14 15:30:52 -0700 | [diff] [blame] | 221 | $time = $time + $step; |
Arjan van de Ven | aa5d915 | 2008-09-13 09:36:06 -0700 | [diff] [blame] | 222 | } |
| 223 | |
| 224 | print "</svg>\n"; |