Added snowflake probe test

This test will probe 100 snowflakes and produce logs and pcap files that
can be analyzed for throughput and Tor bootstrap progress.

README

@@ -20,12 +20,16 @@ where <bridge_line> is the line to go in the torrc file and is structured as fol
 Add to crontab to run tests 4x a day:
 	0 */6 * * * cd ~/bridgetest && ./probetest.sh [TYPE] [SITENAME]
 
-Analyze Tor bootstrap progress through obfs4 bridges from logs:
-	1. Make the CSV: find log -name '*.log' | sort | ./makecsv > obfs4test.csv
-	2. Plot the results: Rscript graph.R obfs4test.csv
+Analyze Tor bootstrap progress from logs:
+	1. Make the CSV: find log -name '*.log' | sort | ./makecsv > bootstrap.csv
+	2. Plot the results: Rscript graph.R bootstrap.csv
 
 Analyze obfs4 throughput from pcap files:
     1. Adapt the variables CLIENT_TUPLE and SERVER_TUPLE in infer-throughput.py.
     2. Run the script: python infer-throughput.py download.pcap > download.csv
     3. Plot the results: Rscript plot-throughput.R download.csv    
 
+Analyze snowflake throughput from pcap files:
+    1. Adapt the LOG_PATH variable in snowflake-throughput.py
+    2. Run the script: python snowflake-throughput.py > download.csv
+    3. Plot the results: Rscript snowflake-throughput.R download.csv    

probetest.sh

@@ -5,8 +5,8 @@ set -e
 CASE="${1:?}"
 SITE="${2:?}"
 
-if ! [[ "$CASE" =~ ^(obfs4)$ ]]; then
-    echo 'Error, please choose a valid test type from [obfs4]'
+if ! [[ "$CASE" =~ ^(obfs4|snowflake)$ ]]; then
+    echo 'Error, please choose a valid test type from ["obfs4"|"snowflake"]'
     exit 1
 fi
 
@@ -19,4 +19,7 @@ case $CASE in
     'obfs4')
         "$dirname/obfs4test" "$dirname/bridge_lines.txt"
         ;;
+    'snowflake')
+        "$dirname/snowflaketest"
+        ;;
 esac

snowflake-throughput.R

+library("ggplot2")
+library("reshape2")
+library("plyr")
+library(data.table)
+
+args <- commandArgs(trailingOnly = TRUE)
+data <- read.csv(args[1], header=TRUE)
+bootstrap <- read.csv(args[2], header=TRUE)
+
+latencies <- data[,2]/(1000*data[,3])
+len <- length(latencies)
+
+data <- latencies[!is.na(latencies)]
+
+print(paste("Number of failed downloads: ", len - length(data), sep=""))
+print(paste("Average throughput (KB/s): ", mean(data), sep=""))
+print(paste("Standard deviation: ", sd(data), sep=""))
+
+##latency
+ggdata <- data.frame(x = data)
+
+ggplot(ggdata, aes(x=x)) + 
+  stat_ecdf(show.legend=FALSE) + labs(x='Throughput (KB/s)', y='CDF') + 
+  theme(text = element_text(size=20,family="Times")) + theme_bw() + theme(text = element_text(size=20,family="Times"))
+
+ggsave("throughput.pdf",
+       width = 5,
+       height = 5)
+
+
+setDT(bootstrap)
+x.max <- bootstrap[ , .SD[which.max(percent)], by=.(site, runid, nickname)]
+setkey(x.max, site, runid)
+
+ggdata = data.frame(x = x.max$percent)
+
+ggplot(ggdata, aes(x=x)) + 
+  stat_ecdf(show.legend=FALSE) + labs(x='Bootstrap progress (%)', y='CDF') + 
+  theme(text = element_text(size=20,family="Times")) + theme_bw() + theme(text = element_text(size=20,family="Times"))
+
+ggsave("bootstrap.pdf",
+       width = 5,
+       height = 5)
+
+
+print(paste("Number of failed snowflakes: ", length(x.max$percent[x.max$percent <= 10]), sep=""))
+print(paste("Number of full bootstraps: ", length(x.max$percent[x.max$percent == 100]), sep=""))
+print(paste("Average bootstrap progress: ", mean(x.max$percent), sep=""))

snowflake-throughput.py

