162306a36Sopenharmony_ci#!/usr/bin/env perl 262306a36Sopenharmony_ci# SPDX-License-Identifier: GPL-2.0-only 362306a36Sopenharmony_ci 462306a36Sopenharmony_ci# Copyright 2008, Intel Corporation 562306a36Sopenharmony_ci# 662306a36Sopenharmony_ci# This file is part of the Linux kernel 762306a36Sopenharmony_ci# 862306a36Sopenharmony_ci# Authors: 962306a36Sopenharmony_ci# Arjan van de Ven <arjan@linux.intel.com> 1062306a36Sopenharmony_ci 1162306a36Sopenharmony_ci 1262306a36Sopenharmony_ci# 1362306a36Sopenharmony_ci# This script turns a dmesg output into a SVG graphic that shows which 1462306a36Sopenharmony_ci# functions take how much time. You can view SVG graphics with various 1562306a36Sopenharmony_ci# programs, including Inkscape, The Gimp and Firefox. 1662306a36Sopenharmony_ci# 1762306a36Sopenharmony_ci# 1862306a36Sopenharmony_ci# For this script to work, the kernel needs to be compiled with the 1962306a36Sopenharmony_ci# CONFIG_PRINTK_TIME configuration option enabled, and with 2062306a36Sopenharmony_ci# "initcall_debug" passed on the kernel command line. 2162306a36Sopenharmony_ci# 2262306a36Sopenharmony_ci# usage: 2362306a36Sopenharmony_ci# dmesg | perl scripts/bootgraph.pl > output.svg 2462306a36Sopenharmony_ci# 2562306a36Sopenharmony_ci 2662306a36Sopenharmony_ciuse strict; 2762306a36Sopenharmony_ciuse Getopt::Long; 2862306a36Sopenharmony_cimy $header = 0; 2962306a36Sopenharmony_ci 3062306a36Sopenharmony_cisub help { 3162306a36Sopenharmony_ci my $text = << "EOM"; 3262306a36Sopenharmony_ciUsage: 3362306a36Sopenharmony_ci1) dmesg | perl scripts/bootgraph.pl [OPTION] > output.svg 3462306a36Sopenharmony_ci2) perl scripts/bootgraph.pl -h 3562306a36Sopenharmony_ci 3662306a36Sopenharmony_ciOptions: 3762306a36Sopenharmony_ci -header Insert kernel version and date 3862306a36Sopenharmony_ciEOM 3962306a36Sopenharmony_ci my $std=shift; 4062306a36Sopenharmony_ci if ($std == 1) { 4162306a36Sopenharmony_ci print STDERR $text; 4262306a36Sopenharmony_ci } else { 4362306a36Sopenharmony_ci print $text; 4462306a36Sopenharmony_ci } 4562306a36Sopenharmony_ci exit; 4662306a36Sopenharmony_ci} 4762306a36Sopenharmony_ci 4862306a36Sopenharmony_ciGetOptions( 4962306a36Sopenharmony_ci 'h|help' =>\&help, 5062306a36Sopenharmony_ci 'header' =>\$header 5162306a36Sopenharmony_ci); 5262306a36Sopenharmony_ci 5362306a36Sopenharmony_cimy %start; 5462306a36Sopenharmony_cimy %end; 5562306a36Sopenharmony_cimy %type; 5662306a36Sopenharmony_cimy $done = 0; 5762306a36Sopenharmony_cimy $maxtime = 0; 5862306a36Sopenharmony_cimy $firsttime = 99999; 5962306a36Sopenharmony_cimy $count = 0; 6062306a36Sopenharmony_cimy %pids; 6162306a36Sopenharmony_cimy %pidctr; 6262306a36Sopenharmony_ci 6362306a36Sopenharmony_cimy $headerstep = 20; 6462306a36Sopenharmony_cimy $xheader = 15; 6562306a36Sopenharmony_cimy $yheader = 25; 6662306a36Sopenharmony_cimy $cyheader = 0; 6762306a36Sopenharmony_ci 6862306a36Sopenharmony_ciwhile (<>) { 6962306a36Sopenharmony_ci my $line = $_; 7062306a36Sopenharmony_ci if ($line =~ /([0-9\.]+)\] calling ([a-zA-Z0-9\_\.]+)\+/) { 7162306a36Sopenharmony_ci my $func = $2; 7262306a36Sopenharmony_ci if ($done == 0) { 7362306a36Sopenharmony_ci $start{$func} = $1; 7462306a36Sopenharmony_ci $type{$func} = 0; 7562306a36Sopenharmony_ci if ($1 < $firsttime) { 7662306a36Sopenharmony_ci $firsttime = $1; 7762306a36Sopenharmony_ci } 7862306a36Sopenharmony_ci } 7962306a36Sopenharmony_ci if ($line =~ /\@ ([0-9]+)/) { 8062306a36Sopenharmony_ci $pids{$func} = $1; 8162306a36Sopenharmony_ci } 8262306a36Sopenharmony_ci $count = $count + 1; 8362306a36Sopenharmony_ci } 8462306a36Sopenharmony_ci 8562306a36Sopenharmony_ci if ($line =~ /([0-9\.]+)\] async_waiting @ ([0-9]+)/) { 8662306a36Sopenharmony_ci my $pid = $2; 8762306a36Sopenharmony_ci my $func; 8862306a36Sopenharmony_ci if (!defined($pidctr{$pid})) { 8962306a36Sopenharmony_ci $func = "wait_" . $pid . "_1"; 9062306a36Sopenharmony_ci $pidctr{$pid} = 1; 9162306a36Sopenharmony_ci } else { 9262306a36Sopenharmony_ci $pidctr{$pid} = $pidctr{$pid} + 1; 9362306a36Sopenharmony_ci $func = "wait_" . $pid . "_" . $pidctr{$pid}; 9462306a36Sopenharmony_ci } 9562306a36Sopenharmony_ci if ($done == 0) { 9662306a36Sopenharmony_ci $start{$func} = $1; 9762306a36Sopenharmony_ci $type{$func} = 1; 9862306a36Sopenharmony_ci if ($1 < $firsttime) { 9962306a36Sopenharmony_ci $firsttime = $1; 10062306a36Sopenharmony_ci } 10162306a36Sopenharmony_ci } 10262306a36Sopenharmony_ci $pids{$func} = $pid; 10362306a36Sopenharmony_ci $count = $count + 1; 10462306a36Sopenharmony_ci } 10562306a36Sopenharmony_ci 10662306a36Sopenharmony_ci if ($line =~ /([0-9\.]+)\] initcall ([a-zA-Z0-9\_\.]+)\+.*returned/) { 10762306a36Sopenharmony_ci if ($done == 0) { 10862306a36Sopenharmony_ci $end{$2} = $1; 10962306a36Sopenharmony_ci $maxtime = $1; 11062306a36Sopenharmony_ci } 11162306a36Sopenharmony_ci } 11262306a36Sopenharmony_ci 11362306a36Sopenharmony_ci if ($line =~ /([0-9\.]+)\] async_continuing @ ([0-9]+)/) { 11462306a36Sopenharmony_ci my $pid = $2; 11562306a36Sopenharmony_ci my $func = "wait_" . $pid . "_" . $pidctr{$pid}; 11662306a36Sopenharmony_ci $end{$func} = $1; 11762306a36Sopenharmony_ci $maxtime = $1; 11862306a36Sopenharmony_ci } 11962306a36Sopenharmony_ci if ($line =~ /Write protecting the/) { 12062306a36Sopenharmony_ci $done = 1; 12162306a36Sopenharmony_ci } 12262306a36Sopenharmony_ci if ($line =~ /Freeing unused kernel memory/) { 12362306a36Sopenharmony_ci $done = 1; 12462306a36Sopenharmony_ci } 12562306a36Sopenharmony_ci} 12662306a36Sopenharmony_ci 12762306a36Sopenharmony_ciif ($count == 0) { 12862306a36Sopenharmony_ci print STDERR <<END; 12962306a36Sopenharmony_ciNo data found in the dmesg. Make sure that 'printk.time=1' and 13062306a36Sopenharmony_ci'initcall_debug' are passed on the kernel command line. 13162306a36Sopenharmony_ciEND 13262306a36Sopenharmony_ci help(1); 13362306a36Sopenharmony_ci exit 1; 13462306a36Sopenharmony_ci} 13562306a36Sopenharmony_ci 13662306a36Sopenharmony_ciprint "<?xml version=\"1.0\" standalone=\"no\"?> \n"; 13762306a36Sopenharmony_ciprint "<svg width=\"2000\" height=\"100%\" version=\"1.1\" xmlns=\"http://www.w3.org/2000/svg\">\n"; 13862306a36Sopenharmony_ci 13962306a36Sopenharmony_ci 14062306a36Sopenharmony_ciif ($header) { 14162306a36Sopenharmony_ci my $version = `uname -a`; 14262306a36Sopenharmony_ci my $date = `date`; 14362306a36Sopenharmony_ci print "<text transform=\"translate($xheader,$yheader)\">Kernel version: $version</text>\n"; 14462306a36Sopenharmony_ci $cyheader = $yheader+$headerstep; 14562306a36Sopenharmony_ci print "<text transform=\"translate($xheader,$cyheader)\">Date: $date</text>\n"; 14662306a36Sopenharmony_ci} 14762306a36Sopenharmony_ci 14862306a36Sopenharmony_cimy @styles; 14962306a36Sopenharmony_ci 15062306a36Sopenharmony_ci$styles[0] = "fill:rgb(0,0,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; 15162306a36Sopenharmony_ci$styles[1] = "fill:rgb(0,255,0);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; 15262306a36Sopenharmony_ci$styles[2] = "fill:rgb(255,0,20);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; 15362306a36Sopenharmony_ci$styles[3] = "fill:rgb(255,255,20);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; 15462306a36Sopenharmony_ci$styles[4] = "fill:rgb(255,0,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; 15562306a36Sopenharmony_ci$styles[5] = "fill:rgb(0,255,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; 15662306a36Sopenharmony_ci$styles[6] = "fill:rgb(0,128,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; 15762306a36Sopenharmony_ci$styles[7] = "fill:rgb(0,255,128);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; 15862306a36Sopenharmony_ci$styles[8] = "fill:rgb(255,0,128);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; 15962306a36Sopenharmony_ci$styles[9] = "fill:rgb(255,255,128);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; 16062306a36Sopenharmony_ci$styles[10] = "fill:rgb(255,128,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; 16162306a36Sopenharmony_ci$styles[11] = "fill:rgb(128,255,255);fill-opacity:0.5;stroke-width:1;stroke:rgb(0,0,0)"; 16262306a36Sopenharmony_ci 16362306a36Sopenharmony_cimy $style_wait = "fill:rgb(128,128,128);fill-opacity:0.5;stroke-width:0;stroke:rgb(0,0,0)"; 16462306a36Sopenharmony_ci 16562306a36Sopenharmony_cimy $mult = 1950.0 / ($maxtime - $firsttime); 16662306a36Sopenharmony_cimy $threshold2 = ($maxtime - $firsttime) / 120.0; 16762306a36Sopenharmony_cimy $threshold = $threshold2/10; 16862306a36Sopenharmony_cimy $stylecounter = 0; 16962306a36Sopenharmony_cimy %rows; 17062306a36Sopenharmony_cimy $rowscount = 1; 17162306a36Sopenharmony_cimy @initcalls = sort { $start{$a} <=> $start{$b} } keys(%start); 17262306a36Sopenharmony_ci 17362306a36Sopenharmony_ciforeach my $key (@initcalls) { 17462306a36Sopenharmony_ci my $duration = $end{$key} - $start{$key}; 17562306a36Sopenharmony_ci 17662306a36Sopenharmony_ci if ($duration >= $threshold) { 17762306a36Sopenharmony_ci my ($s, $s2, $s3, $e, $w, $y, $y2, $style); 17862306a36Sopenharmony_ci my $pid = $pids{$key}; 17962306a36Sopenharmony_ci 18062306a36Sopenharmony_ci if (!defined($rows{$pid})) { 18162306a36Sopenharmony_ci $rows{$pid} = $rowscount; 18262306a36Sopenharmony_ci $rowscount = $rowscount + 1; 18362306a36Sopenharmony_ci } 18462306a36Sopenharmony_ci $s = ($start{$key} - $firsttime) * $mult; 18562306a36Sopenharmony_ci $s2 = $s + 6; 18662306a36Sopenharmony_ci $s3 = $s + 1; 18762306a36Sopenharmony_ci $e = ($end{$key} - $firsttime) * $mult; 18862306a36Sopenharmony_ci $w = $e - $s; 18962306a36Sopenharmony_ci 19062306a36Sopenharmony_ci $y = $rows{$pid} * 150; 19162306a36Sopenharmony_ci $y2 = $y + 4; 19262306a36Sopenharmony_ci 19362306a36Sopenharmony_ci $style = $styles[$stylecounter]; 19462306a36Sopenharmony_ci $stylecounter = $stylecounter + 1; 19562306a36Sopenharmony_ci if ($stylecounter > 11) { 19662306a36Sopenharmony_ci $stylecounter = 0; 19762306a36Sopenharmony_ci }; 19862306a36Sopenharmony_ci 19962306a36Sopenharmony_ci if ($type{$key} == 1) { 20062306a36Sopenharmony_ci $y = $y + 15; 20162306a36Sopenharmony_ci print "<rect x=\"$s\" width=\"$w\" y=\"$y\" height=\"115\" style=\"$style_wait\"/>\n"; 20262306a36Sopenharmony_ci } else { 20362306a36Sopenharmony_ci print "<rect x=\"$s\" width=\"$w\" y=\"$y\" height=\"145\" style=\"$style\"/>\n"; 20462306a36Sopenharmony_ci if ($duration >= $threshold2) { 20562306a36Sopenharmony_ci print "<text transform=\"translate($s2,$y2) rotate(90)\">$key</text>\n"; 20662306a36Sopenharmony_ci } else { 20762306a36Sopenharmony_ci print "<text transform=\"translate($s3,$y2) rotate(90)\" font-size=\"3pt\">$key</text>\n"; 20862306a36Sopenharmony_ci } 20962306a36Sopenharmony_ci } 21062306a36Sopenharmony_ci } 21162306a36Sopenharmony_ci} 21262306a36Sopenharmony_ci 21362306a36Sopenharmony_ci 21462306a36Sopenharmony_ci# print the time line on top 21562306a36Sopenharmony_cimy $time = $firsttime; 21662306a36Sopenharmony_cimy $step = ($maxtime - $firsttime) / 15; 21762306a36Sopenharmony_ciwhile ($time < $maxtime) { 21862306a36Sopenharmony_ci my $s3 = ($time - $firsttime) * $mult; 21962306a36Sopenharmony_ci my $tm = int($time * 100) / 100.0; 22062306a36Sopenharmony_ci print "<text transform=\"translate($s3,89) rotate(90)\">$tm</text>\n"; 22162306a36Sopenharmony_ci $time = $time + $step; 22262306a36Sopenharmony_ci} 22362306a36Sopenharmony_ci 22462306a36Sopenharmony_ciprint "</svg>\n"; 225