From f9b9796ade7609cd62571d38f064e20c77d31281 Mon Sep 17 00:00:00 2001 From: Arjan van de Ven Date: Sat, 13 Sep 2008 09:36:06 -0700 Subject: 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 some of the initializing going asynchronous soon, it's valuable to track/print which worker thread is executing the initialization. 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 --- scripts/bootgraph.pl | 138 +++++++++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 138 insertions(+) create mode 100644 scripts/bootgraph.pl (limited to 'scripts') diff --git a/scripts/bootgraph.pl b/scripts/bootgraph.pl new file mode 100644 index 00000000000..d459b8bdef0 --- /dev/null +++ b/scripts/bootgraph.pl @@ -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 + + +# +# 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 " \n"; +print "\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 "\n"; + print "$key\n"; + } +} + + +# print the time line on top +my $time = 0.0; +while ($time < $maxtime) { + my $s2 = $time * $mult; + print "$time\n"; + $time = $time + 0.1; +} + +print "\n"; -- cgit v1.2.3 From 709790a9aafe424785dd02bcb31b0dddb4ef59e4 Mon Sep 17 00:00:00 2001 From: Arjan van de Ven Date: Sun, 14 Sep 2008 15:30:52 -0700 Subject: fastboot: fix issues and improve output of bootgraph.pl David Sanders reported some issues with bootgraph.pl's display of his sytems bootup; this commit fixes these by scaling the graph not from 0 - end time but from the first initcall to the end time; the minimum display size etc also now need to scale with this, as does the axis display. Signed-off-by: Arjan van de Ven --- scripts/bootgraph.pl | 25 +++++++++++++++++-------- 1 file changed, 17 insertions(+), 8 deletions(-) (limited to 'scripts') diff --git a/scripts/bootgraph.pl b/scripts/bootgraph.pl index d459b8bdef0..4e5f4ab2ed7 100644 --- a/scripts/bootgraph.pl +++ b/scripts/bootgraph.pl @@ -42,6 +42,7 @@ my %start, %end, %row; my $done = 0; my $rowcount = 0; my $maxtime = 0; +my $firsttime = 100; my $count = 0; while (<>) { my $line = $_; @@ -49,6 +50,9 @@ while (<>) { my $func = $2; if ($done == 0) { $start{$func} = $1; + if ($1 < $firsttime) { + $firsttime = $1; + } } $row{$func} = 1; if ($line =~ /\@ ([0-9]+)/) { @@ -71,6 +75,9 @@ while (<>) { if ($line =~ /Write protecting the/) { $done = 1; } + if ($line =~ /Freeing unused kernel memory/) { + $done = 1; + } } if ($count == 0) { @@ -99,17 +106,17 @@ $styles[9] = "fill:rgb(255,255,128);fill-opacity:0.5;stroke-width:1;stroke:rgb(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 $mult = 950.0 / ($maxtime - $firsttime); +my $threshold = ($maxtime - $firsttime) / 60.0; 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; + $s = ($value - $firsttime) * $mult; $s2 = $s + 6; - $e = $end{$key} * $mult; + $e = ($end{$key} - $firsttime) * $mult; $w = $e - $s; $y = $row{$key} * 150; @@ -128,11 +135,13 @@ while (($key,$value) = each %start) { # print the time line on top -my $time = 0.0; +my $time = $firsttime; +my $step = ($maxtime - $firsttime) / 15; while ($time < $maxtime) { - my $s2 = $time * $mult; - print "$time\n"; - $time = $time + 0.1; + my $s2 = ($time - $firsttime) * $mult; + my $tm = int($time * 100) / 100.0; + print "$tm\n"; + $time = $time + $step; } print "\n"; -- cgit v1.2.3 From 8bd9890e94627bc1ef372085e64dda7f9e307e82 Mon Sep 17 00:00:00 2001 From: Arnaud Patard Date: Fri, 19 Sep 2008 20:16:25 -0700 Subject: fastboot: Fix bootgraph.pl initcall name regexp The regexp used to match the start and the end of an initcall are matching only on [a-zA-Z\_]. This rules out initcalls with a number in them. This patch is fixing that. Signed-off-by: Arnaud Patard --- scripts/bootgraph.pl | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) (limited to 'scripts') diff --git a/scripts/bootgraph.pl b/scripts/bootgraph.pl index 4e5f4ab2ed7..2243353fe55 100644 --- a/scripts/bootgraph.pl +++ b/scripts/bootgraph.pl @@ -46,7 +46,7 @@ my $firsttime = 100; my $count = 0; while (<>) { my $line = $_; - if ($line =~ /([0-9\.]+)\] calling ([a-zA-Z\_]+)\+/) { + if ($line =~ /([0-9\.]+)\] calling ([a-zA-Z0-9\_]+)\+/) { my $func = $2; if ($done == 0) { $start{$func} = $1; @@ -66,7 +66,7 @@ while (<>) { $count = $count + 1; } - if ($line =~ /([0-9\.]+)\] initcall ([a-zA-Z\_]+)\+.*returned/) { + if ($line =~ /([0-9\.]+)\] initcall ([a-zA-Z0-9\_]+)\+.*returned/) { if ($done == 0) { $end{$2} = $1; $maxtime = $1; @@ -81,8 +81,8 @@ while (<>) { } 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 "No data found in the dmesg. Make sure that 'printk.time=1' and\n"; + print "'initcall_debug' are passed on the kernel command line.\n\n"; print "Usage: \n"; print " dmesg | perl scripts/bootgraph.pl > output.svg\n\n"; exit; -- cgit v1.2.3