+#!/usr/bin/env python2
+"""
+Turn pcap into csv file.
+
+Problem:  A client is downloading a large file from a server and we want to
+          figure out if the throughput of the download degrades over time.
+
+Solution: We analyze the pcap file of the download and extract the ACK segments
+          that the client sends to the server.  From the ACK segments we can
+          infer how much data was transferred in a given time interval
+          (CUM_TIME_THRESHOLD).  We can then plot the number of downloaded
+          bytes per time interval and do a simple qualitative inspection.
+"""
+
+import sys
+import time
+
+import scapy.all as scapy
+
+LOG_PATH="log/linux-na/20191127-1845"
+
+# Change this to whatever client/server tuple you want to analyze.
+ip_addr = "127.0.0.1"
+server_port = 0
+
+# Number of seconds of our time intervals.
+CUM_TIME_THRESHOLD = 1
+
+timestamp = None
+prev_ack = None
+prev_time = None
+cum_time = 0
+sent_bytes = 0
+client_port = 0
+
+test_id = 0
+
+socks_re = re.compile('.*Socks listener listening on port (\d+)')
+
+print "test,bytes,timestamp"
+
+def ignore_packet(packet):
+
+    # Make sure that we only inspect the given client and server IP
+    # addresses.
+    if not packet.haslayer(scapy.IP):
+        return True
+    if not packet[scapy.IP].src == ip_addr:
+        return True
+    if not packet[scapy.IP].dst == ip_addr:
+        return True
+
+    # Make sure that we only inspect the given client and server TCP ports.
+    if not packet.haslayer(scapy.TCP):
+        return True
+    if not packet[scapy.TCP].dport == server_port:
+        return True
+
+    # Make sure that we're only inspecting ACK segments.
+    if not (packet[scapy.TCP].flags.A):
+        return True
+
+    return False
+
+
+def process_packet(packet):
+
+    global prev_ack
+    global prev_time
+    global cum_time
+    global sent_bytes
+    global timestamp
+    global client_port
+
+    if ignore_packet(packet):
+        return
+
+    # Reset measurements for a new connection
+    if not packet[scapy.TCP].sport == client_port:
+        client_port = packet[scapy.TCP].sport
+        timestamp = packet.time
+        prev_time = None
+        prev_ack = None
+        sent_bytes = 0
+        cum_time = 0
+
+    # Remember timestamp and ACK number of the very first segment.
+    if prev_time is None and prev_ack is None:
+        prev_time = packet.time
+        prev_ack = packet[scapy.TCP].ack
+        return
+
+    ack = packet[scapy.TCP].ack
+    sent_bytes += (ack - prev_ack)
+    cum_time += (packet.time - prev_time)
+
+    prev_ack = ack
+    prev_time = packet.time
+
+    return
+
+
+if __name__ == "__main__":
+
+    for i in range(0,100):
+        test_id = i
+        pcap_file = ("%s/snowflake-probe-%d.pcap" % (LOG_PATH, i) )
+        log_file = ("%s/snowflake-probe-%d.log" % (LOG_PATH, i) )
+
+        sys.stderr.write("Processing snowflake probe %d\n" % i)
+        # Figure out the Socks port from the log file
+        with open(log_file) as f:
+            for line in f:
+                m = socks_re.match(line)
+
+                if m is not None:
+                    server_port = int(m.group(1))
+                    sys.stderr.write("Found Socks port %s\n" % server_port)
+                    break
+
+
+        scapy.sniff(offline=pcap_file, prn=process_packet, store=0)
+        print "%d,%d,%.2f" % ( i, sent_bytes, cum_time)
+        sent_bytes = 0
+        cum_time = 0
+        prev_time = None
+        prev_ack = None

snowflaketest

