the-tree/scripts/bootgraph.pl

0001 #!/usr/bin/env perl
0002 # SPDX-License-Identifier: GPL-2.0-only
0003
0004 # Copyright 2008, Intel Corporation
0005 #
0006 # This file is part of the Linux kernel
0007 #
0008 # Authors:
0009 #   Arjan van de Ven <arjan@linux.intel.com>
0010
0011
0012 #
0013 # This script turns a dmesg output into a SVG graphic that shows which
0014 # functions take how much time. You can view SVG graphics with various
0015 # programs, including Inkscape, The Gimp and Firefox.
0016 #
0017 #
0018 # For this script to work, the kernel needs to be compiled with the
0019 # CONFIG_PRINTK_TIME configuration option enabled, and with
0020 # "initcall_debug" passed on the kernel command line.
0021 #
0022 # usage:
0023 #   dmesg | perl scripts/bootgraph.pl > output.svg
0024 #
0025
0026 use strict;
0027 use Getopt::Long;
0028 my $header = 0;
0029
0030 sub help {
0031     my $text = << "EOM";
0032 Usage:
0033 1) dmesg | perl scripts/bootgraph.pl [OPTION] > output.svg
0034 2) perl scripts/bootgraph.pl -h
0035
0036 Options:
0037     -header Insert kernel version and date
0038 EOM
0039     my $std=shift;
0040     if ($std == 1) {
0041         print STDERR $text;
0042     } else {
0043         print $text;
0044     }
0045     exit;
0046 }
0047
0048 GetOptions(
0049     'h|help'    =>\&help,
0050     'header'    =>\$header
0051 );
0052
0053 my %start;
0054 my %end;
0055 my %type;
0056 my $done = 0;
0057 my $maxtime = 0;
0058 my $firsttime = 99999;
0059 my $count = 0;
0060 my %pids;
0061 my %pidctr;
0062
0063 my $headerstep = 20;
0064 my $xheader = 15;
0065 my $yheader = 25;
0066 my $cyheader = 0;
0067
0068 while (<>) {
0069     my $line = $_;
0070     if ($line =~ /([0-9\.]+)\] calling  ([a-zA-Z0-9\_\.]+)\+/) {
0071         my $func = $2;
0072         if ($done == 0) {
0073             $start{$func} = $1;
0074             $type{$func} = 0;
0075             if ($1 < $firsttime) {
0076                 $firsttime = $1;
0077             }
0078         }
0079         if ($line =~ /\@ ([0-9]+)/) {
0080             $pids{$func} = $1;
0081         }
0082         $count = $count + 1;
0083     }
0084
0085     if ($line =~ /([0-9\.]+)\] async_waiting @ ([0-9]+)/) {
0086         my $pid = $2;
0087         my $func;
0088         if (!defined($pidctr{$pid})) {
0089             $func = "wait_" . $pid . "_1";
0090             $pidctr{$pid} = 1;
0091         } else {
0092             $pidctr{$pid} = $pidctr{$pid} + 1;
0093             $func = "wait_" . $pid . "_" . $pidctr{$pid};
0094         }
0095         if ($done == 0) {
0096             $start{$func} = $1;
0097             $type{$func} = 1;
0098             if ($1 < $firsttime) {
0099                 $firsttime = $1;
0100             }
0101         }
0102         $pids{$func} = $pid;
0103         $count = $count + 1;
0104     }
0105
0106     if ($line =~ /([0-9\.]+)\] initcall ([a-zA-Z0-9\_\.]+)\+.*returned/) {
0107         if ($done == 0) {
0108             $end{$2} = $1;
0109             $maxtime = $1;
0110         }
0111     }
0112
0113     if ($line =~ /([0-9\.]+)\] async_continuing @ ([0-9]+)/) {
0114         my $pid = $2;
0115         my $func =  "wait_" . $pid . "_" . $pidctr{$pid};
0116         $end{$func} = $1;
0117         $maxtime = $1;
0118     }
0119     if ($line =~ /Write protecting the/) {
0120         $done = 1;
0121     }
0122     if ($line =~ /Freeing unused kernel memory/) {
0123         $done = 1;
0124     }
0125 }
0126
0127 if ($count == 0) {
0128     print STDERR <<END;
0129 No data found in the dmesg. Make sure that 'printk.time=1' and
0130 'initcall_debug' are passed on the kernel command line.
0131 END
0132     help(1);
0133     exit 1;
0134 }
0135
0136 print "<?xml version=\"1.0\" standalone=\"no\"?> \n";
0137 print "<svg width=\"2000\" height=\"100%\" version=\"1.1\" xmlns=\"http://www.w3.org/2000/svg\">\n";
0138
0139
0140 if ($header) {
0141     my $version = `uname -a`;
0142     my $date = `date`;
0143     print "<text transform=\"translate($xheader,$yheader)\">Kernel version: $version</text>\n";
0144     $cyheader = $yheader+$headerstep;
0145     print "<text transform=\"translate($xheader,$cyheader)\">Date: $date</text>\n";
0146 }
0147
0148 my @styles;
0149
0150 $styles[0] = "fill:rgb(0,0,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)";
0151 $styles[1] = "fill:rgb(0,255,0);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)";
0152 $styles[2] = "fill:rgb(255,0,20);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)";
0153 $styles[3] = "fill:rgb(255,255,20);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)";
0154 $styles[4] = "fill:rgb(255,0,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)";
0155 $styles[5] = "fill:rgb(0,255,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)";
0156 $styles[6] = "fill:rgb(0,128,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)";
0157 $styles[7] = "fill:rgb(0,255,128);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)";
0158 $styles[8] = "fill:rgb(255,0,128);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)";
0159 $styles[9] = "fill:rgb(255,255,128);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)";
0160 $styles[10] = "fill:rgb(255,128,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)";
0161 $styles[11] = "fill:rgb(128,255,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)";
0162
0163 my $style_wait = "fill:rgb(128,128,128);fill-opacity:0.5;stroke-width:0;stroke:rgb(0,0,0)";
0164
0165 my $mult = 1950.0 / ($maxtime - $firsttime);
0166 my $threshold2 = ($maxtime - $firsttime) / 120.0;
0167 my $threshold = $threshold2/10;
0168 my $stylecounter = 0;
0169 my %rows;
0170 my $rowscount = 1;
0171 my @initcalls = sort { $start{$a} <=> $start{$b} } keys(%start);
0172
0173 foreach my $key (@initcalls) {
0174     my $duration = $end{$key} - $start{$key};
0175
0176     if ($duration >= $threshold) {
0177         my ($s, $s2, $s3, $e, $w, $y, $y2, $style);
0178         my $pid = $pids{$key};
0179
0180         if (!defined($rows{$pid})) {
0181             $rows{$pid} = $rowscount;
0182             $rowscount = $rowscount + 1;
0183         }
0184         $s = ($start{$key} - $firsttime) * $mult;
0185         $s2 = $s + 6;
0186         $s3 = $s + 1;
0187         $e = ($end{$key} - $firsttime) * $mult;
0188         $w = $e - $s;
0189
0190         $y = $rows{$pid} * 150;
0191         $y2 = $y + 4;
0192
0193         $style = $styles[$stylecounter];
0194         $stylecounter = $stylecounter + 1;
0195         if ($stylecounter > 11) {
0196             $stylecounter = 0;
0197         };
0198
0199         if ($type{$key} == 1) {
0200             $y = $y + 15;
0201             print "<rect x=\"$s\" width=\"$w\" y=\"$y\" height=\"115\" style=\"$style_wait\"/>\n";
0202         } else {
0203             print "<rect x=\"$s\" width=\"$w\" y=\"$y\" height=\"145\" style=\"$style\"/>\n";
0204             if ($duration >= $threshold2) {
0205                 print "<text transform=\"translate($s2,$y2) rotate(90)\">$key</text>\n";
0206             } else {
0207                 print "<text transform=\"translate($s3,$y2) rotate(90)\" font-size=\"3pt\">$key</text>\n";
0208             }
0209         }
0210     }
0211 }
0212
0213
0214 # print the time line on top
0215 my $time = $firsttime;
0216 my $step = ($maxtime - $firsttime) / 15;
0217 while ($time < $maxtime) {
0218     my $s3 = ($time - $firsttime) * $mult;
0219     my $tm = int($time * 100) / 100.0;
0220     print "<text transform=\"translate($s3,89) rotate(90)\">$tm</text>\n";
0221     $time = $time + $step;
0222 }
0223
0224 print "</svg>\n";