Using requests in combination with websockets

Grafana k6 OSS Support
1

Hello,

I am trying to load test my socket server by starting a conversation and sending messages to that conversation. To start a conversation I first have to call an API endpoint, then connect to the websocket and subscribe to the channel, call another endpoint and finally start to converse. But unfortunately my socket.on("message") is not firing and I cannot see why. Is there any one who could help me out? This is my script:

import http from 'k6/http';
import { check, group, sleep, fail } from 'k6';
import { Rate } from 'k6/metrics';
import ws from "k6/ws";

export let errorRate = new Rate('errors');
export let options = {
  stages: [
    { target: 1, duration: '15s' },
  ],
  thresholds: { http_req_duration: ["max<5000"] },
  ext: {
    loadimpact: {
      distribution: {
        "amazon:de:frankfurt": { loadZone: "amazon:de:frankfurt", percent: 100 }
      }
    }
  }
};

function uuid() {
  var dt = new Date().getTime();
  var uuid = 'xxxxxxxx-xxxx-4xxx-yxxx-xxxxxxxxxxxx'.replace(/[xy]/g, function (c) {
    var r = (dt + Math.random() * 16) % 16 | 0;
    dt = Math.floor(dt / 16);
    return (c == 'x' ? r : (r & 0x3 | 0x8)).toString(16);
  });
  return uuid;
}

const ENV = "stage"
const WEBCHAT_TOKEN = "WEBCHAT_TOKEN";

const BASE_URL_LEGACY_BACKEND = `https://backend-${ENV}.appspot.com`;
const SOCKET_URL = `ws://api2-${ENV}.co/socket_server/v1/connection`;

const fillCustomField = (conversationId, callerId) => {
  const conversationIncoming = http.post(
    `${BASE_URL_LEGACY_BACKEND}/webchat/conversation/incoming`,
    {
      "webchat_token": WEBCHAT_TOKEN,
      "message": "k6io loadtest " + (new Date().toString()),
      "tree": true,
      "conversation_id": conversationId,
      "caller_id": callerId,
      "identifier": uuid()
    }
  );

  check(
    conversationIncoming,
    {
      'conversation incoming succeed': (r) => r.status === 201,
    }
  ) || errorRate.add(1);
};

const forwardToEmployee = (conversationId, callerId) => {
  const quickreplyIncoming = http.post(
    `${BASE_URL_LEGACY_BACKEND}/webchat/quickreply/incoming`,
    {
      "webchat_token": WEBCHAT_TOKEN,
      "name": "Stuur mij door",
      "index": 4,
      "conversation_id": conversationId,
      "caller_id": callerId,
    }
  );

  console.log('quickreplyIncoming.body');
  console.log(quickreplyIncoming.body);

  check(
    quickreplyIncoming,
    {
      'quickreply incoming succeed': (r) => r.status === 201,
    }
  ) || errorRate.add(1);
};

const talkWithEmployee = (conversationId, callerId) => {
  const messageIncoming = http.post(
    `${BASE_URL_LEGACY_BACKEND}/webchat/message/incoming`,
    {
      "webchat_token": WEBCHAT_TOKEN,
      "text": "Hello from k6.io loadtest " + (new Date().toString()),
      "type": "text",
      "conversation_id": conversationId,
      "caller_id": callerId,
      "identifier": uuid()
    }
  );

  console.log('messageIncoming.body');
  console.log(messageIncoming.body);

  check(
    messageIncoming,
    {
      'message incoming succeed': (r) => r.status === 201,
    }
  ) || errorRate.add(1);
};

let conversationId, callerId, webchatSocketChannel;

const webchatStart = () => {
  const webchatStart = http.get(
    `${BASE_URL_LEGACY_BACKEND}/webchat/start/${WEBCHAT_TOKEN}?conversation_id=null`
  );

  check(
    webchatStart,
    {
      'webchat start successful': (r) => r.status === 201,
      'got conversation id': (r) => r.json('conversation').hasOwnProperty('id'),
      'got caller id': (r) => r.json('conversation').hasOwnProperty('caller_id'),
      'got webchat socket channel': (r) => r.json('conversation').hasOwnProperty('webchat_socket_channel')
    }
  ) || errorRate.add(1);

  conversationId = webchatStart.json('conversation')['id'];
  callerId = webchatStart.json('conversation')['caller_id'];
  webchatSocketChannel = webchatStart.json('conversation')['webchat_socket_channel'];
};

const webchatStartConversation = () => {
  const webchatStartConversation = http.get(
    `${BASE_URL_LEGACY_BACKEND}/webchat/start/conversation/${conversationId}`
  );

  check(
    webchatStartConversation,
    {
      'webchat start conversation successful': (r) => r.status === 201
    }
  ) || errorRate.add(1);
};