+#!/usr/bin/env python3
+
+import errno
+import logging
+import os
+import re
+import shutil
+import subprocess
+import tempfile
+import time
+import sys
+
+import stem.process
+
+BRIDGE_LINES = (
+)
+
+START_TOR_TIMEOUT = 3*60
+CIRCUIT_BUILD_TIMEOUT = 3*60
+OBFS4PROXY_PATH = "/usr/bin/obfs4proxy"
+SNOWFLAKE_PATH = "/usr/bin/snowflake"
+
+def makedirs(path):
+    try:
+        return os.makedirs(path)
+    except OSError as e:
+        if e.errno != errno.EEXIST:
+            raise
+
+def get_address_from_bridge_line(bridge_line):
+    host, port = bridge_line.split()[1].split(":", 1)
+    port = int(port)
+    return (host, port)
+
+def start_tcpdump(basename):
+    # need to look at capture file to see which snowflake we got
+    bpf = "tcp"
+    # http://packetlife.net/blog/2010/mar/19/sniffing-wireshark-non-root-user/
+    # groupadd tcpdump
+    # usermod -a -G tcpdump user
+    # chgrp tcpdump /usr/sbin/tcpdump
+    # setcap cap_net_raw,cap_net_admin=eip /usr/sbin/tcpdump
+    p = subprocess.Popen(["/usr/sbin/tcpdump", "-i", "lo", "-U", "-B", "4096", "-w", basename + ".pcap", bpf],
+        stdout=open(basename + ".pcap", "w"),
+        stderr=open(basename + ".tcpdump.err", "w"))
+    return p
+
+def download_file(socks_port):
+    logging.info("Attempting to download large file")
+    
+    try:
+        start = time.time()
+        # Download a ~1MB file
+        subprocess.run(["/usr/bin/torsocks", "-P", str(socks_port), "wget", "-O", "/dev/null", "https://mirror.csclub.uwaterloo.ca/ubuntu/dists/xenial/main/binary-amd64/Packages.xz"], check=True)
+        stop = time.time()
+        download_time = stop - start
+    except subprocess.CalledProcessError as e:
+        logging.info("failed to download file: %s", e)
+
+
+def start_tor(tor_config):
+    assert "DataDirectory" in tor_config
+
+    config = {
+        "SOCKSPort": "auto",
+        "ControlPort": "auto",
+        "CookieAuthentication": "1",
+        "LearnCircuitBuildTimeout": "0",
+        "CircuitBuildTimeout": str(CIRCUIT_BUILD_TIMEOUT),
+        "FetchHidServDescriptors": "0",
+        "ClientTransportPlugin": "obfs4 exec %s" % OBFS4PROXY_PATH,
+        "LogTimeGranularity": "1",
+        "Log": "notice stdout",
+    }
+    config.update(tor_config)
+
+    class Ports(object):
+        socks = None
+        control = None
+    ports = Ports()
+    socks_re = re.compile(r'\bSocks listener listening on port ([0-9]+)\.')
+    control_re = re.compile(r'\bControl listener listening on port ([0-9]+)\.')
+    def init_msg_handler(line):
+        logging.info("tor: %s" % line.encode("unicode_escape"))
+        m = socks_re.search(line)
+        if m is not None:
+            assert ports.socks is None
+            ports.socks = int(m.group(1))
+        m = control_re.search(line)
+        if m is not None:
+            assert ports.control is None
+            ports.control = int(m.group(1))
+
+    logging.info("starting tor with configuration %r" % config)
+
+    proc = stem.process.launch_tor_with_config(
+        config,
+        timeout=START_TOR_TIMEOUT,
+        take_ownership=True,
+        init_msg_handler=init_msg_handler,
+    )
+
+    assert ports.socks is not None
+    assert ports.control is not None
+
+    return proc, ports.socks, ports.control
+
+logging.basicConfig(
+    level=logging.INFO,
+    format="%(asctime)s.%(msecs)03d %(message)s",
+    datefmt="%Y-%m-%d %H:%M:%S",
+)
+logging.Formatter.converter = time.gmtime
+
+# Set timezone to be inherited by tor processes.
+os.environ["TZ"] = "UTC"
+time.tzset()
+
+logging.info("starting")
+
+#Now do a set of probes of snowflake proxies
+for x in range(0, 100):
+    nickname = "snowflake-probe-%(num)d" % {"num": x}
+    datadir = tempfile.mkdtemp(prefix="datadir.", dir=".")
+    logging.info("created temporary DataDirectory %r", datadir)
+    tcpdump_proc = None
+    try:
+        logging.info("starting tcpdump for bridge %r" % nickname)
+        try:
+            tcpdump_proc = start_tcpdump(nickname)
+        except OSError as e:
+            logging.info("failed to start tcpdump, stopping snowflake probe: %s", e)
+            #these tests break if we can't find the proxy ip address
+            break
+	
+        logging.info("starting tor for bridge %r" % nickname)
+        tor_config = {
+		"DataDirectory": datadir, 
+		"Log": "notice file %s" % os.path.join(".", "%s.log" % nickname),
+		"UseBridges": "1",
+		"ClientTransportPlugin": "snowflake exec %s \
+					-url https://snowflake-broker.azureedge.net/ \
+					-front ajax.aspnetcdn.com \
+					-ice stun:stun.l.google.com:19302" % SNOWFLAKE_PATH,
+		"Bridge": "snowflake 0.0.3.0:1",
+		}
+        try:
+            tor_proc, socks_port, _ = start_tor(tor_config)
+            download_file(socks_port)
+            tor_proc.terminate()
+            tor_proc.wait()
+        except OSError as err:
+            logging.info("failed to start tor: %s" % err)
+            continue
+
+    finally:
+	#Extract the proxy ip
+        logging.info("deleting temporary DataDirectory %r", datadir)
+        shutil.rmtree(datadir)
+        if tcpdump_proc is not None:
+            tcpdump_proc.terminate()
+