bootgraph.pl 5.6 KB

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