123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381 |
- #!/usr/bin/perl
- # Parse the log output files of run-experiment
- # Send concatenated log files to stdin, or list them on the command
- # line.
- use strict;
- my $mode = '';
- my $depth = 0;
- my $numops = 0;
- my $phase = '';
- my $numparties = '';
- my $what = '';
- my $setupsize = 0;
- my $opsize = 0;
- my @seconds = (0, 0);
- my $netsetup = '';
- my %preproc_s_data = ();
- my %preproc_kib_data = ();
- my %online_s_data = ();
- my %online_kib_data = ();
- while(<>) {
- chomp;
- if (/Network setup: (.*)/) {
- $netsetup = "$1 ";
- next;
- }
- if (/===== Running duoram (\S+) (\d+) (\d+) (\S+) ([23]P)/) {
- $mode = $1;
- $depth = $2;
- $numops = $3;
- $phase = $4;
- $numparties = $5;
- my $label = "${numparties}Duoram $mode $depth $netsetup$numops";
- if ($mode eq "read" && $numparties eq "2P") {
- &parse_2P_read($label);
- } elsif ($mode eq "write" && $numparties eq "2P" && $phase eq "preproc") {
- &parse_2P_write_preproc($label);
- } elsif ($mode eq "write" && $numparties eq "2P" && $phase eq "online") {
- &parse_2P_write_online($label);
- } elsif ($numparties eq "3P" && $phase eq "preproc") {
- &parse_3P_preproc("$depth $netsetup$numops");
- } elsif ($numparties eq "3P" && $phase eq "online") {
- &parse_3P_online("$depth $netsetup$numops");
- }
- @seconds = (0,0);
- $what = '';
- $setupsize = 0;
- $opsize = 0;
- next;
- }
- }
- # Convert the data (in the form [n, sum, sum_squares]) to statistics (in
- # the form [mean, variance])
- my %preproc_s_stats = ();
- my %preproc_kib_stats = ();
- my %online_s_stats = ();
- my %online_kib_stats = ();
- &statsify(\%preproc_s_stats, \%preproc_s_data);
- &statsify(\%preproc_kib_stats, \%preproc_kib_data);
- &statsify(\%online_s_stats, \%online_s_data);
- &statsify(\%online_kib_stats, \%online_kib_data);
- # The 2P readwrite values are just the sums of the read and the write values
- &sum_readwrite_2P(\%preproc_s_stats);
- &sum_readwrite_2P(\%preproc_kib_stats);
- &sum_readwrite_2P(\%online_s_stats);
- &sum_readwrite_2P(\%online_kib_stats);
- # The total values are the sums of the preproc and online values
- my %total_s_stats = ();
- my %total_kib_stats = ();
- &sum_preproc_online(\%total_s_stats, \%preproc_s_stats, \%online_s_stats);
- &sum_preproc_online(\%total_kib_stats, \%preproc_kib_stats, \%online_kib_stats);
- # Output the data
- &output_stats(\%preproc_s_stats, "Preprc", "s");
- &output_stats(\%preproc_kib_stats, "Preprc", "KiB");
- &output_stats(\%online_s_stats, "Onln", "s");
- &output_stats(\%online_kib_stats, "Onln", "KiB");
- &output_stats(\%total_s_stats, "Totl", "s");
- &output_stats(\%total_kib_stats, "Totl", "KiB");
- # Subroutines
- sub parse_2P_read {
- my $label = $_[0];
- my $who = 0;
- my @preproc_s = ();
- my @preproc_kib = ();
- my @online_s = ();
- my @online_kib = ();
- while(<>) {
- last if /===== End/;
- # Try to recover from a malformed log
- last if /^Max GB:/;
- # It was too malformed
- die "Malformed log" if /===== Running/;
- if (/===== P([012]) output/) {
- $who = $1;
- next;
- }
- if (/Total preprocessing time: (\d+) µs/) {
- $preproc_s[$who] = $1 / 1000000;
- }
- if (/Total preprocessing bytes: (\d+)/) {
- $preproc_kib[$who] = $1 / 1024;
- }
- if (/Total query time: (\d+) µs/) {
- $online_s[$who] = $1 / 1000000;
- }
- if (/Total query bytes: (\d+)/) {
- $online_kib[$who] = $1 / 1024;
- }
- }
- return if $#preproc_s < 0;
- &accum_data(\%preproc_s_data, $label, &maxarray(@preproc_s));
- &accum_data(\%preproc_kib_data, $label, &avgarray(@preproc_kib));
- &accum_data(\%online_s_data, $label, &maxarray(@online_s));
- &accum_data(\%online_kib_data, $label, &avgarray(@online_kib));
- }
- sub parse_2P_write_preproc {
- my $label = $_[0];
- my $who = 0;
- my @preproc_s = ();
- my @preproc_kib = ();
- while(<>) {
- last if /===== End/;
- # Try to recover from a malformed log
- last if /^Max GB:/;
- # It was too malformed
- die "Malformed log" if /===== Running/;
- if (/===== P([012]) output/) {
- $who = $1;
- next;
- }
- if (/time to generate and evaluate \d+ OTs is: (\d+\.?\d*+)s/) {
- $preproc_s[$who] = $1;
- }
- if (/bytes transmitted for OT = (\d+) bytes/) {
- $preproc_kib[$who] = $1 / 1024;
- }
- if (/WallClockTime: (\d+\.?\d*) s/) {
- $preproc_s[$who] += $1;
- }
- if (/CommunicationCost: (\d+) bytes/) {
- $preproc_kib[$who] += $1 / 1024;
- }
- }
- return if $#preproc_s < 0;
- &accum_data(\%preproc_s_data, $label, &maxarray(@preproc_s));
- &accum_data(\%preproc_kib_data, $label, &avgarray(@preproc_kib));
- }
- sub parse_2P_write_online {
- my $label = $_[0];
- my $who = 0;
- my @online_s = ();
- my @online_kib = ();
- while(<>) {
- last if /===== End/;
- # Try to recover from a malformed log
- last if /^Max GB:/;
- # It was too malformed
- die "Malformed log" if /===== Running/;
- if (/===== P([012]) output/) {
- $who = $1;
- next;
- }
- if (/write_time = (\d+\.?\d*)/) {
- $online_s[$who] = $1;
- }
- if (/communication_cost_writes = (\d+) bytes/) {
- $online_kib[$who] = $1 / 1024;
- }
- }
- return if $#online_s < 0;
- &accum_data(\%online_s_data, $label, &maxarray(@online_s));
- &accum_data(\%online_kib_data, $label, &avgarray(@online_kib));
- }
- sub parse_3P_preproc {
- my $labelsuffix = $_[0];
- my $who = 0;
- my @preproc_s = ();
- my @preproc_kib = ();
- while(<>) {
- if (/===== P([012]) output/) {
- $who = $1;
- next;
- }
- last if /===== End/;
- # Try to recover from a malformed log
- last if /^Max GB:/;
- # It was too malformed
- die "Malformed log" if /===== Running/;
- if (/WallClockTime: (\d+\.?\d*)/) {
- $preproc_s[$who] = $1;
- }
- if (/CommunicationCost: (\d+) bytes/) {
- $preproc_kib[$who] = $1 / 1024;
- }
- }
- return if $#preproc_s < 0;
- &accum_data(\%preproc_s_data, "3PDuoram read $labelsuffix", &maxarray(@preproc_s));
- &accum_data(\%preproc_kib_data, "3PDuoram read $labelsuffix", &avgarray(@preproc_kib));
- &accum_data(\%preproc_s_data, "3PDuoram write $labelsuffix", &maxarray(@preproc_s));
- &accum_data(\%preproc_kib_data, "3PDuoram write $labelsuffix", &avgarray(@preproc_kib));
- &accum_data(\%preproc_s_data, "3PDuoram readwrite $labelsuffix", 2*&maxarray(@preproc_s));
- &accum_data(\%preproc_kib_data, "3PDuoram readwrite $labelsuffix", 2*&avgarray(@preproc_kib));
- }
- sub parse_3P_online {
- my $labelsuffix = $_[0];
- my $who = 0;
- my @read_s = ();
- my @read_kib = ();
- my @write_s = ();
- my @write_kib = ();
- my @readwrite_s = ();
- my @readwrite_kib = ();
- while(<>) {
- last if /===== End/;
- # Try to recover from a malformed log
- last if /^Max GB:/;
- # It was too malformed
- die "Malformed log" if /===== Running/;
- if (/===== P([012]) output/) {
- $who = $1;
- next;
- }
- if (/write_time =\s+(\d+\.?\d*)/) {
- $write_s[$who] = $1;
- }
- if (/communication_cost_writes = (\d+) bytes/) {
- $write_kib[$who] = $1 / 1024;
- }
- if (/dependent_read_time =\s+(\d+\.?\d*)/) {
- $read_s[$who] = $1;
- }
- if (/communication_cost_dep_read = (\d+) bytes/) {
- $read_kib[$who] = $1 / 1024;
- }
- if (/interleaved_time =\s+(\d+\.?\d*)/) {
- $readwrite_s[$who] = $1;
- }
- if (/communication_cost_interleaved = (\d+) bytes/) {
- $readwrite_kib[$who] = $1 / 1024;
- }
- }
- return if $#read_s < 0;
- &accum_data(\%online_s_data, "3PDuoram read $labelsuffix", &maxarray(@read_s));
- &accum_data(\%online_kib_data, "3PDuoram read $labelsuffix", &avgarray(@read_kib));
- &accum_data(\%online_s_data, "3PDuoram write $labelsuffix", &maxarray(@write_s));
- &accum_data(\%online_kib_data, "3PDuoram write $labelsuffix", &avgarray(@write_kib));
- &accum_data(\%online_s_data, "3PDuoram readwrite $labelsuffix", &maxarray(@readwrite_s));
- &accum_data(\%online_kib_data, "3PDuoram readwrite $labelsuffix", &avgarray(@readwrite_kib));
- }
- sub maxarray {
- my $max = $_[0];
- foreach (@_) {
- $max = $_ if $_ > $max;
- }
- $max;
- }
- sub avgarray {
- my $sum = 0;
- my $n = 0;
- foreach (@_) {
- $sum += $_;
- $n += 1;
- }
- $sum / $n;
- }
- # Pass:
- # - a reference to a dictionary
- # - the key into that dictionary
- # - the new data point
- # Data is stored in the dictionary as a triple (n, sum, sum_squares)
- sub accum_data {
- my ($dict, $key, $data) = @_;
- $dict->{$key} = [0, 0, 0] unless defined $dict->{$key};
- $dict->{$key}->[0] += 1;
- $dict->{$key}->[1] += $data;
- $dict->{$key}->[2] += ($data * $data);
- }
- # Convert data (in the form [n, sum, sum_squares]) to statistics (in
- # the form [mean, variance])
- sub statsify {
- my ($sdict, $ddict) = @_;
- my $key;
- foreach $key (keys %$ddict) {
- my $data = $ddict->{$key};
- my $n = $data->[0];
- my $sum = $data->[1];
- my $sumsq = $data->[2];
- if ($n == 0) {
- $sdict->{$key} = [undef, undef];
- } elsif ($n == 1) {
- $sdict->{$key} = [$sum, undef];
- } else {
- $sdict->{$key} = [$sum/$n, ($sumsq - ($sum*$sum/$n))/($n-1)];
- }
- }
- }
- # Turn a stat array [mean, variance] into a string to display
- sub statstr {
- my $data = $_[0];
- if (defined $data->[1]) {
- my $mean = $data->[0];
- my $stddev = $data->[1] > 0 ? sqrt($data->[1]) : 0;
- return "$mean ± $stddev";
- } elsif (defined $data->[0]) {
- return $data->[0];
- } else {
- return "none"
- }
- }
- # Sum two stat arrays
- sub statsum {
- my ($data0, $data1) = @_;
- if (defined $data0->[1] && defined $data1->[1]) {
- return [$data0->[0] + $data1->[0], $data0->[1] + $data1->[1]];
- } else {
- return [$data0->[0] + $data1->[0], undef];
- }
- }
- # The 2P readwrite values are just the sums of the read and the write values
- sub sum_readwrite_2P {
- my $dict = $_[0];
- my $key;
- foreach $key (keys %$dict) {
- if ($key =~ /^2PDuoram read /) {
- my $writekey = $key;
- my $readwritekey = $key;
- $writekey =~ s/^2PDuoram read /2PDuoram write /;
- $readwritekey =~ s/^2PDuoram read /2PDuoram readwrite /;
- if (defined $dict->{$writekey}) {
- $dict->{$readwritekey} = &statsum($dict->{$key}, $dict->{$writekey});
- } else {
- # It's OK if we're missing the data point, since we
- # don't necessary parse all the data at once.
- # print "Missing data point for $writekey\n";
- }
- }
- }
- }
- # Add the preproc and online stats to get the total stats
- sub sum_preproc_online {
- my ($tdict, $pdict, $odict) = @_;
- my $key;
- foreach $key (keys %$pdict) {
- if (defined $odict->{$key}) {
- $tdict->{$key} = &statsum($pdict->{$key}, $odict->{$key});
- }
- }
- }
- # Output the stats in the given dictionary. Append $phase to the
- # protocol name, and add $units to the end.
- sub output_stats {
- my ($dict, $phase, $units) = @_;
- my $label;
- foreach $label (sort keys %$dict) {
- my $printlabel = $label;
- $printlabel =~ s/PDuoram/PDuoram$phase/;
- print $printlabel, " ", &statstr($dict->{$label}), " $units\n";
- }
- }
|