HTTP: Whole traffic from WebSocket is logged as a DEBUG - can't filter failed messages

[MSlaski]

Hello,

I'm using Gatling 3.9.5 and found that issue reported here: #4439 is still visible. Original ticket was not reopened so I raised another one

During simulation with WebSocket every log related to WebSocket traffic is using DEBUG level. It means even if I try to log to file only failed messages Gatling will store everything. The most annoying issue of that is a log file with a couple of GBs which is harder to store/parse after tests

Is it possible to fix this and use logic similar to HTTP where using DEBUG for logging only failed messages will be logged, and TRACE for everything?

My logback.xml content:

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%d{HH:mm:ss.SSS} [%-5level] %logger{15} - %msg%n%rEx</pattern>
        </encoder>
        <immediateFlush>false</immediateFlush>
    </appender>
    <appender name="FILE" class="ch.qos.logback.core.FileAppender">
        <file>target/gatling/LastRun.log</file>
        <append>true</append>
        <encoder>
            <pattern>%d{HH:mm:ss.SSS} [%-5level] %logger{15} - %msg%n%rEx</pattern>
        </encoder>
    </appender>
    <!-- uncomment and set to DEBUG to log all failing HTTP requests -->
    <!-- uncomment and set to TRACE to log all HTTP requests -->
    <logger name="io.gatling.http.engine.response" level="DEBUG"/>
    <logger name="io.gatling.http.action.ws.fsm" level="DEBUG" />
    <root level="WARN">
        <appender-ref ref="FILE"/>
<!--        <appender-ref ref="CONSOLE"/>-->
    </root>
</configuration>

BR
Mateusz

[frodosik]

up

[slandelle]

using DEBUG for logging only failed messages

How do you define failed messages with WebSockets?

With HTTP, it's pretty straightforward that to the single (request, response) pair model.
With WebSockets, things are way more complicated:

• currently, we only support flows triggered from an outbound message, but this might change in the future
• which inbound message(s) should be logged? Only the one failing a check? But what about non-matching messages? And what about check timeouts?

[MSlaski]

From my point of view those incoming messages which failed check or exceed timeout should be treat as a "failed" ones. According to docs during matching all non-matching messages will be ignored, so at the end if I will not got message which im expecting using matching API I will reach some timeout

[slandelle]

From my point of view those incoming messages which ... exceed timeout should be treat as a "failed" ones.

so at the end if I will not got message which im expecting using matching API I will reach some timeout

Exactly, check timeout means no inbound message matched. So what should we log then? Only the outbound message? Or do you expect all unmatched message?

[MSlaski]

Outbound message should be good enough. Ofc better to log all non-matching messages but in this case I see more difficult scenario.
When im expecting some message using matching API and first 2 inbound messages doesn't match and third will match. At the end check works fine. For me, previous messages shouldn't be logged

[slandelle]

Summing up:

• outbound messages:
  • log in TRACE at send time
  • retain in memory for later logging if DEBUG is enabled and there's a check
• inbound messages:
  • when matching a check, logged along with the original inbound message:
    • in TRACE if the check succeeds
    • in DEBUG otherwise
  • otherwise (not matching, no check), log in TRACE

Note: when TRACE is enabled, so is DEBUG too.

Agree?

[CierpMat]

Bump. Same here

[slandelle]

@frodosik @CierpMat Please understand this is not how things work on an open-source project. Adding a comment with the objective of making things happen faster doesn't work, it's just annoying. If you want to make something happen faster, contribute it yourself or have your organization sponsor it.

[MSlaski]

Summing up:

• outbound messages:

  • log in TRACE at send time
  • retain in memory for later logging if DEBUG is enabled and there's a check

• inbound messages:

  • when matching a check, logged along with the original inbound message:

    • in TRACE if the check succeeds
    • in DEBUG otherwise

  • otherwise (not matching, no check), log in TRACE

Note: when TRACE is enabled, so is DEBUG too.

Agree?

Correct

[slandelle]

Is this something you're interested in contributing? Or your company willing to sponsor?

[Amerousful]

@MSlaski For your purpose you have to define a logger in this way:

 <logger name="io.gatling.http.action.ws.fsm.WsLogger" level="DEBUG"/>

Thus, you will receive only failure message logs, instead of all of these logs from fsm.

[slandelle]

Improved as of #4471

[MSlaski]

@MSlaski For your purpose you have to define a logger in this way:

 <logger name="io.gatling.http.action.ws.fsm.WsLogger" level="DEBUG"/>

Thus, you will receive only failure message logs, instead of all of these logs from fsm.

Unfortunately its not working like that

[Amerousful]

Unfortunately its not working like that

@MSlaski Could you please clarify what specifically is not working? Are you still receiving logs for requests that did not fail?

[MSlaski]

Unfortunately its not working like that

@MSlaski Could you please clarify what specifically is not working? Are you still receiving logs for requests that did not fail?

Sorry, My bad. I thought you provide the same details for this appended as it was described at Gatling's documentation. When I changed it and add WsLogger at the very end it is working fine.
Do you know what is the difference between your appender and the default one mentioned in documentation?