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