export default function (data) {
  webchatStart();
  
  let index = 0;

  const response = ws.connect(SOCKET_URL, null, function (socket) {
    socket.on("open", function open() {
      console.log("connected to websocket");
      
      socket.send(JSON.stringify({
        type: 'subscribe',
        channel: `webchat.${webchatSocketChannel}`
      }));

      console.log("subscribed");
      
      console.log(JSON.stringify({
        type: 'subscribe',
        channel: `webchat.${webchatSocketChannel}`
      }));

      webchatStartConversation();

      console.log("webchatStartConversation");

    });

    socket.on("message", (event) => {
      console.log(event);

      const webSocketData = JSON.parse(event.data);
      let eventType = webSocketData.name;

      if (!eventType) {
        eventType = webSocketData.event;
      }

      if (eventType == 'chat:quickreply:options') {
        if (index == 0) {
          fillCustomField(conversationId, callerId);
          index++;
        }

        if (index == 1) {
          forwardToEmployee(conversationId, callerId);
          index++;
        }

        if (index == 2) {
          talkWithEmployee(conversationId, callerId);

          socket.close();
        }
      }

    });

    socket.on("close", () => console.log("disconnected from websocket"));

    socket.on("error", (e) => {
      if (e.error() != "websocket: close sent") {
        console.log("An unexpected error occured: ", e.error());
      }
    });
  });

  check(response, { "socket connection status is 101": r => r && r.status === 101 });

  sleep(1);
}

This is the output when executing my script via the CLI.
➜ ~ k6 run --out cloud script.js

          /\      |‾‾|  /‾‾/  /‾/
     /\  /  \     |  |_/  /  / /
    /  \/    \    |      |  /  ‾‾\
   /          \   |  |‾\  \ | (_) |
  / __________ \  |__|  \__\ \___/ .io

  execution: local
     output: cloud (https://app.k6.io/runs/724469)
     script: script.js

    duration: -,  iterations: -
         vus: 1, max: 1

INFO[0002] connected to websocket
INFO[0002] subscribed
INFO[0002] {"type":"subscribe","channel":"webchat.8LosuOhOgbKaDxbfrtBndha9gupezlnY54drBUE1tUta9r7Ow9WjXXScohy8"}
INFO[0002] webchatStartConversation
    done [==========================================================] 15s / 15s
WARN[0017] No data generated, because no script iterations finished, consider making the test duration longer

    ✓ webchat start successful
    ✓ got conversation id
    ✓ got caller id
    ✓ got webchat socket channel
    ✓ webchat start conversation successful

    checks.....................: 100.00% ✓ 5   ✗ 0
    http_req_blocked...........: avg=19.68ms  min=1µs      med=19.68ms  max=39.37ms  p(90)=35.43ms  p(95)=37.4ms
    http_req_connecting........: avg=4.83ms   min=0s       med=4.83ms   max=9.67ms   p(90)=8.7ms    p(95)=9.18ms
  ✓ http_req_duration..........: avg=277.81ms min=161.84ms med=277.81ms max=393.78ms p(90)=370.58ms p(95)=382.18ms
    http_req_receiving.........: avg=108.5µs  min=98µs     med=108.5µs  max=119µs    p(90)=116.9µs  p(95)=117.95µs
    http_req_sending...........: avg=332.49µs min=76µs     med=332.49µs max=589µs    p(90)=537.7µs  p(95)=563.35µs
    http_req_tls_handshaking...: avg=6.3ms    min=0s       med=6.3ms    max=12.61ms  p(90)=11.34ms  p(95)=11.98ms
    http_req_waiting...........: avg=277.37ms min=161.66ms med=277.37ms max=393.07ms p(90)=369.93ms p(95)=381.5ms
    http_reqs..................: 2       0.133333/s
    vus........................: 1       min=1 max=1
    vus_max....................: 1       min=1 max=1
1 Like
2

Hi, welcome to the forum :slight_smile:

It’s a bit difficult to troubleshoot your script as it relies on your infrastructure, but I tested with replacing BASE_URL_LEGACY_BACKEND = 'https://httpbin.test.k6.io/anything' and SOCKET_URL = 'ws://echo.websocket.org', and after commenting out a few things and minor tweaks, here’s the log output I see:

INFO[0002] connected to websocket
INFO[0002] subscribed
INFO[0002] {"type":"subscribe","channel":"webchat.undefined"}
INFO[0002] webchatStartConversation
INFO[0002] {"type":"subscribe","channel":"webchat.undefined"}  0="Received message"
    done [==========================================================] 15s / 15s
WARN[0016] No data generated, because no script iterations finished, consider making the test duration longer

Note the Received message event (console.log(event) on line 168 in your script), which means I received the echo reply from the server. Since this isn’t logged in your example run, it implies the server never sent the message.

So I would troubleshoot on the server side in this case, and use tcpdump/Wireshark to confirm the packet actually arrived.

If I then call socket.close() in the message handler, the connection is closed successfully and the iteration completes fine, so your script looks OK to me.

Hope this helps,

Ivan

1 Like