parse_logs for Duoram

Docker/parse_logs

@@ -0,0 +1,352 @@
+#!/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/;
+        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;
+        }
+    }
+    &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/;
+        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;
+        }
+    }
+    &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/;
+        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;
+        }
+    }
+    &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(<>) {
+        last if /===== End/;
+        if (/WallClockTime: (\d+\.?\d*)/) {
+            $preproc_s[$who] = $1;
+        }
+        if (/CommunicationCost: (\d+) bytes/) {
+            $preproc_kib[$who] = $1 / 1024;
+        }
+    }
+    &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/;
+        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;
+        }
+    }
+    &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 = sqrt($data->[1]);
+        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";
+    }
+}

Docker/repro

@@ -89,9 +89,19 @@ run() {
     runone read $1 $2 $3 $4 online 2P
     runone write $1 $2 $3 $4 preproc 2P
     runone write $1 $2 $3 $4 online 2P
-    # The 3P protocols do both reads and writes
+    # The 2P read and write protocols are completely different, so
+    # readwrite is just the sum of read and write.
+    # The 3P preprocessing protocol is identical for reads and writes,
+    # so we just do it once, and count it twice for readwrite.
     runone read $1 $2 $3 $4 preproc 3P
-    runone read $1 $2 $3 $4 online 3P
+    # The 3P online protocols do reads, writes, and readwrites in a
+    # single run.
+    runone readwrite $1 $2 $3 $4 online 3P
+    # Clean up any preprocessed DPFs
+    docker exec -w /root/duoram/duoram-online/preprocflags duoram_p0 bash -c "rm -f *" &
+    docker exec -w /root/duoram/duoram-online/preprocflags duoram_p1 bash -c "rm -f *" &
+    docker exec -w /root/duoram/duoram-online/preprocflags duoram_p2 bash -c "rm -f *" &
+    wait
 }
 
 # Parse the output logs.  We run this in the docker in case you don't
@@ -181,38 +191,80 @@ fi
 now=`date`
 echo "$now: Experiments complete"
 
