From 0509874d6f1f5a125c33687198fed6e11fa7ca21 Mon Sep 17 00:00:00 2001 From: Sean McBride Date: Sat, 3 Oct 2020 19:19:07 -0400 Subject: [PATCH] test: add concurrency experiment --- .gitignore | 3 + runtime/Makefile | 20 ++- runtime/experiments/concurrency/.gitignore | 1 + runtime/experiments/concurrency/debug.sh | 19 +++ .../experiments/concurrency/latency.gnuplot | 19 +++ runtime/experiments/concurrency/run.sh | 139 ++++++++++++++++++ runtime/experiments/concurrency/spec.json | 14 ++ .../experiments/concurrency/success.gnuplot | 12 ++ .../concurrency/throughput.gnuplot | 12 ++ runtime/tests/raw_utilization/debug.sh | 19 --- runtime/tests/raw_utilization/demo.sh | 39 ----- runtime/tests/raw_utilization/post.lua | 58 -------- .../test_mixed_preemption.json | 70 --------- 13 files changed, 228 insertions(+), 197 deletions(-) create mode 100644 runtime/experiments/concurrency/.gitignore create mode 100755 runtime/experiments/concurrency/debug.sh create mode 100644 runtime/experiments/concurrency/latency.gnuplot create mode 100755 runtime/experiments/concurrency/run.sh create mode 100644 runtime/experiments/concurrency/spec.json create mode 100644 runtime/experiments/concurrency/success.gnuplot create mode 100644 runtime/experiments/concurrency/throughput.gnuplot delete mode 100755 runtime/tests/raw_utilization/debug.sh delete mode 100755 runtime/tests/raw_utilization/demo.sh delete mode 100644 runtime/tests/raw_utilization/post.lua delete mode 100644 runtime/tests/raw_utilization/test_mixed_preemption.json diff --git a/.gitignore b/.gitignore index 481a919..bcb5681 100644 --- a/.gitignore +++ b/.gitignore @@ -53,6 +53,9 @@ dkms.conf runtime/tags runtime/bin runtime/tests/tmp/ +runtime/tests/**/*.csv +runtime/tests/**/*.txt +runtime/tests/**/*.xlsx # Swap Files *.swp diff --git a/runtime/Makefile b/runtime/Makefile index dbdc3ff..954b5de 100644 --- a/runtime/Makefile +++ b/runtime/Makefile @@ -13,7 +13,7 @@ BINARY_NAME=sledgert # Number of Cores. Options: {2...N or TOTAL_CORES} # NCORES = ${TOTAL_CORES} -NCORES = 2 +NCORES = 8 # Options: {USE_MEM_GENERIC, USE_MEM_VM} USE_MEM = USE_MEM_VM @@ -21,19 +21,20 @@ USE_MEM = USE_MEM_VM # Debugging Flags # Strips out calls to assert() -# CFLAGS += -DNDEBUG +CFLAGS += -DNDEBUG # Turns on debuglog and other assorted printfs in third party libs -CFLAGS += -DDEBUG +# CFLAGS += -DDEBUG # Redirects debuglogs to /runtime/bin/awesome.log #FIXME This log should be changed to sledge.log (and likely to a user defined path) # CFLAGS += -DLOG_TO_FILE # Various Informational Logs for Debugging -CFLAGS += -DLOG_STATE_CHANGES +# CFLAGS += -DLOG_HTTP_PARSER +# CFLAGS += -DLOG_STATE_CHANGES # CFLAGS += -DLOG_LOCK_OVERHEAD -CFLAGS += -DLOG_CONTEXT_SWITCHES +# CFLAGS += -DLOG_CONTEXT_SWITCHES # CFLAGS += -DLOG_ADMISSIONS_CONTROL # CFLAGS += -DLOG_SANDBOX_PERF # CFLAGS += -DLOG_REQUEST_ALLOCATION @@ -43,19 +44,16 @@ CFLAGS += -DLOG_CONTEXT_SWITCHES # This flag dumps totals of incoming requests and outgoing responses, broken out by status code # family, such as 2XX, 4XX, 5XX. It is useful to debug clients hanging waiting for a response. # To log, run `call runtime_log_requests_responses()` while in GDB -CFLAGS += -DLOG_TOTAL_REQS_RESPS +# CFLAGS += -DLOG_TOTAL_REQS_RESPS # This flag logs the total number of sandboxes in the various states # It is useful to debug if sandboxes are "getting caught" in a particular state # To log, run `call runtime_log_sandbox_states()` while in GDB -CFLAGS += -DLOG_SANDBOX_TOTALS +# CFLAGS += -DLOG_SANDBOX_TOTALS # This flag enables an per-worker atomic count of sandbox's local runqueue count in thread local storage # Useful to debug if sandboxes are "getting caught" or "leaking" while in a local runqueue -CFLAGS += -DLOG_LOCAL_RUNQUEUE - -# Debug the HTTP Parser -CFLAGS += -DLOG_HTTP_PARSER +# CFLAGS += -DLOG_LOCAL_RUNQUEUE # System Configuraiton Flags diff --git a/runtime/experiments/concurrency/.gitignore b/runtime/experiments/concurrency/.gitignore new file mode 100644 index 0000000..64f722e --- /dev/null +++ b/runtime/experiments/concurrency/.gitignore @@ -0,0 +1 @@ +res diff --git a/runtime/experiments/concurrency/debug.sh b/runtime/experiments/concurrency/debug.sh new file mode 100755 index 0000000..62c64e3 --- /dev/null +++ b/runtime/experiments/concurrency/debug.sh @@ -0,0 +1,19 @@ +#!/bin/bash +# Executes the runtime in GDB +# Substitutes the absolute path from the container with a path relatively derived from the location of this script +# This allows debugging outside of the Docker container +# Also disables pagination and stopping on SIGUSR1 + +experiment_directory=$(pwd) +project_directory=$(cd ../.. && pwd) +binary_directory=$(cd "$project_directory"/bin && pwd) + +export LD_LIBRARY_PATH="$binary_directory:$LD_LIBRARY_PATH" +export PATH="$binary_directory:$PATH" + +gdb --eval-command="handle SIGUSR1 nostop" \ + --eval-command="handle SIGPIPE nostop" \ + --eval-command="set pagination off" \ + --eval-command="set substitute-path /sledge/runtime $project_directory" \ + --eval-command="run $experiment_directory/spec.json" \ + sledgert diff --git a/runtime/experiments/concurrency/latency.gnuplot b/runtime/experiments/concurrency/latency.gnuplot new file mode 100644 index 0000000..af8cffe --- /dev/null +++ b/runtime/experiments/concurrency/latency.gnuplot @@ -0,0 +1,19 @@ +reset + +set term jpeg +set output "latency.jpg" + +set xlabel "Concurrency" +set ylabel "Latency (ms)" + +set key left top + +set xrange [-5:105] +set yrange [0:] + +set style histogram columnstacked + +plot 'latency.dat' using 1:2 title 'p50', \ + 'latency.dat' using 1:3 title 'p90', \ + 'latency.dat' using 1:4 title 'p99', \ + 'latency.dat' using 1:5 title 'p100', \ diff --git a/runtime/experiments/concurrency/run.sh b/runtime/experiments/concurrency/run.sh new file mode 100755 index 0000000..01bab05 --- /dev/null +++ b/runtime/experiments/concurrency/run.sh @@ -0,0 +1,139 @@ +#!/bin/bash + +# This experiment is intended to document how the level of concurrent requests influence the latency, throughput, and success/failure rate +# Use -d flag if running under gdb + +timestamp=$(date +%s) +experiment_directory=$(pwd) +binary_directory=$(cd ../../bin && pwd) +results_directory="$experiment_directory/res/$timestamp" +log=log.txt + +mkdir -p "$results_directory" + +{ + echo "*******" + echo "* Git *" + echo "*******" + git log | head -n 1 | cut -d' ' -f2 + git status + echo "" + + echo "************" + echo "* Makefile *" + echo "************" + cat ../../Makefile + echo "" + + echo "**********" + echo "* Run.sh *" + echo "**********" + cat run.sh + echo "" + + echo "************" + echo "* Hardware *" + echo "************" + lscpu + echo "" + + echo "*************" + echo "* Execution *" + echo "*************" +} >>"$results_directory/$log" + +# Start the runtime +if [ "$1" != "-d" ]; then + PATH="$binary_directory:$PATH" LD_LIBRARY_PATH="$binary_directory:$LD_LIBRARY_PATH" sledgert "$experiment_directory/spec.json" >>"$results_directory/$log" 2>>"$results_directory/$log" & + sleep 1 +else + echo "Running under gdb" + echo "Running under gdb" >>"$results_directory/$log" +fi + +# Execute workloads long enough for runtime to learn excepted execution time +echo -n "Running Samples: " +hey -n 10000 -c 3 -q 200 -o csv -m GET http://localhost:10000 +sleep 5 +echo "[DONE]" + +# Execute the experiments +concurrency=(1 20 40 60 80 100) +echo "Running Experiments" +for conn in ${concurrency[*]}; do + printf "\t%d Concurrency: " "$conn" + hey -n 10000 -c "$conn" -cpus 2 -o csv -m GET http://localhost:10000 >"$results_directory/con$conn.csv" + echo "[DONE]" +done + +# Stop the runtime + +if [ "$1" != "-d" ]; then + sleep 5 + echo -n "Running Cleanup: " + pkill sledgert >/dev/null 2>/dev/null + pkill wrk >/dev/null 2>/dev/null + echo "[DONE]" +fi + +# Generate *.csv and *.dat results +echo -n "Parsing Results: " + +printf "Concurrency,Success_Rate\n" >>"$results_directory/success.csv" +printf "Concurrency,Throughput\n" >>"$results_directory/throughput.csv" +printf "Con,p50,p90,p99,p100\n" >>"$results_directory/latency.csv" + +for conn in ${concurrency[*]}; do + # Calculate Success Rate for csv + awk -F, ' + $7 == 200 {ok++} + END{printf "'"$conn"',%3.5f\n", (ok / (NR - 1) * 100)} + ' <"$results_directory/con$conn.csv" >>"$results_directory/success.csv" + + # Filter on 200s, convery from s to ms, and sort + awk -F, '$7 == 200 {print ($1 * 1000)}' <"$results_directory/con$conn.csv" | + sort -g >"$results_directory/con$conn-response.csv" + + # Get Number of 200s + oks=$(wc -l <"$results_directory/con$conn-response.csv") + + # Get Latest Timestamp + duration=$(tail -n1 "$results_directory/con$conn.csv" | cut -d, -f8) + throughput=$(echo "$oks/$duration" | bc) + printf "%d,%f\n" "$conn" "$throughput" >>"$results_directory/throughput.csv" + + # Generate Latency Data for csv + awk ' + BEGIN { + sum = 0 + p50 = int('"$oks"' * 0.5) + p90 = int('"$oks"' * 0.9) + p99 = int('"$oks"' * 0.99) + p100 = '"$oks"' + printf "'"$conn"'," + } + NR==p50 {printf "%1.4f,", $0} + NR==p90 {printf "%1.4f,", $0} + NR==p99 {printf "%1.4f,", $0} + NR==p100 {printf "%1.4f\n", $0} + ' <"$results_directory/con$conn-response.csv" >>"$results_directory/latency.csv" + + # Delete scratch file used for sorting/counting + rm -rf "$results_directory/con$conn-response.csv" +done + +# Transform csvs to dat files for gnuplot +for file in success latency throughput; do + echo -n "#" >"$results_directory/$file.dat" + tr ',' ' ' <"$results_directory/$file.csv" | column -t >>"$results_directory/$file.dat" +done + +# Generate gnuplots +cd "$results_directory" || exit +gnuplot ../../latency.gnuplot +gnuplot ../../success.gnuplot +gnuplot ../../throughput.gnuplot +cd "$experiment_directory" || exit + +# Cleanup, if requires +echo "[DONE]" diff --git a/runtime/experiments/concurrency/spec.json b/runtime/experiments/concurrency/spec.json new file mode 100644 index 0000000..b2b4a20 --- /dev/null +++ b/runtime/experiments/concurrency/spec.json @@ -0,0 +1,14 @@ +{ + "active": "yes", + "name": "empty", + "path": "empty_wasm.so", + "port": 10000, + "relative-deadline-us": 50000, + "argsize": 1, + "http-req-headers": [], + "http-req-content-type": "text/plain", + "http-req-size": 1024, + "http-resp-headers": [], + "http-resp-size": 1024, + "http-resp-content-type": "text/plain" +} \ No newline at end of file diff --git a/runtime/experiments/concurrency/success.gnuplot b/runtime/experiments/concurrency/success.gnuplot new file mode 100644 index 0000000..02be39e --- /dev/null +++ b/runtime/experiments/concurrency/success.gnuplot @@ -0,0 +1,12 @@ +reset + +set term jpeg +set output "success.jpg" + +set xlabel "Concurrency" +set ylabel "% 2XX" + +set xrange [-5:105] +set yrange [0:110] + +plot 'success.dat' using 1:2 title '2XX' diff --git a/runtime/experiments/concurrency/throughput.gnuplot b/runtime/experiments/concurrency/throughput.gnuplot new file mode 100644 index 0000000..3a5ca11 --- /dev/null +++ b/runtime/experiments/concurrency/throughput.gnuplot @@ -0,0 +1,12 @@ +reset + +set term jpeg +set output "throughput.jpg" + +set xlabel "Concurrency" +set ylabel "Requests/sec" + +set xrange [-5:105] +set yrange [0:] + +plot 'throughput.dat' using 1:2 title 'Reqs/sec' diff --git a/runtime/tests/raw_utilization/debug.sh b/runtime/tests/raw_utilization/debug.sh deleted file mode 100755 index 5541f0c..0000000 --- a/runtime/tests/raw_utilization/debug.sh +++ /dev/null @@ -1,19 +0,0 @@ -#!/bin/bash -# Executes the runtime in GDB -# Substitutes the absolute path from the container with a path relatively derived from the location of this script -# This allows debugging outside of the Docker container -# Also disables pagination and stopping on SIGUSR1 - -declare project_path="$( - cd "$(dirname "$1")/../.." - pwd -)" -echo $project_path -cd ../../bin -export LD_LIBRARY_PATH="$(pwd):$LD_LIBRARY_PATH" -gdb --eval-command="handle SIGUSR1 nostop" \ - --eval-command="set pagination off" \ - --eval-command="set substitute-path /sledge/runtime $project_path" \ - --eval-command="run ../tests/raw_utilization/test_mixed_preemption.json" \ - ./sledgert -cd ../../tests diff --git a/runtime/tests/raw_utilization/demo.sh b/runtime/tests/raw_utilization/demo.sh deleted file mode 100755 index a1efbfc..0000000 --- a/runtime/tests/raw_utilization/demo.sh +++ /dev/null @@ -1,39 +0,0 @@ -#!/bin/bash -# cd ../../bin -# LD_LIBRARY_PATH="$(pwd):$LD_LIBRARY_PATH" ./sledgert ../tests/mixed_preemption/test_mixed_preemption.json & -# cd ../tests/mixed_preemption/ - -# Run small samples on each port to let the runtime figure out the execution time -sleep 10 -echo "Running Samples" -wrk -d 1m -t 1 -s post.lua http://localhost:10025 -- --delay 0 25\n - -# Run in Serial, increasing number of open connections -sleep 10 -echo "Running Experiments" -wrk --duration 1m --threads 1 --connections 10 --timeout 10m --script post.lua http://localhost:10025 -- --delay 0 25\n >./res/con10.txt -wrk --duration 1m --threads 1 --connections 15 --timeout 10m --script post.lua http://localhost:10025 -- --delay 0 25\n >./res/con15.txt -wrk --duration 1m --threads 1 --connections 20 --timeout 10m --script post.lua http://localhost:10025 -- --delay 0 25\n >./res/con20.txt -wrk --duration 1m --threads 1 --connections 25 --timeout 10m --script post.lua http://localhost:10025 -- --delay 0 25\n >./res/con25.txt - -# Kill the Background Sledge processes -sleep 10 -echo "Running Cleanup" -pkill sledgert -pkill wrk - -# Extract the Latency CSV Data from the Log - -echo 'con10, con10' >./res/con10.csv -grep -A200 -m1 -e 'Percentile, Latency' ./res/con10.txt >>./res/con10.csv - -echo 'con15, con15' >./res/con15.csv -grep -A200 -m1 -e 'Percentile, Latency' ./res/con15.txt >>./res/con15.csv - -echo 'con20, con20' >./res/con20.csv -grep -A200 -m1 -e 'Percentile, Latency' ./res/con20.txt >>./res/con20.csv - -echo 'con25, con25' >./res/con25.csv -grep -A200 -m1 -e 'Percentile, Latency' ./res/con25.txt >>./res/con25.csv - -paste -d, ./res/con10.csv ./res/con15.csv ./res/con20.csv ./res/con25.csv >./res/merged.csv diff --git a/runtime/tests/raw_utilization/post.lua b/runtime/tests/raw_utilization/post.lua deleted file mode 100644 index 84d7779..0000000 --- a/runtime/tests/raw_utilization/post.lua +++ /dev/null @@ -1,58 +0,0 @@ --- Default to 1 request / second -wrk.method = "POST" -wrk.body = "10\n" -wrk.headers["Content-Type"] = "text/plain" -local delay_val = 1000 - -function init(args) - if #args == 0 then - io.write("[wrk stuff] -- --delay [delay in ms] [args ...]\n") - os.exit(); - end - - local current_arg = 1 - while current_arg <= #args do - if args[current_arg] == "--delay" then - delay_val = args[current_arg + 1] - current_arg = current_arg + 2; - io.write(string.format("Delay: %s\n", delay_val)) - else - -- Concatenate all remaining args - local buffer = "" - for i = current_arg, #args, 1 do - buffer = buffer .. args[i] - end - io.write(string.format("Buffer: %s\n", buffer)) - wrk.body = buffer - -- And exit loop - break; - end - end -end - --- Uncomment to dynamically generate a different request each time --- function request() --- return wrk.format(nil, nil, nil,tostring(math.random(10, 23)) .."\n") --- end - --- Wrk calls a function name delay to get the delay between requests (in ms) -function delay() - return delay_val -end - -function response(status, headers, body) - -- io.write(string.format("%s: %s\n", status, body)) -end - --- Done Phase - --- Called when complete, presenting aggregate results -function done(summary, latency, requests) - io.write("Percentile, Latency\n"); - for i = 1, 99 do - io.write(string.format("%d, %d\n", i, latency:percentile(i))) - end -end - - - diff --git a/runtime/tests/raw_utilization/test_mixed_preemption.json b/runtime/tests/raw_utilization/test_mixed_preemption.json deleted file mode 100644 index cbd3b0c..0000000 --- a/runtime/tests/raw_utilization/test_mixed_preemption.json +++ /dev/null @@ -1,70 +0,0 @@ -{ - "active": "yes", - "name": "fibonacci_10", - "path": "fibonacci_wasm.so", - "port": 10010, - "relative-deadline-us": 4000, - "argsize": 1, - "http-req-headers": [], - "http-req-content-type": "text/plain", - "http-req-size": 1024, - "http-resp-headers": [], - "http-resp-size": 1024, - "http-resp-content-type": "text/plain" -}, -{ - "active": "yes", - "name": "fibonacci_20", - "path": "fibonacci_wasm.so", - "port": 10020, - "relative-deadline-us": 5000, - "argsize": 1, - "http-req-headers": [], - "http-req-content-type": "text/plain", - "http-req-size": 1024, - "http-resp-headers": [], - "http-resp-size": 1024, - "http-resp-content-type": "text/plain" -}, -{ - "active": "yes", - "name": "fibonacci_25", - "path": "fibonacci_wasm.so", - "port": 10025, - "relative-deadline-us": 6000, - "argsize": 1, - "http-req-headers": [], - "http-req-content-type": "text/plain", - "http-req-size": 1024, - "http-resp-headers": [], - "http-resp-size": 1024, - "http-resp-content-type": "text/plain" -}, -{ - "active": "yes", - "name": "fibonacci_30", - "path": "fibonacci_wasm.so", - "port": 10030, - "relative-deadline-us": 8000, - "argsize": 1, - "http-req-headers": [], - "http-req-content-type": "text/plain", - "http-req-size": 1024, - "http-resp-headers": [], - "http-resp-size": 1024, - "http-resp-content-type": "text/plain" -}, -{ - "active": "yes", - "name": "fibonacci_35", - "path": "fibonacci_wasm.so", - "port": 10035, - "relative-deadline-us": 53000, - "argsize": 1, - "http-req-headers": [], - "http-req-content-type": "text/plain", - "http-req-size": 1024, - "http-resp-headers": [], - "http-resp-size": 1024, - "http-resp-content-type": "text/plain" -}