improve logging and minor updates

Author: molly-moen

cicd/3-app/load-test.template.yml

@@ -37,9 +37,9 @@ Resources:
               awslogs-group:  !Ref CloudwatchLogsGroup
               awslogs-region: !Ref AWS::Region
               awslogs-stream-prefix:  !Sub "${AWS::StackName}-task"
-      Cpu: 1024
+      Cpu: 2048
       ExecutionRoleArn: !Ref ExecutionRole
-      Memory: 2048
+      Memory: 4096
       NetworkMode: awsvpc
       RuntimePlatform: 
         OperatingSystemFamily: LINUX

load-test/Dockerfile

@@ -4,4 +4,4 @@ COPY ./scripts /scripts
 WORKDIR /scripts
 # Override the entry point of the base k6 image
 ENTRYPOINT []
-CMD ["sh", "-c", "k6 run $SCRIPT"]
+CMD ["sh", "-c", "k6 run $SCRIPT --quiet"]

load-test/scripts/configuration.js

@@ -34,9 +34,6 @@ export const MiniAppType = {
 
 export function getTestOptions(maxUserGoal, rampUpTimeMinutes, highLoadTimeMinutes) {
   const maxConcurrentUsers =  Math.floor(maxUserGoal / 30);
-  // set constant VUs to be slightly higher than max concurrent users to account for users taking slightly different
-  // amounts of time
-  const constantVUs =  Math.floor(maxUserGoal / 25);
   return  {
     scenarios: {
       // ramp up to maxConcurrentUsers VUs over rampUpTimeMinutes
@@ -47,24 +44,26 @@ export function getTestOptions(maxUserGoal, rampUpTimeMinutes, highLoadTimeMinut
           {duration: `${rampUpTimeMinutes}m`, target: maxConcurrentUsers}
         ]
       },
-      // have constantVUs VUs do 3 iterations each minute, for a total of highLoadTimeMinutes * 3
+      // have maxConcurrentUsers VUs do 3 iterations each minute, for a total of highLoadTimeMinutes * 3
       // iterations per virutal user.
-      // Start this after the ramp up time and allow for 1 extra minute in the max duration in case of issues.
+      // Start this after the ramp up time.
       highLoad: {
         executor: "per-vu-iterations",
-        vus: constantVUs,
+        vus: maxConcurrentUsers,
         iterations: 3 * highLoadTimeMinutes, // this is iterations per virtual user
         // add a large buffer to max duration to ensure all requests can complete.
-        maxDuration: `${highLoadTimeMinutes + (Math.floor(highLoadTimeMinutes * 0.5))}m`,
+        maxDuration: `${highLoadTimeMinutes + (Math.ceil(highLoadTimeMinutes * 0.5))}m`,
         startTime: `${rampUpTimeMinutes}m`,
       }
     },
     thresholds: {
       exceptions: ["count == 0"],
       errors: ["count == 0"],
-      websocket_session_duration_without_sleep: ["p(95) < 5000"],
+      timeouts: ["count == 0"],
+      total_request_time: ["p(95) < 5000"],
       long_websocket_sessions: [`count <= ${maxConcurrentUsers}`],
-      extra_long_websocket_sessions: ["count == 0"]
+      extra_long_websocket_sessions: ["count == 0"],
+      dropped_iterations: ["count == 0"]
     },
     summaryTrendStats: ["avg", "min", "med", "max", "p(90)", "p(95)", "p(98)", "p(99)"],
   };

load-test/scripts/loadTest.js

@@ -3,6 +3,7 @@ import http from "k6/http";
 import { check, sleep } from "k6";
 import { Counter, Trend } from "k6/metrics";
 import { helloWorld } from "./sources.js";
+import { getRandomId, generateToken } from "./tokenHelpers.js";
 import {
   LONG_REQUEST_MS,
   EXTRA_LONG_REQUEST_MS,
@@ -13,24 +14,24 @@ import {
   WEBSOCKET_PARAMS,
   getTestOptions
 } from "./configuration.js";
-import generateToken from "./generateToken.js";
 
 // Change these options to increase the user goal or time to run the test.
 export const options = getTestOptions(
-  /* User goal */ 100,
-  /* Ramp up time minutes */ 1,
-  /* High load time minutes */ 1
+  /* User goal */ 1000,
+  /* Ramp up time minutes */ 5,
+  /* High load time minutes */ 10
 );
 
 // Change this to test different code
 const sourceToTest = helloWorld;
+// Timeout is we go greater than the max request time to ensure we stay
+// close to our concurrent user goal.
+const MAX_REQUEST_TIME_MS = 20000;
 
 const exceptionCounter = new Counter("exceptions");
 const errorCounter = new Counter("errors");
-const connectToCloseTime = new Trend(
-  "websocket_session_duration_without_sleep",
-  true
-);
+const timeoutCounter = new Counter("timeouts");
+const totalRequestTime = new Trend("total_request_time", true);
 // websocket sessions > LONG_REQUEST_MS
 const longWebsocketSessions = new Counter("long_websocket_sessions");
 // websocket sessions > EXTRA_LONG_REQUEST_MS
@@ -42,7 +43,9 @@ function isResultSuccess(result) {
 }
 
 export default function () {
-  const authToken = generateToken(MiniAppType.CONSOLE);
+  const requestStartTime = Date.now();
+  const sessionId = getRandomId();
+  const authToken = generateToken(MiniAppType.CONSOLE, sessionId);
   const uploadResult = http.put(
     UPLOAD_URL + authToken,
     sourceToTest,
@@ -53,41 +56,57 @@ export default function () {
 
   if (isResultSuccess(uploadResult)) {
     const res = ws.connect(WEBSOCKET_URL + authToken, WEBSOCKET_PARAMS, (socket) =>
-      onSocketConnect(socket, Date.now())
+      onSocketConnect(socket, requestStartTime, Date.now(), sessionId)
     );
 
     check(res, { "websocket status is 101": (r) => r && r.status === 101 });
+  } else {
+    console.log(`ERROR upload failed for session id ${sessionId}`);
   }
 }
 
-function onSocketConnect(socket, startTime) {
-  socket.on("open", () => {});
+function onSocketConnect(socket, requestStartTime, websocketStartTime, sessionId) {
+  socket.on("open", () => {
+    socket.setTimeout(() => {
+      console.log(`Triggering TIMEOUT for session id ${sessionId}, request has gone longer than ${MAX_REQUEST_TIME_MS} ms.`);
+      socket.close();
+    }, MAX_REQUEST_TIME_MS);
+  });
 
   socket.on("message", function (data) {
     const parsedData = JSON.parse(data);
     if (parsedData.type === "EXCEPTION") {
-      console.log("[EXCEPTION] " + parsedData.value);
+      console.log(`EXCEPTION for session id ${sessionId} ` + parsedData.value);
       exceptionCounter.add(1);
     }
   });
 
   socket.on("close", () => {
-    const time = Date.now() - startTime;
-    connectToCloseTime.add(time);
-    if (time > LONG_REQUEST_MS) {
-      longWebsocketSessions.add(1);
-    }
-    if (time > EXTRA_LONG_REQUEST_MS) {
-      extraLongWebsocketSessions.add(1);
+    const websocketTime = Date.now() - websocketStartTime;
+    const totalTime = Date.now() - requestStartTime;
+    if (websocketTime < MAX_REQUEST_TIME_MS) {
+      // only log requests that didn't time out, as timeouts are a separate metric.
+      totalRequestTime.add(totalTime);
+      if (totalTime > EXTRA_LONG_REQUEST_MS) {
+        console.log(`EXTRA LONG REQUEST Session id ${sessionId} had a request time of ${totalTime} ms.`);
+        extraLongWebsocketSessions.add(1);
+      } else if (totalTime > LONG_REQUEST_MS) {
+        console.log(`LONG REQUEST Session id ${sessionId} had a request time of ${totalTime} ms.`);
+        longWebsocketSessions.add(1);
+      }
+    } else {
+      console.log(`TIMEOUT detected for session id ${sessionId}`);
+      timeoutCounter.add(1);
     }
-    const sleepTime = Math.floor(20 - (time / 1000));
+    
+    const sleepTime = Math.floor((MAX_REQUEST_TIME_MS - totalTime) / 1000);
     if (sleepTime > 0) {
       sleep(sleepTime);
     }
   });
 
   socket.on("error", function (e) {
-    console.log("[ERROR] " + e.error());
+    console.log(`ERROR on websocket request for session id ${sessionId} ` + e.error());
     errorCounter.add(1);
   });
 }

load-test/scripts/generateToken.js load-test/scripts/tokenHelpers.jsload-test/scripts/generateToken.js renamed to load-test/scripts/tokenHelpers.js

@@ -7,24 +7,28 @@ import { PRIVATE_KEY } from "./configuration.js";
 
 // Generate a JWT token for the given mini app type, with random
 // user id, teacher id and session id. The token has a time to live of 1 minute.
-export default function generateToken(miniAppType) {
+export function generateToken(miniAppType, sessionId) {
   const issuedAtTime = (Date.now() / 1000) - 3;
   const expirationTime = issuedAtTime + 63;
   const payload = {
     iat: issuedAtTime,
     iss: "load-test",
     exp: expirationTime,
-    uid: uuidv4(),
+    uid: getRandomId(),
     level_id: "none",
     execution_type: "RUN",
     mini_app_type: miniAppType,
-    verified_teachers: uuidv4(),
+    verified_teachers: getRandomId(),
     options: "{}",
-    sid: uuidv4()
+    sid: sessionId
   };
   return encodeAsJWT(payload);
 }
 
+export function getRandomId() {
+  return uuidv4();
+}
+
 // Generate a JWT using the HS256 algorithm, which relies on a shared secret
 // between the sender and receiver. 
 // To keep the load test script small we can't use npm packages that do this for us,