nancy prepare-workload: the 1st working version + a test

Author: NikolayS

.circleci/sample.log

@@ -0,0 +1,15 @@
+2018-07-12 22:47:06.085 UTC,"testci","testci",2460,"127.0.0.1:53862",5b47da68.99c,6,"idle",2018-07-12 22:47:04 UTC,,0,LOG,00000,"disconnection: session time: 0:00:01.185 user=testci database=testci host=127.0.0.1 port=53862",,,,,,,,,""
+2018-07-12 22:47:06.302 UTC,,,2473,"127.0.0.1:53865",5b47da6a.9a9,1,"",2018-07-12 22:47:06 UTC,,0,LOG,00000,"connection received: host=127.0.0.1 port=53865",,,,,,,,,""
+2018-07-12 22:47:07.394 UTC,"testci","testci",28569,"127.0.0.1:53615",5b47d84e.6f99,15,"idle",2018-07-12 22:38:06 UTC,,0,LOG,00000,"disconnection: session time: 0:09:00.762 user=testci database=testci host=127.0.0.1 port=53615",,,,,,,,,""
+2018-07-12 22:47:07.838 UTC,"testci","testci",2473,"127.0.0.1:53865",5b47da6a.9a9,4,"SELECT",2018-07-12 22:47:06 UTC,12/0,0,LOG,00000,"duration: 14.564 ms  statement: select count(*)
+    from ""hello_world"" as t
+    order by t.id desc limit 26",,,,,,,,,""
+2018-07-12 22:47:08.053 UTC,"testci","testci",2473,"127.0.0.1:53865",5b47da6a.9a9,5,"SELECT",2018-07-12 22:47:06 UTC,12/0,0,LOG,00000,"duration: 43.544 ms  statement: SELECT * FROM ""hello_world"" ""t"" WHERE i > 0  ORDER BY random()",,,,,,,,,""
+2018-07-12 22:47:08.547 UTC,"testci","testci",2473,"127.0.0.1:53865",5b47da6a.9a9,6,"idle",2018-07-12 22:47:06 UTC,,0,LOG,00000,"disconnection: session time: 0:00:02.245 user=testci database=testci host=127.0.0.1 port=53865",,,,,,,,,""
+2018-07-12 22:47:19.218 UTC,,,2642,"127.0.0.1:54013",5b47da77.a52,1,"",2018-07-12 22:47:19 UTC,,0,LOG,00000,"connection received: host=127.0.0.1 port=54013",,,,,,,,,""
+2018-07-12 22:47:19.218 UTC,,,2643,"127.0.0.1:54014",5b47da77.a53,1,"",2018-07-12 22:47:19 UTC,,0,LOG,00000,"connection received: host=127.0.0.1 port=54014",,,,,,,,,""
+2018-07-12 22:47:19.218 UTC,,,2644,"127.0.0.1:54015",5b47da77.a54,1,"",2018-07-12 22:47:19 UTC,,0,LOG,00000,"connection received: host=127.0.0.1 port=54015",,,,,,,,,""
+2018-07-12 22:47:19.226 UTC,"testci","testci",2644,"127.0.0.1:54015",5b47da77.a54,2,"authentication",2018-07-12 22:47:19 UTC,11/77223,0,LOG,00000,"connection authorized: user=testci database=testci SSL enabled (protocol=TLSv1.2, cipher=ECDHE-RSA-AES256-GCM-SHA384, compression=off)",,,,,,,,,""
+2018-07-12 22:47:19.227 UTC,"testci","testci",2642,"127.0.0.1:54013",5b47da77.a52,2,"authentication",2018-07-12 22:47:19 UTC,12/323914,0,LOG,00000,"connection authorized: user=testci database=testci SSL enabled (protocol=TLSv1.2, cipher=ECDHE-RSA-AES256-GCM-SHA384, compression=off)",,,,,,,,,""
+2018-07-12 22:47:19.227 UTC,"testci","testci",2643,"127.0.0.1:54014",5b47da77.a53,2,"authentication",2018-07-12 22:47:19 UTC,13/6385,0,LOG,00000,"connection authorized: user=testci database=testci SSL enabled (protocol=TLSv1.2, cipher=ECDHE-RSA-AES256-GCM-SHA384, compression=off)",,,,,,,,,""
+2018-07-12 22:47:25.491 UTC,"testci","testci",2687,"127.0.0.1:54016",5b47da7a.a7f,3,"idle",2018-07-12 22:47:22 UTC,,0,LOG,00000,"disconnection: session time: 0:00:02.680 user=testci database=testci host=127.0.0.1 port=54016",,,,,,,,,""