-# # If you specified a custom log suffix, you're going to be parsing the
-# # outputs differently.
-# if [ "$LOGSUFFIX" = "" ]; then
-
-# parse *_${numops}.out > floram_${numops}.dat
-
-# echo
-# echo "# Figure 7(a)"
-# egrep 'Duoram readwrite .* 30ms 100mbit .* s$' floram_${numops}.dat | sort -k3 -n
-# echo
-# echo "# Figure 7(b)"
-# egrep 'Duoram readwrite 20 30ms .* s$' floram_${numops}.dat | sort -k5 -n
-# echo
-# echo "# Figure 7(c)"
-# egrep 'Duoram readwrite 20 .* 100mbit .* s$' floram_${numops}.dat | sort -k4 -n
-# echo
-# echo "# Figure 8(a)"
-# egrep 'Duoram read .* 1us 100gbit .* KiB$' floram_${numops}.dat | sort -k3 -n
-# echo
-# echo "# Figure 8(b)"
-# egrep 'Duoram write .* 1us 100gbit .* KiB$' floram_${numops}.dat | sort -k3 -n
-# echo
-# echo "# Figure 8(c)"
-# egrep 'Duoram readwrite .* 30ms 100mbit .* KiB$' floram_${numops}.dat | sort -k3 -n
-# echo
-# echo "# Figure 9(a)"
-# egrep 'Duoram read .* 30ms 100mbit .* s$' floram_${numops}.dat | sort -k3 -n
-# echo
-# echo "# Figure 9(b)"
-# egrep 'Duoram read .* 1us 100gbit .* s$' floram_${numops}.dat | sort -k3 -n
-# echo
-# echo "# Figure 9(c)"
-# egrep 'Duoram read .* 1us 100gbit .* KiB$' floram_${numops}.dat | sort -k3 -n
-
-# fi
+# If you specified a custom log suffix, you're going to be parsing the
+# outputs differently.
+if [ "$LOGSUFFIX" = "" ]; then
+
+parse *_${numops}_{online,preproc}_{2P,3P}.out > duoram_${numops}.dat
+
+echo
+echo "# Figure 7(a)"
+egrep '2PDuoramOnln readwrite .* 30ms 100mbit .* s$' duoram_${numops}.dat | sort -k3 -n
+echo
+egrep '2PDuoramTotl readwrite .* 30ms 100mbit .* s$' duoram_${numops}.dat | sort -k3 -n
+echo
+egrep '3PDuoramOnln readwrite .* 30ms 100mbit .* s$' duoram_${numops}.dat | sort -k3 -n
+echo
+egrep '3PDuoramTotl readwrite .* 30ms 100mbit .* s$' duoram_${numops}.dat | sort -k3 -n
+echo
+echo "# Figure 7(b)"
+egrep '2PDuoramOnln readwrite 20 30ms .* s$' duoram_${numops}.dat | sort -k5 -n
+echo
+egrep '2PDuoramTotl readwrite 20 30ms .* s$' duoram_${numops}.dat | sort -k5 -n
+echo
+egrep '3PDuoramOnln readwrite 20 30ms .* s$' duoram_${numops}.dat | sort -k5 -n
+echo
+egrep '3PDuoramTotl readwrite 20 30ms .* s$' duoram_${numops}.dat | sort -k5 -n
+echo
+echo "# Figure 7(c)"
+egrep '2PDuoramOnln readwrite 20 .* 100mbit .* s$' duoram_${numops}.dat | sort -k4 -n
+echo
+egrep '2PDuoramTotl readwrite 20 .* 100mbit .* s$' duoram_${numops}.dat | sort -k4 -n
+echo
+egrep '3PDuoramOnln readwrite 20 .* 100mbit .* s$' duoram_${numops}.dat | sort -k4 -n
+echo
+egrep '3PDuoramTotl readwrite 20 .* 100mbit .* s$' duoram_${numops}.dat | sort -k4 -n
+echo
+echo "# Figure 8(a)"
+egrep '2PDuoramOnln read .* 1us 100gbit .* KiB$' duoram_${numops}.dat | sort -k3 -n
+echo
+egrep '2PDuoramTotl read .* 1us 100gbit .* KiB$' duoram_${numops}.dat | sort -k3 -n
+echo
+egrep '3PDuoramOnln read .* 1us 100gbit .* KiB$' duoram_${numops}.dat | sort -k3 -n
+echo
+egrep '3PDuoramTotl read .* 1us 100gbit .* KiB$' duoram_${numops}.dat | sort -k3 -n
+echo
+echo "# Figure 8(b)"
+egrep '2PDuoramOnln write .* 1us 100gbit .* KiB$' duoram_${numops}.dat | sort -k3 -n
+echo
+egrep '2PDuoramTotl write .* 1us 100gbit .* KiB$' duoram_${numops}.dat | sort -k3 -n
+echo
+egrep '3PDuoramOnln write .* 1us 100gbit .* KiB$' duoram_${numops}.dat | sort -k3 -n
+echo
+egrep '3PDuoramTotl write .* 1us 100gbit .* KiB$' duoram_${numops}.dat | sort -k3 -n
+echo
+echo "# Figure 8(c)"
+egrep '2PDuoramOnln readwrite .* 30ms 100mbit .* KiB$' duoram_${numops}.dat | sort -k3 -n
+echo
+egrep '2PDuoramTotl readwrite .* 30ms 100mbit .* KiB$' duoram_${numops}.dat | sort -k3 -n
+echo
+egrep '3PDuoramOnln readwrite .* 30ms 100mbit .* KiB$' duoram_${numops}.dat | sort -k3 -n
+echo
+egrep '3PDuoramTotl readwrite .* 30ms 100mbit .* KiB$' duoram_${numops}.dat | sort -k3 -n
+echo
+echo "# Figure 9(a)"
+egrep '3PDuoramOnln read .* 30ms 100mbit .* s$' duoram_${numops}.dat | sort -k3 -n
+echo
+egrep '3PDuoramTotl read .* 30ms 100mbit .* s$' duoram_${numops}.dat | sort -k3 -n
+echo
+echo "# Figure 9(b)"
+egrep '3PDuoramOnln read .* 1us 100gbit .* s$' duoram_${numops}.dat | sort -k3 -n
+echo
+egrep '3PDuoramTotl read .* 1us 100gbit .* s$' duoram_${numops}.dat | sort -k3 -n
+echo
+echo "# Figure 9(c)"
+egrep '3PDuoramOnln read .* 1us 100gbit .* KiB$' duoram_${numops}.dat | sort -k3 -n
+echo
+egrep '3PDuoramTotl read .* 1us 100gbit .* KiB$' duoram_${numops}.dat | sort -k3 -n
+
+fi