[Need Help] Strange behavior of WebSocket checks

[nobody]

Hi,

I’m testing a websocket service, the scenario should be:

• Each client keeps the connection open and sends 1 message with a random unique sequence number every 10 seconds.
• Server returns the seq in response body.
• Client should only accept the message with the same seq.

I also want to print the seq for failed requests.
Here’s my code:

public class WebsocketTest extends Simulation {
    private static final Logger log = LoggerFactory.getLogger(WebsocketTest.class);

    // ...

    HttpProtocolBuilder httpConf = http
        .wsBaseUrl(baseUrl)
        .wsAutoReplySocketIo4();

    ScenarioBuilder scn = scenario("WebSocket")
        .exec(ws("Connect WS").connect(path))
        .exitHereIfFailed()
        .repeat(loop).on(
            pause(sendIntervalMin, sendIntervalMax)
                .exec(session -> {
                    session.markAsSucceeded();
                    String nanoTime = String.valueOf(System.nanoTime());
                    return session.set("seq", System.currentTimeMillis() + nanoTime.substring(nanoTime.length() - 5));
                })
                .exec(ws("Send text")
                    .sendText(data)
                    .await(responseTimeout).on(
                        ws.checkTextMessage("Check response code")
                            .matching(
                                jsonPath(matchJsonPath).ofLong().isEL("#{seq}").saveAs("returnSeq")
                            )
                            .check(
                                jsonPath(checkJsonPath).ofInt().is(returnCode).saveAs("returnCode")
                            )
                    )
                ).doIf(Session::isFailed).then(
                    exec(session -> {
                            log.error("Failed request seq: {} ; Return seq: {} ; Return code: {} ; session: {}",
                                session.getString("seq"),
                                session.getString("returnSeq"),
                                session.getString("returnCode"),
                                session.userId()
                            );

                            return session.reset();
                        }
                    )
                )
        ).exec(ws("Close WS").close());

    public WebsocketTest() {
        setUp(
            scn.injectOpen(rampUsers(connections).during(rampUp))
        ).protocols(httpConf);
    }
}

But the result is so confusing. In this pic, validation is passed, but an error msg is still logged.
So Session::isFailed returns true?

And here looks like thread gatling-1-2 consumes gatling-1-3’s msg, then gatling-1-3 has to wait for nothing until timeout and fails the request.

Env:

• Gradle 7.5 w/ Gatling plugin 3.8.3.2
• JDK 11
• macOS 12.1

[slandelle]

@nobody

session -> {
                    session.markAsSucceeded();
                    String nanoTime = String.valueOf(System.nanoTime());

Session is immutable: Gatling - Session API.

[nobody]

Thank you slandelle. The 1st problem is solved, but the 2nd one still here.

New code:

.exec(session -> {
    Session newSession = session.markAsSucceeded();
    String nanoTime = String.valueOf(System.nanoTime());
    return newSession.set("seq", System.currentTimeMillis() + nanoTime.substring(nanoTime.length() - 5));
})

I got 12 out of 3500 requests being mistakenly treated as non-matching:

================================================================================
2022-08-18 21:51:01                                         121s elapsed
---- Requests ------------------------------------------------------------------
> Global                                                   (OK=8388   KO=12    )
> Connect WS                                               (OK=700    KO=0     )
> Send text                                                (OK=3500   KO=0     )
> Check response code                                      (OK=3488   KO=12    )
> Close WS                                                 (OK=700    KO=0     )
---- Errors --------------------------------------------------------------------
> Check Check response code timeout                                  12 (100.0%)

---- WebSocket -----------------------------------------------------------------
[##########################################################################]100%
          waiting: 0      / active: 0      / done: 700   
================================================================================

[slandelle]

Your matchJsonPath (missing from your sample) is likely wrong.

.matching(
   jsonPath(matchJsonPath).ofLong().isEL("#{seq}").saveAs("returnSeq")
)

Note that saveAs here won’t work (in matching).

[nobody]

matchJsonPath is using the default value and unchanged during the test.
If the jsonpath is wrong, all requests should fail.

String matchJsonPath = System.getProperty("matchJsonPath", "$.body.seq");

The response body is fixed (except client seq($.body.seq), server seq($.seq) and timestamp), so $.body.seq is always available.

{"body":{"code":10001,"desc": "UNSUPPORT PROTOCOL","ptype":"UNRECOGNIZED","seq":166083059168627347},"ptype":"ACK","seq":1660830593473,"timestamp":1660830593474,  "ver":"1.0.0"}

[nobody]

Under higher concurrency, more and more responses seemed to fail to match the “seq” attribute in Session?

[slandelle]

session.set(“seq”, System.currentTimeMillis() + nanoTime.substring(nanoTime.length() - 5));

“seq” is a String here.

jsonPath(matchJsonPath).ofLong().isEL(“#{seq}”).saveAs(“returnSeq”)

And here you’re comparing a long and a String, so it’s bound to fail.

[slandelle]

Then, if you face an issue, please provide a reproducer as instructed here: How to Ask a Question.

[nobody]

And here you’re comparing a long and a String, so it’s bound to fail.

I found out the root cause, nothing to do with test code or gatling.
There was a bug in our server code, in some circumstances, server sends msg to a wrong channel.