nancy

@@ -59,4 +59,3 @@ done
 [ "$DEBUG" -eq "1" ] &&  echo "CMD: $cmd"
 
 eval $cmd
-

nancy_prepare_workload.sh

@@ -26,6 +26,8 @@ while true; do
     -d | --debug ) DEBUG=1; shift ;;
     --db-name )
       DB_NAME="$2"; shift 2 ;;
+    --output )
+      OUTPUT="$2"; shift 2 ;;
     -- )
       >&2 echo "ERROR: Invalid option '$1'"
       exit 1
@@ -47,3 +49,37 @@ if [ $DEBUG -eq 1 ]; then
   echo "output: ${OUTPUT}"
   echo "db_name: ${DB_NAME}"
 fi
+
+if [ -z ${INPUT+x} ]; then
+  >&2 echo "ERROR: the input (path to Postgres log file) is not specified."
+  exit 1;
+fi
+
+if [ -z ${OUTPUT+x} ]; then
+  >&2 echo "ERROR: the output path is not specified."
+  exit 1;
+fi
+
+cat $INPUT \
+  | sed -r 's/^([0-9]{4}-[0-9]{2}-[0-9]{2} [0-9]{2}:[0-9]{2}:[0-9]{2}\.[0-9]{3} .*)$/\nNANCY_NEW_LINE_SEPARATOR\n\1/' \
+  | sed "s/\"\"/NANCY_TWO_DOUBLE_QUOTES_SEPARATOR/g" \
+  | awk -v dbname="\"$DB_NAME\"" '
+BEGIN {
+  RS="\nNANCY_NEW_LINE_SEPARATOR\n";
+  FPAT = "([^,]+)|(\"[^\"]+\")"
+  OFS=","
+}
+{
+  if ($3 == dbname && substr($14, 0, 11) == "\"duration: ") {
+    duration_ms = substr($14, 0, 30)
+    if (match($14, /^"duration: ([^ ]+) ms  statement: (.*)$/, match_arr)) {
+      duration = match_arr[1] * 1000
+      statement = "\"statement: " match_arr[2]
+    }
+    "date -u -d @$(echo \"scale=6; ($(date -u --date=\"" $1 "\" +'%s%6N') - " duration \
+      ") / 1000000\" | bc) +\"%Y-%m-%d %H:%M:%S.%6N%:::z\" | tr -d \"\\n\"" | getline res_ts
+    print res_ts,"\"postgres\"","\"test\"",$4,$5,$6,$7,$8,$9,$10,$11,$12,$13,statement ",,,,,,,,"
+  }
+}' \
+  | sed "s/NANCY_TWO_DOUBLE_QUOTES_SEPARATOR/\"\"/g" \
+  | pgreplay -f -c -o "$OUTPUT"

tests/nancy_prepare_workload.sh

@@ -0,0 +1,18 @@
+#!/bin/bash
+
+export PATH=$PATH:${BASH_SOURCE%/*}/..
+
+output=$( \
+  nancy prepare-workload --db-name testci \
+    --output ./test.replay ./.circleci/sample.log \
+    2>&1
+)
+
+if [[ $output =~ "Total SQL statements processed: 2" ]]; then
+  echo -e "\e[36mOK\e[39m"
+else
+  >&2 echo -e "\e[31mFAILED\e[39m"
+  >&2 echo -e "Output: $output"
+  exit 1
+fi
+