parse_logs 22 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593594595596597598599600601602603604605606607608609610611612613614615616617618619620621622623624625626627628629630631632633634635636637638
  1. #!/usr/bin/perl
  2. # Parse the log output files of run-experiment
  3. # Send concatenated log files to stdin, or list them on the command
  4. # line.
  5. use strict;
  6. my $showmemusage = 0;
  7. my $netsetup = '';
  8. my %preproc_resources = ();
  9. my @preproc_seconds = (0, 0, 0);
  10. my @preproc_kib = (0, 0, 0);
  11. my @preproc_latencies = (0, 0, 0);
  12. my @preproc_mem_mib = (0, 0, 0);
  13. my %preproc_s_data = ();
  14. my %preproc_kib_data = ();
  15. my %preproc_latencies_data = ();
  16. my %preproc_P0mem_mib_data = ();
  17. my %preproc_P1mem_mib_data = ();
  18. my %preproc_P2mem_mib_data = ();
  19. my %online_s_data = ();
  20. my %online_kib_data = ();
  21. my %online_latencies_data = ();
  22. my %online_P0mem_mib_data = ();
  23. my %online_P1mem_mib_data = ();
  24. my %online_P2mem_mib_data = ();
  25. if ($ARGV[0] eq "-m") {
  26. shift;
  27. $showmemusage = 1;
  28. }
  29. while(<>) {
  30. chomp;
  31. if (/Network setup: (.*)/) {
  32. $netsetup = "$1 ";
  33. next;
  34. }
  35. if (/===== Running prac (.*)/) {
  36. my $cmdline = $1;
  37. if ($cmdline =~ /-[pa]/) {
  38. &parse_preproc($cmdline);
  39. next;
  40. } elsif ($cmdline =~ /^-- read/) {
  41. &parse_read($cmdline);
  42. } elsif ($cmdline =~ /^-- b?bsearch/) {
  43. &parse_bsearch($cmdline);
  44. } elsif ($cmdline =~ /^-- heapsampler/) {
  45. &parse_heapsampler($cmdline);
  46. } elsif ($cmdline =~ /^-- heap/) {
  47. &parse_heap($cmdline);
  48. } elsif ($cmdline =~ /^-- avl/) {
  49. &parse_avl($cmdline);
  50. } else {
  51. warn "Unknown cmdline: $cmdline\n";
  52. while(<>) {
  53. last if /===== End/;
  54. }
  55. }
  56. %preproc_resources = ();
  57. @preproc_seconds = (0, 0, 0);
  58. @preproc_kib = (0, 0, 0);
  59. @preproc_latencies = (0, 0, 0);
  60. @preproc_mem_mib = (0, 0, 0);
  61. next;
  62. }
  63. }
  64. # Convert the data (in the form [n, sum, sum_squares]) to statistics (in
  65. # the form [mean, variance])
  66. my %preproc_s_stats = ();
  67. my %preproc_kib_stats = ();
  68. my %preproc_latencies_stats = ();
  69. my %preproc_P0mem_mib_stats = ();
  70. my %preproc_P1mem_mib_stats = ();
  71. my %preproc_P2mem_mib_stats = ();
  72. my %online_s_stats = ();
  73. my %online_kib_stats = ();
  74. my %online_latencies_stats = ();
  75. my %online_P0mem_mib_stats = ();
  76. my %online_P1mem_mib_stats = ();
  77. my %online_P2mem_mib_stats = ();
  78. &statsify(\%preproc_s_stats, \%preproc_s_data);
  79. &statsify(\%preproc_kib_stats, \%preproc_kib_data);
  80. &statsify(\%preproc_latencies_stats, \%preproc_latencies_data);
  81. &statsify(\%preproc_P0mem_mib_stats, \%preproc_P0mem_mib_data);
  82. &statsify(\%preproc_P1mem_mib_stats, \%preproc_P1mem_mib_data);
  83. &statsify(\%preproc_P2mem_mib_stats, \%preproc_P2mem_mib_data);
  84. &statsify(\%online_s_stats, \%online_s_data);
  85. &statsify(\%online_kib_stats, \%online_kib_data);
  86. &statsify(\%online_latencies_stats, \%online_latencies_data);
  87. &statsify(\%online_P0mem_mib_stats, \%online_P0mem_mib_data);
  88. &statsify(\%online_P1mem_mib_stats, \%online_P1mem_mib_data);
  89. &statsify(\%online_P2mem_mib_stats, \%online_P2mem_mib_data);
  90. # The total values are the sums of the preproc and online values
  91. my %total_s_stats = ();
  92. my %total_kib_stats = ();
  93. &sum_preproc_online(\%total_s_stats, \%preproc_s_stats, \%online_s_stats);
  94. &sum_preproc_online(\%total_kib_stats, \%preproc_kib_stats, \%online_kib_stats);
  95. # Output the data
  96. &output_stats(\%preproc_s_stats, "Preprc", "s");
  97. &output_stats(\%preproc_kib_stats, "Preprc", "KiB");
  98. &output_stats(\%preproc_latencies_stats, "Preprc", "latencies");
  99. if ($showmemusage) {
  100. &output_stats(\%preproc_P0mem_mib_stats, "Preprc", "P0MemMiB");
  101. &output_stats(\%preproc_P1mem_mib_stats, "Preprc", "P1MemMiB");
  102. &output_stats(\%preproc_P2mem_mib_stats, "Preprc", "P2MemMiB");
  103. }
  104. &output_stats(\%online_s_stats, "Onln", "s");
  105. &output_stats(\%online_kib_stats, "Onln", "KiB");
  106. &output_stats(\%online_latencies_stats, "Onln", "latencies");
  107. if ($showmemusage) {
  108. &output_stats(\%online_P0mem_mib_stats, "Onln", "P0MemMiB");
  109. &output_stats(\%online_P1mem_mib_stats, "Onln", "P1MemMiB");
  110. &output_stats(\%online_P2mem_mib_stats, "Onln", "P2MemMiB");
  111. }
  112. &output_stats(\%total_s_stats, "Totl", "s");
  113. &output_stats(\%total_kib_stats, "Totl", "KiB");
  114. # Subroutines
  115. sub parse_preproc {
  116. my $cmdline = $_[0];
  117. my $who = 0;
  118. # Reset the preproc usages unless we're appending to a previous
  119. # preproc
  120. unless ($cmdline =~ /-a/) {
  121. %preproc_resources = ();
  122. @preproc_seconds = (0, 0, 0);
  123. @preproc_kib = (0, 0, 0);
  124. @preproc_latencies = (0, 0, 0);
  125. @preproc_mem_mib = (0, 0, 0);
  126. }
  127. &parse_resources(\%preproc_resources, $cmdline);
  128. while(<>) {
  129. if (/===== P([012]) output/) {
  130. $who = $1;
  131. next;
  132. }
  133. last if /===== End/;
  134. # Try to recover from a malformed log
  135. last if /^Max MB:/;
  136. # It was too malformed
  137. die "Malformed log" if /===== Running/;
  138. if (/^(\d+) message bytes sent/) {
  139. $preproc_kib[$who] += $1 / 1024;
  140. } elsif (/^(\d+) Lamport clock/) {
  141. $preproc_latencies[$who] += $1;
  142. } elsif (/^(\d+) milliseconds? wall clock/) {
  143. $preproc_seconds[$who] += $1 / 1000;
  144. } elsif (/^Mem: (\d+) KiB/) {
  145. $preproc_mem_mib[$who] += $1 / 1024;
  146. }
  147. }
  148. }
  149. # Parse a resource usage string, and accumulate the values into the
  150. # given dict
  151. sub parse_resources {
  152. my ($dict, $resstr) = @_;
  153. while ($resstr =~ /(\S+):(\d+)/g) {
  154. $dict->{$1} = 0 unless defined $dict->{$1};
  155. $dict->{$1} += $2;
  156. }
  157. }
  158. # Serialize a resource usage dict back into a canonical string
  159. sub serialize_resources {
  160. my $dict = $_[0];
  161. my $res = '';
  162. my $k;
  163. foreach $k (sort keys %$dict) {
  164. if ($res ne '') {
  165. $res .= ' ';
  166. }
  167. $res .= $k . ":" . $dict->{$k};
  168. }
  169. $res;
  170. }
  171. sub parse_read {
  172. my $cmdline = $_[0];
  173. my $who = 0;
  174. my @online_seconds = (0, 0, 0);
  175. my @online_kib = (0, 0, 0);
  176. my @online_latencies = (0, 0, 0);
  177. my @online_mem_mib = (0, 0, 0);
  178. unless ($cmdline =~ /read (\d+) (\d+)/) {
  179. die "Cannot parse read cmdline: $cmdline";
  180. }
  181. my ($size, $num) = ($1, $2);
  182. while(<>) {
  183. if (/===== P([012]) output/) {
  184. $who = $1;
  185. next;
  186. }
  187. last if /===== End/;
  188. # Try to recover from a malformed log
  189. last if /^Max MB:/;
  190. # It was too malformed
  191. die "Malformed log" if /===== Running/;
  192. if (/^(\d+) message bytes sent/) {
  193. $online_kib[$who] = $1 / 1024;
  194. } elsif (/^(\d+) Lamport clock/) {
  195. $online_latencies[$who] = $1;
  196. } elsif (/^(\d+) milliseconds? wall clock/) {
  197. $online_seconds[$who] = $1 / 1000;
  198. } elsif (/^Mem: (\d+) KiB/) {
  199. $online_mem_mib[$who] = $1 / 1024;
  200. } elsif ($who == 0 && /^Precomputed values used: (.*)/) {
  201. my %used_resources = ();
  202. &parse_resources(\%used_resources, $1);
  203. my $preproc_resources_str = &serialize_resources(\%preproc_resources);
  204. my $used_resources_str = &serialize_resources(\%used_resources);
  205. if ($preproc_resources_str ne $used_resources_str) {
  206. warn "Resource usage does not match preprocessing:\n" .
  207. "Preproc: $preproc_resources_str\n" .
  208. "Used: $used_resources_str\n ";
  209. }
  210. }
  211. }
  212. my $label = "PRAC read $netsetup$size $num";
  213. &accum_data(\%preproc_s_data, $label, &maxarray(@preproc_seconds));
  214. &accum_data(\%preproc_kib_data, $label, &avgarray(@preproc_kib));
  215. &accum_data(\%preproc_latencies_data, $label, &maxarray(@preproc_latencies));
  216. &accum_data(\%preproc_P0mem_mib_data, $label, $preproc_mem_mib[0]);
  217. &accum_data(\%preproc_P1mem_mib_data, $label, $preproc_mem_mib[1]);
  218. &accum_data(\%preproc_P2mem_mib_data, $label, $preproc_mem_mib[2]);
  219. &accum_data(\%online_s_data, $label, &maxarray(@online_seconds));
  220. &accum_data(\%online_kib_data, $label, &avgarray(@online_kib));
  221. &accum_data(\%online_latencies_data, $label, &maxarray(@online_latencies));
  222. &accum_data(\%online_P0mem_mib_data, $label, $online_mem_mib[0]);
  223. &accum_data(\%online_P1mem_mib_data, $label, $online_mem_mib[1]);
  224. &accum_data(\%online_P2mem_mib_data, $label, $online_mem_mib[2]);
  225. }
  226. sub parse_bsearch {
  227. my $cmdline = $_[0];
  228. my $optimized = "Opt";
  229. if ($cmdline =~ /bbsearch/) {
  230. $optimized = "Basic";
  231. }
  232. my $who = 0;
  233. my $section = '';
  234. my @online_seconds = (0, 0, 0);
  235. my @online_kib = (0, 0, 0);
  236. my @online_latencies = (0, 0, 0);
  237. my @online_mem_mib = (0, 0, 0);
  238. unless ($cmdline =~ /b?bsearch (\d+) (\d+)/) {
  239. die "Cannot parse bsearch cmdline: $cmdline";
  240. }
  241. my ($size, $num) = ($1, $2);
  242. while(<>) {
  243. if (/===== P([012]) output/) {
  244. $who = $1;
  245. next;
  246. }
  247. if (/===== ([A-Z ]+) =====/) {
  248. $section = $1;
  249. next;
  250. }
  251. last if /===== End/;
  252. # Try to recover from a malformed log
  253. last if /^Max MB:/;
  254. # It was too malformed
  255. die "Malformed log" if /===== Running/;
  256. if ($section eq "BINARY SEARCH") {
  257. if (/^(\d+) message bytes sent/) {
  258. $online_kib[$who] = $1 / 1024;
  259. } elsif (/^(\d+) Lamport clock/) {
  260. $online_latencies[$who] = $1;
  261. } elsif (/^(\d+) milliseconds? wall clock/) {
  262. $online_seconds[$who] = $1 / 1000;
  263. } elsif (/^Mem: (\d+) KiB/) {
  264. $online_mem_mib[$who] = $1 / 1024;
  265. }
  266. }
  267. if ($who == 0 && /^Precomputed values used: (.*)/) {
  268. my %used_resources = ();
  269. &parse_resources(\%used_resources, $1);
  270. my $preproc_resources_str = &serialize_resources(\%preproc_resources);
  271. my $used_resources_str = &serialize_resources(\%used_resources);
  272. if ($preproc_resources_str ne $used_resources_str) {
  273. warn "Resource usage does not match preprocessing:\n" .
  274. "Preproc: $preproc_resources_str\n" .
  275. "Used: $used_resources_str\n ";
  276. }
  277. }
  278. }
  279. my $label = "${optimized}PRAC bsearch $netsetup$size $num";
  280. &accum_data(\%preproc_s_data, $label, &maxarray(@preproc_seconds));
  281. &accum_data(\%preproc_kib_data, $label, &avgarray(@preproc_kib));
  282. &accum_data(\%preproc_latencies_data, $label, &maxarray(@preproc_latencies));
  283. &accum_data(\%preproc_P0mem_mib_data, $label, $preproc_mem_mib[0]);
  284. &accum_data(\%preproc_P1mem_mib_data, $label, $preproc_mem_mib[1]);
  285. &accum_data(\%preproc_P2mem_mib_data, $label, $preproc_mem_mib[2]);
  286. &accum_data(\%online_s_data, $label, &maxarray(@online_seconds));
  287. &accum_data(\%online_kib_data, $label, &avgarray(@online_kib));
  288. &accum_data(\%online_latencies_data, $label, &maxarray(@online_latencies));
  289. &accum_data(\%online_P0mem_mib_data, $label, $online_mem_mib[0]);
  290. &accum_data(\%online_P1mem_mib_data, $label, $online_mem_mib[1]);
  291. &accum_data(\%online_P2mem_mib_data, $label, $online_mem_mib[2]);
  292. }
  293. sub parse_heap {
  294. my $cmdline = $_[0];
  295. my $who = 0;
  296. my $section = '';
  297. my @online_seconds = (0, 0, 0);
  298. my @online_kib = (0, 0, 0);
  299. my @online_latencies = (0, 0, 0);
  300. my @online_mem_mib = (0, 0, 0);
  301. my $optimized = "Opt";
  302. my $oper = "";
  303. unless ($cmdline =~ /heap -m (\d+) -d \d+ -i (\d+) -e (\d+) -opt (\d+) -s 0/) {
  304. die "Cannot parse heap cmdline: $cmdline";
  305. }
  306. my ($size, $nins, $next, $optflag) = ($1, $2, $3, $4);
  307. if ($nins > 0 && $next > 0) {
  308. die "heap does both insertions and extractions: $cmdline\n";
  309. }
  310. $oper = "Ins" if $nins > 0;
  311. $oper = "Ext" if $next > 0;
  312. if ($optflag == 0) {
  313. $optimized = "Basic";
  314. }
  315. my $num = ($nins + $next);
  316. while(<>) {
  317. if (/===== P([012]) output/) {
  318. $who = $1;
  319. next;
  320. }
  321. if (/===== ([A-Za-z ]+) Stats =====/) {
  322. $section = $1;
  323. next;
  324. }
  325. last if /===== End/;
  326. # Try to recover from a malformed log
  327. last if /^Max MB:/;
  328. # It was too malformed
  329. die "Malformed log" if /===== Running/;
  330. my $rightsection = 0;
  331. if ($section eq "Insert" && $oper eq "Ins") {
  332. $rightsection = 1;
  333. }
  334. if ($section eq "Extract Min" && $oper eq "Ext") {
  335. $rightsection = 1;
  336. }
  337. if ($rightsection) {
  338. if (/^(\d+) message bytes sent/) {
  339. $online_kib[$who] = $1 / 1024;
  340. } elsif (/^(\d+) Lamport clock/) {
  341. $online_latencies[$who] = $1;
  342. } elsif (/^(\d+) milliseconds? wall clock/) {
  343. $online_seconds[$who] = $1 / 1000;
  344. } elsif (/^Mem: (\d+) KiB/) {
  345. $online_mem_mib[$who] = $1 / 1024;
  346. }
  347. }
  348. if ($who == 0 && /^Precomputed values used: (.*)/) {
  349. my %used_resources = ();
  350. &parse_resources(\%used_resources, $1);
  351. my $preproc_resources_str = &serialize_resources(\%preproc_resources);
  352. my $used_resources_str = &serialize_resources(\%used_resources);
  353. if ($preproc_resources_str ne $used_resources_str) {
  354. warn "Resource usage does not match preprocessing:\n" .
  355. "Preproc: $preproc_resources_str\n" .
  356. "Used: $used_resources_str\n ";
  357. }
  358. }
  359. }
  360. my $label = "${optimized}PRAC heap$oper $netsetup$size $num";
  361. &accum_data(\%preproc_s_data, $label, &maxarray(@preproc_seconds));
  362. &accum_data(\%preproc_kib_data, $label, &avgarray(@preproc_kib));
  363. &accum_data(\%preproc_latencies_data, $label, &maxarray(@preproc_latencies));
  364. &accum_data(\%preproc_P0mem_mib_data, $label, $preproc_mem_mib[0]);
  365. &accum_data(\%preproc_P1mem_mib_data, $label, $preproc_mem_mib[1]);
  366. &accum_data(\%preproc_P2mem_mib_data, $label, $preproc_mem_mib[2]);
  367. &accum_data(\%online_s_data, $label, &maxarray(@online_seconds));
  368. &accum_data(\%online_kib_data, $label, &avgarray(@online_kib));
  369. &accum_data(\%online_latencies_data, $label, &maxarray(@online_latencies));
  370. &accum_data(\%online_P0mem_mib_data, $label, $online_mem_mib[0]);
  371. &accum_data(\%online_P1mem_mib_data, $label, $online_mem_mib[1]);
  372. &accum_data(\%online_P2mem_mib_data, $label, $online_mem_mib[2]);
  373. }
  374. sub parse_avl {
  375. my $cmdline = $_[0];
  376. my $who = 0;
  377. my $section = '';
  378. my @online_seconds = (0, 0, 0);
  379. my @online_kib = (0, 0, 0);
  380. my @online_latencies = (0, 0, 0);
  381. my @online_mem_mib = (0, 0, 0);
  382. my $optimized = "Opt";
  383. my $oper = "";
  384. unless ($cmdline =~ /avl -m (\d+) -i (\d+) -e (\d+) -opt (\d+) -s 0/) {
  385. die "Cannot parse heap cmdline: $cmdline";
  386. }
  387. my ($size, $nins, $ndel, $optflag) = ($1, $2, $3, $4);
  388. if ($nins > 0 && $ndel > 0) {
  389. die "avl does both insertions and deletions: $cmdline\n";
  390. }
  391. $oper = "Ins" if $nins > 0;
  392. $oper = "Del" if $ndel > 0;
  393. if ($optflag == 0) {
  394. $optimized = "Basic";
  395. }
  396. my $num = ($nins + $ndel);
  397. while(<>) {
  398. if (/===== P([012]) output/) {
  399. $who = $1;
  400. next;
  401. }
  402. if (/===== ([A-Z ]+) =====/) {
  403. $section = $1;
  404. next;
  405. }
  406. last if /===== End/;
  407. # Try to recover from a malformed log
  408. last if /^Max MB:/;
  409. # It was too malformed
  410. die "Malformed log" if /===== Running/;
  411. my $rightsection = 0;
  412. if ($section eq "INSERTS" && $oper eq "Ins") {
  413. $rightsection = 1;
  414. }
  415. if ($section eq "DELETES" && $oper eq "Del") {
  416. $rightsection = 1;
  417. }
  418. if ($rightsection) {
  419. if (/^(\d+) message bytes sent/) {
  420. $online_kib[$who] = $1 / 1024;
  421. } elsif (/^(\d+) Lamport clock/) {
  422. $online_latencies[$who] = $1;
  423. } elsif (/^(\d+) milliseconds? wall clock/) {
  424. $online_seconds[$who] = $1 / 1000;
  425. } elsif (/^Mem: (\d+) KiB/) {
  426. $online_mem_mib[$who] = $1 / 1024;
  427. }
  428. }
  429. if ($who == 0 && /^Precomputed values used: (.*)/) {
  430. my %used_resources = ();
  431. &parse_resources(\%used_resources, $1);
  432. my $preproc_resources_str = &serialize_resources(\%preproc_resources);
  433. my $used_resources_str = &serialize_resources(\%used_resources);
  434. if ($preproc_resources_str ne $used_resources_str) {
  435. warn "Resource usage does not match preprocessing:\n" .
  436. "Preproc: $preproc_resources_str\n" .
  437. "Used: $used_resources_str\n ";
  438. }
  439. }
  440. }
  441. my $label = "${optimized}PRAC avl$oper $netsetup$size $num";
  442. &accum_data(\%preproc_s_data, $label, &maxarray(@preproc_seconds));
  443. &accum_data(\%preproc_kib_data, $label, &avgarray(@preproc_kib));
  444. &accum_data(\%preproc_latencies_data, $label, &maxarray(@preproc_latencies));
  445. &accum_data(\%preproc_P0mem_mib_data, $label, $preproc_mem_mib[0]);
  446. &accum_data(\%preproc_P1mem_mib_data, $label, $preproc_mem_mib[1]);
  447. &accum_data(\%preproc_P2mem_mib_data, $label, $preproc_mem_mib[2]);
  448. &accum_data(\%online_s_data, $label, &maxarray(@online_seconds));
  449. &accum_data(\%online_kib_data, $label, &avgarray(@online_kib));
  450. &accum_data(\%online_latencies_data, $label, &maxarray(@online_latencies));
  451. &accum_data(\%online_P0mem_mib_data, $label, $online_mem_mib[0]);
  452. &accum_data(\%online_P1mem_mib_data, $label, $online_mem_mib[1]);
  453. &accum_data(\%online_P2mem_mib_data, $label, $online_mem_mib[2]);
  454. }
  455. sub parse_heapsampler {
  456. my $cmdline = $_[0];
  457. my $who = 0;
  458. my $section = '';
  459. my @online_seconds = (0, 0, 0);
  460. my @online_kib = (0, 0, 0);
  461. my @online_latencies = (0, 0, 0);
  462. my @online_mem_mib = (0, 0, 0);
  463. unless ($cmdline =~ /heapsampler (\d+) (\d+)/) {
  464. die "Cannot parse heapsampler cmdline: $cmdline";
  465. }
  466. my ($num, $size) = ($1, $2);
  467. while(<>) {
  468. if (/===== P([012]) output/) {
  469. $who = $1;
  470. next;
  471. }
  472. if (/===== ([A-Z ]+) =====/) {
  473. $section = $1;
  474. next;
  475. }
  476. last if /===== End/;
  477. # Try to recover from a malformed log
  478. last if /^Max MB:/;
  479. # It was too malformed
  480. die "Malformed log" if /===== Running/;
  481. if ($section eq "STREAMING") {
  482. if (/^(\d+) message bytes sent/) {
  483. $online_kib[$who] = $1 / 1024;
  484. } elsif (/^(\d+) Lamport clock/) {
  485. $online_latencies[$who] = $1;
  486. } elsif (/^(\d+) milliseconds? wall clock/) {
  487. $online_seconds[$who] = $1 / 1000;
  488. } elsif (/^Mem: (\d+) KiB/) {
  489. $online_mem_mib[$who] = $1 / 1024;
  490. }
  491. }
  492. if ($who == 0 && /^Precomputed values used: (.*)/) {
  493. my %used_resources = ();
  494. &parse_resources(\%used_resources, $1);
  495. my $preproc_resources_str = &serialize_resources(\%preproc_resources);
  496. my $used_resources_str = &serialize_resources(\%used_resources);
  497. if ($preproc_resources_str ne $used_resources_str) {
  498. warn "Resource usage does not match preprocessing:\n" .
  499. "Preproc: $preproc_resources_str\n" .
  500. "Used: $used_resources_str\n ";
  501. }
  502. }
  503. }
  504. my $label = "PRAC heapsampler $netsetup$size $num";
  505. &accum_data(\%preproc_s_data, $label, &maxarray(@preproc_seconds));
  506. &accum_data(\%preproc_kib_data, $label, &avgarray(@preproc_kib));
  507. &accum_data(\%preproc_latencies_data, $label, &maxarray(@preproc_latencies));
  508. &accum_data(\%preproc_P0mem_mib_data, $label, $preproc_mem_mib[0]);
  509. &accum_data(\%preproc_P1mem_mib_data, $label, $preproc_mem_mib[1]);
  510. &accum_data(\%preproc_P2mem_mib_data, $label, $preproc_mem_mib[2]);
  511. &accum_data(\%online_s_data, $label, &maxarray(@online_seconds));
  512. &accum_data(\%online_kib_data, $label, &avgarray(@online_kib));
  513. &accum_data(\%online_latencies_data, $label, &maxarray(@online_latencies));
  514. &accum_data(\%online_P0mem_mib_data, $label, $online_mem_mib[0]);
  515. &accum_data(\%online_P1mem_mib_data, $label, $online_mem_mib[1]);
  516. &accum_data(\%online_P2mem_mib_data, $label, $online_mem_mib[2]);
  517. }
  518. sub maxarray {
  519. my $max = $_[0];
  520. foreach (@_) {
  521. $max = $_ if $_ > $max;
  522. }
  523. $max;
  524. }
  525. sub avgarray {
  526. my $sum = 0;
  527. my $n = 0;
  528. foreach (@_) {
  529. $sum += $_;
  530. $n += 1;
  531. }
  532. $sum / $n;
  533. }
  534. # Pass:
  535. # - a reference to a dictionary
  536. # - the key into that dictionary
  537. # - the new data point
  538. # Data is stored in the dictionary as a triple (n, sum, sum_squares)
  539. sub accum_data {
  540. my ($dict, $key, $data) = @_;
  541. $dict->{$key} = [0, 0, 0] unless defined $dict->{$key};
  542. $dict->{$key}->[0] += 1;
  543. $dict->{$key}->[1] += $data;
  544. $dict->{$key}->[2] += ($data * $data);
  545. }
  546. # Convert data (in the form [n, sum, sum_squares]) to statistics (in
  547. # the form [mean, variance])
  548. sub statsify {
  549. my ($sdict, $ddict) = @_;
  550. my $key;
  551. foreach $key (keys %$ddict) {
  552. my $data = $ddict->{$key};
  553. my $n = $data->[0];
  554. my $sum = $data->[1];
  555. my $sumsq = $data->[2];
  556. if ($n == 0) {
  557. $sdict->{$key} = [undef, undef];
  558. } elsif ($n == 1) {
  559. $sdict->{$key} = [$sum, undef];
  560. } else {
  561. $sdict->{$key} = [$sum/$n, ($sumsq - ($sum*$sum/$n))/($n-1)];
  562. }
  563. }
  564. }
  565. # Turn a stat array [mean, variance] into a string to display
  566. sub statstr {
  567. my $data = $_[0];
  568. if (defined $data->[1]) {
  569. my $mean = $data->[0];
  570. my $stddev = $data->[1] > 0 ? sqrt($data->[1]) : 0;
  571. return "$mean ± $stddev";
  572. } elsif (defined $data->[0]) {
  573. return $data->[0];
  574. } else {
  575. return "none"
  576. }
  577. }
  578. # Sum two stat arrays
  579. sub statsum {
  580. my ($data0, $data1) = @_;
  581. if (defined $data0->[1] && defined $data1->[1]) {
  582. return [$data0->[0] + $data1->[0], $data0->[1] + $data1->[1]];
  583. } else {
  584. return [$data0->[0] + $data1->[0], undef];
  585. }
  586. }
  587. # Add the preproc and online stats to get the total stats
  588. sub sum_preproc_online {
  589. my ($tdict, $pdict, $odict) = @_;
  590. my $key;
  591. foreach $key (keys %$pdict) {
  592. if (defined $odict->{$key}) {
  593. $tdict->{$key} = &statsum($pdict->{$key}, $odict->{$key});
  594. }
  595. }
  596. }
  597. # Output the stats in the given dictionary. Append $phase to the
  598. # protocol name, and add $units to the end.
  599. sub output_stats {
  600. my ($dict, $phase, $units) = @_;
  601. my $label;
  602. foreach $label (sort keys %$dict) {
  603. my $printlabel = $label;
  604. $printlabel =~ s/PRAC/PRAC$phase/;
  605. print $printlabel, " ", &statstr($dict->{$label}), " $units\n";
  606. }
  607. }