websocket check (wsAwait) not working, timing out even when messages are received

I am using Gatling version 2.2.4, I open a websocket and with debug logging, I see that I am getting data, but the websocket check always fails, timing out. Here is my code to open the websocket and create the check:

.exec(ws("_a_wsSession_survey_open")
.open("/a/wsSession/survey/${sessionId}/${participantId}?eid=${sessionId}&eType=session&prv=false&pid=${participantId}&hash=")
.check(wsAwait.within(40).until(1).regex("(.*)").saveAs(“wsresponse”))
)

And in my logs, I see the response:

09:15:58.699 [INFO ] i.g.h.a.a.w.WsOpen - Opening websocket ‘gatling.http.webSocket’: Scenario ‘SurveyTakingScenario’, UserId #2
09:15:58.771 [DEBUG] i.g.h.a.a.w.WsActor - Websocket ‘gatling.http.webSocket’ open
09:15:58.772 [DEBUG] i.g.h.a.a.w.WsActor - setCheck blocking=true timeout=40 seconds
09:15:58.883 [DEBUG] i.g.h.a.a.w.WsActor - Received text message on websocket ‘gatling.http.webSocket’:{“responseType”:“NEW_CONNECTION”,“payload”:{“session”:{“id”:“",“created”:“04/12/2017 - 11:48 AM”,“lastModified”:“04/12/2017 - 11:49 AM”,“startDate”:“04/12/2017 - 04:00 AM”,“startTimeInMillis”:1491969600000,“endDate”:“04/20/2017 - 03:59 AM”,“endTimeInMillis”:1492660740000,“tenantId”:null,“projectId”:"”,“userId”:null,“name”:“session 1”,“state”:“OPEN”,“referencedSurvey”:false,“surveyId”:“",“surveyName”:“Performance Test Survey w/ CR”,“newSurvey”:false,“tags”:[],“includedParticipants”:10,“surveySubmissions”:10,“surveyTerminations”:0,“responseRate”:100.0,“targetedURL”:true,“config”:{“blobStoreScopeId”:null,“metaDataCollectionId”:null,“participantCollectionIds”:["”]},“requireNickname”:true,“beforeStartTimeOffset”:0,“afterStartTimeOffset”:0,“beforeStartTimeOffsetFlag”:false,“afterStartTimeOffsetFlag”:false,“enableSessionLogin”:null,“agentSupport”:[“DESKTOP”,“TABLET”],“sessionMode”:“Open”,“targetParticipants”:0,“panelConfigs”:[{“panelId”:"",“terminateUrl”:"",“completedUrl”:"",“terminateParameters”:[],“completedParameters”:[]}],“favoriteParticipantIds”:[],“version”:“",“allowAnswerUpdate”:false,“loginState”:“Enabled”,“currentJoinerId”:null,“autoEnroll”:true,“autoTerminate”:false,“autoTerminatePercent”:null,“autoTerminateReason”:null,“deployConfig”:null},“survey”:{“id”:"”,“name”:“Performance Test Survey w/ CR”,“surveyState”:null,“tags”:null,“version”:“",“defaultJoinerId”:"”,“joiners”:[{“def”:null,“researchPrompt”:“q1”,“parentId”:null,“stim”:{“type”:“text”,“media”:null,“type”:“text”,“textLang”:null,“active”:true,“id”:“",“contents”:“q1”},“refStimId”:null,“timingOptions”:{“timingEnabled”:true,“defaultTime”:30,“configuredTime”:30},“id”:"”,“features”:[],“branchIds”:null,“displayIndex”:0,“displayLogic”:null,“branchingLogic”:null,“defaultNextJoinerId”:“",“displayTimeInSecs”:30,“container”:false,“group”:null,“groupName”:null,“active”:true,“hidden”:false,“termOptions”:null,“displayLayout”:null,“restartMedia”:false,“orphaned”:false,“conceptId”:null,“conceptRotationId”:null,“conceptRotation”:null,“stimOnly”:true,“thirdPartyStim”:false}],“parentId”:null,“userId”:"”,“supportedLanguages”:null,“participantId”:null,“surveyOptions”:null,“groupNames”:null,“createDate”:“04-12-2017 11:48:49”,“modifiedDate”:“04-12-2017 11:48:49”},“error”:null,“previewMode”:false,“requireNickname”:true,“entryPoint”:“ONGOING”},“error”:null}
09:16:28.878 [DEBUG] i.g.h.a.a.w.WsActor - Received text message on websocket ‘gatling.http.webSocket’:X
09:16:38.787 [DEBUG] i.g.h.a.a.w.WsActor - Check on WebSocket ‘gatling.http.webSocket’ timed out

I was first trying to use the jsonPath check, but when that wasn’t working, I figured I would just capture everything with regex, but this isn’t working, either.

At this point, I’m not sure how to debug this further

Charles,
I am experiencing the same issue. Were you able to resolve your issue and get the check to work?

Thanks,
Vincent Tanakas

Yes, I ended up using jsonPath check instead of regex:

.check(wsAwait.within(600).until(1).jsonPath("$…*").exists.saveAs(“wsResponse”)))

Thanks Charles,

I was using a JSONPath extraction as well, but I modified my code to match with yours, the only real change was the duration of the timeout.

.exec(Notification.openWebsocket)
//.exec(ws(“Open Check”).check(wsListen.within(10).until(1).jsonPath("$").saveAs(“openResponse”)))
.exec(ws(“Open Check”).check(wsAwait.within(600).until(1).jsonPath("$…*").exists.saveAs(“wsResponse”)))

Upon digging into my logs I found the following,

12:59:58.955 [DEBUG] i.g.h.a.a.w.WsActor - Websocket ‘gatling.http.webSocket’ open
12:59:58.955 [DEBUG] i.n.h.c.h.w.WebSocket08FrameDecoder - Decoding WebSocket Frame opCode=1
12:59:58.955 [DEBUG] i.n.h.c.h.w.WebSocket08FrameDecoder - Decoding WebSocket Frame length=45
12:59:58.959 [DEBUG] i.g.h.a.a.w.WsActor - Received text message on websocket ‘gatling.http.webSocket’:{“type”:“active-subscriptions”,“channels”:[]}
12:59:58.960 [DEBUG] i.g.h.a.a.w.WsActor - Setting check on WebSocket 'gatling.http.webSocket’
12:59:58.960 [DEBUG] i.g.h.a.a.w.WsActor - setCheck blocking=true timeout=600 seconds

On Line 1: The socket is reported as open.
On Lines 2-4: The socket receives its first message from the server.
On Lines 5-6: The socket sets up the check

The fact that the check is setup after the message is received is what is causing my problem. Perhaps under load, there is enough of a delay introduced where the check is created before the message is received. But that’s completely unrealiable. Do you recall if you experienced the same out of order operations?

Thanks,
VT