1The following are examples of pl_flowinfo.d. 2 3This is a simple script to trace the flow of Perl subroutines (functions). 4Here it traces the example program, Code/Perl/func_abc.pl. 5 6 # pl_flowinfo.d 7 C PID DELTA(us) FILE:LINE TYPE -- SUB 8 0 305127 2 func_abc.pl:15 sub -> func_a 9 0 305127 1008776 func_abc.pl:9 sub -> func_b 10 0 305127 1010019 func_abc.pl:4 sub -> func_c 11 0 305127 1009979 func_abc.pl:4 sub <- func_c 12 0 305127 26 func_abc.pl:9 sub <- func_b 13 0 305127 9 func_abc.pl:15 sub <- func_a 14 ^C 15 16As each subroutine is entered, the third column is indented by 2 spaces. This 17shows which subroutine is calling who - the output abovebegins by showing that 18func_a() began, and then called func_b(). 19 20The DELTA(us) column shows time from that line to the previous line, and 21so can be a bit tricky to read. For example, the second line of data output 22(skipping the header) reads as "the time from func_a() beginning to 23func_b() beginning was 1008776 us, or 1.01 seconds". 24 25The LINE column shows the line in the file what was being executed. Refer 26to the source program to see what this line refers to. 27 28If the output looks shuffled, check the CPU "C" column - if it changes, 29then the output is probably shuffled. See Notes/ALLsnoop_notes.txt for 30details and suggested workarounds. 31 32See Notes/ALLflow_notes.txt for important notes about reading flow outputs. 33 34 35 36The following traces a Perl network interface statistics tool, "nicstat" 37version 0.99, 38 39# pl_flowinfo.d 40C PID DELTA(us) FILE:LINE TYPE -- SUB 410 305132 2 nicstat:83 sub -> BEGIN 420 305132 444 strict.pm:12 sub -> bits 430 305132 34 strict.pm:12 sub <- bits 440 305132 32 strict.pm:28 sub -> import 450 305132 22 strict.pm:28 sub <- import 460 305132 8 nicstat:83 sub <- BEGIN 470 305132 26 nicstat:84 sub -> BEGIN 480 305132 2339 Exporter.pm:30 sub -> import 490 305132 83 Exporter.pm:30 sub <- import 500 305132 14 nicstat:84 sub <- BEGIN 510 305132 27 nicstat:85 sub -> BEGIN 520 305132 205 Kstat.pm:34 sub -> BEGIN 530 305132 11 strict.pm:28 sub -> import 540 305132 11 strict.pm:28 sub <- import 550 305132 8 Kstat.pm:34 sub <- BEGIN 560 305132 23 Kstat.pm:35 sub -> BEGIN 570 305132 187 DynaLoader.pm:18 sub -> BEGIN 580 305132 73 vars.pm:3 sub -> BEGIN 590 305132 9 vars.pm:3 sub <- BEGIN 600 305132 34 vars.pm:7 sub -> BEGIN 610 305132 470 warnings.pm:134 sub -> BEGIN 620 305132 598 warnings.pm:134 sub <- BEGIN 630 305132 2151 register.pm:37 sub -> import 640 305132 23 register.pm:28 sub -> mkMask 650 305132 13 register.pm:28 sub <- mkMask 660 305132 53 register.pm:28 sub -> mkMask 670 305132 11 register.pm:28 sub <- mkMask 680 305132 11 register.pm:37 sub <- import 690 305132 8 vars.pm:7 sub <- BEGIN 700 305132 28 vars.pm:8 sub -> BEGIN 710 305132 9 strict.pm:28 sub -> import 720 305132 8 strict.pm:12 sub -> bits 730 305132 13 strict.pm:12 sub <- bits 740 305132 9 strict.pm:28 sub <- import 750 305132 8 vars.pm:8 sub <- BEGIN 760 305132 294 vars.pm:11 sub -> import 770 305132 52 vars.pm:11 sub <- import 780 305132 8 DynaLoader.pm:18 sub <- BEGIN 790 305132 48 DynaLoader.pm:25 sub -> BEGIN 800 305132 97 Config.pm:5 sub -> BEGIN 810 305132 9 strict.pm:28 sub -> import 820 305132 9 strict.pm:28 sub <- import 830 305132 8 Config.pm:5 sub <- BEGIN 840 305132 134 Config.pm:31 sub -> BEGIN 850 305132 9 strict.pm:33 sub -> unimport 860 305132 8 strict.pm:12 sub -> bits 870 305132 11 strict.pm:12 sub <- bits 880 305132 16 strict.pm:33 sub <- unimport 890 305132 8 Config.pm:31 sub <- BEGIN 900 305132 343 Config.pm:60 sub -> TIEHASH 910 305132 10 Config.pm:60 sub <- TIEHASH 920 305132 44 Config.pm:25 sub -> import 930 305132 18 Config.pm:25 sub <- import 940 305132 9 DynaLoader.pm:25 sub <- BEGIN 950 305132 1301 AutoLoader.pm:3 sub -> BEGIN 960 305132 11 strict.pm:28 sub -> import 970 305132 10 strict.pm:28 sub <- import 980 305132 9 AutoLoader.pm:3 sub <- BEGIN 990 305132 22 AutoLoader.pm:4 sub -> BEGIN 1000 305132 9 AutoLoader.pm:4 sub <- BEGIN 1010 305132 89 AutoLoader.pm:14 sub -> BEGIN 1020 305132 13 AutoLoader.pm:14 sub <- BEGIN 1030 305132 375 AutoLoader.pm:95 sub -> BEGIN 1040 305132 9 strict.pm:33 sub -> unimport 1050 305132 8 strict.pm:12 sub -> bits 1060 305132 11 strict.pm:12 sub <- bits 1070 305132 9 strict.pm:33 sub <- unimport 1080 305132 8 AutoLoader.pm:95 sub <- BEGIN 1090 305132 203 AutoLoader.pm:128 sub -> BEGIN 1100 305132 9 strict.pm:33 sub -> unimport 1110 305132 8 strict.pm:12 sub -> bits 1120 305132 11 strict.pm:12 sub <- bits 1130 305132 9 strict.pm:33 sub <- unimport 1140 305132 8 AutoLoader.pm:128 sub <- BEGIN 1150 305132 220 AutoLoader.pm:173 sub -> BEGIN 1160 305132 9 strict.pm:33 sub -> unimport 1170 305132 8 strict.pm:12 sub -> bits 1180 305132 10 strict.pm:12 sub <- bits 1190 305132 9 strict.pm:33 sub <- unimport 1200 305132 8 AutoLoader.pm:173 sub <- BEGIN 1210 305132 103 Config.pm:52 sub -> FETCH 1220 305132 12 Config.pm:52 sub <- FETCH 1230 305132 16 Config.pm:52 sub -> FETCH 1240 305132 9 Config.pm:52 sub <- FETCH 1250 305132 11 Config.pm:52 sub -> FETCH 1260 305132 9 Config.pm:52 sub <- FETCH 1270 305132 11 Config.pm:52 sub -> FETCH 1280 305132 9 Config.pm:52 sub <- FETCH 1290 305132 95 Kstat.pm:35 sub <- BEGIN 1300 305132 29 Kstat.pm:36 sub -> BEGIN 1310 305132 10 vars.pm:11 sub -> import 1320 305132 33 vars.pm:11 sub <- import 1330 305132 8 Kstat.pm:36 sub <- BEGIN 1340 305132 56 DynaLoader.pm:133 sub -> bootstrap 1350 305132 314 DynaLoader.pm:48 sub -> dl_load_flags 1360 305132 11 DynaLoader.pm:48 sub <- dl_load_flags 1370 305132 1113 DynaLoader.pm:133 sub <- bootstrap 1380 305132 41 nicstat:85 sub <- BEGIN 1390 305132 6102 Std.pm:219 sub -> getopts 1400 305132 52 Exporter.pm:30 sub -> import 1410 305132 40 Exporter.pm:30 sub <- import 1420 305132 22 Std.pm:219 sub <- getopts 1430 305132 24 nicstat:264 sub -> find_nets 1440 305132 79662 nicstat:264 sub <- find_nets 1450 305132 420 nicstat:304 sub -> fetch_net_data 1460 305132 43871 nicstat:304 sub <- fetch_net_data 1470 305132 479 nicstat:372 sub -> print_neat 1480 305132 150 nicstat:372 sub <- print_neat 1490 305132 10 nicstat:372 sub -> print_neat 1500 305132 220 nicstat:372 sub <- print_neat 1510 305132 10 nicstat:372 sub -> print_neat 1520 305132 126 nicstat:372 sub <- print_neat 1530 305132 10 nicstat:372 sub -> print_neat 1540 305132 125 nicstat:372 sub <- print_neat 1550 305132 10 nicstat:372 sub -> print_neat 1560 305132 157 nicstat:372 sub <- print_neat 1570 305132 10 nicstat:372 sub -> print_neat 1580 305132 171 nicstat:372 sub <- print_neat 1590 305132 343 nicstat:372 sub -> print_neat 1600 305132 128 nicstat:372 sub <- print_neat 1610 305132 10 nicstat:372 sub -> print_neat 1620 305132 157 nicstat:372 sub <- print_neat 1630 305132 9 nicstat:372 sub -> print_neat 1640 305132 125 nicstat:372 sub <- print_neat 1650 305132 9 nicstat:372 sub -> print_neat 1660 305132 123 nicstat:372 sub <- print_neat 1670 305132 9 nicstat:372 sub -> print_neat 1680 305132 160 nicstat:372 sub <- print_neat 1690 305132 10 nicstat:372 sub -> print_neat 1700 305132 124 nicstat:372 sub <- print_neat 1710 305132 342 nicstat:372 sub -> print_neat 1720 305132 126 nicstat:372 sub <- print_neat 1730 305132 10 nicstat:372 sub -> print_neat 1740 305132 123 nicstat:372 sub <- print_neat 1750 305132 10 nicstat:372 sub -> print_neat 1760 305132 156 nicstat:372 sub <- print_neat 1770 305132 10 nicstat:372 sub -> print_neat 1780 305132 153 nicstat:372 sub <- print_neat 1790 305132 10 nicstat:372 sub -> print_neat 1800 305132 123 nicstat:372 sub <- print_neat 1810 305132 9 nicstat:372 sub -> print_neat 1820 305132 123 nicstat:372 sub <- print_neat 1830 305132 3736 Config.pm:63 sub -> DESTROY 1840 305132 32 Config.pm:63 sub <- DESTROY 185 186After initialising Perl libraries and modules, the "nicstat" program ran, 187the output matching what was expected from the source. 188 189