Browsers automatically respond to ping with same pong message content - how to do that with this plugin?

[Myer Nore]

In our scripts which use this plugin, after 20 seconds, the read samplers start intercepting pings. I can filter the pings, but I shouldn’t - and after 50 seconds, the server disconnects them, resulting in:

Response code:Websocket I/O error
Response message:WebSocket I/O error: end of stream

Our websocket server daphne sends a ping to the client after 20 seconds, and if the client doesn't respond with a pong in the next 30 seconds, it prunes the connection.

As described in MDN's "Pings and Pongs: The Heartbeat of WebSockets":

When you get a ping, send back a pong with the exact same Payload Data as the ping

Browsers implement this behavior, and daphne will prune connections that do not obey the part where you send back the same data payload; daphne sends hex nonces along with the ping that must be returned intact within 30 seconds. Is there a way to configure this plugin to automatically send a pong back with the exact payload sent in the ping, as in browsers?

I see how to send an unsolicited pong request with a ping/pong sampler. In theory, I could write a script which expects a ping at the particular time, parses the response to get the payload data, and sends back a Ping sampler with the same data, but it seems a bit complex; I would expect an example of such in the samples directory if that was so.

Hopefully there's something I'm missing. If not, then I propose an enhancement: a Ping Autoresponder config element such that pings are responded to as per the websocket spec.

[Peter Doornbosch]

Hi,

Did you try the PingFrameFilter? It has an option to automatically respond to pings (with a pong) and it should include the ping-data in the pong.

Regards
Peter

[Myer Nore]

I did use a top-level Ping/Pong Frame Filter with “Automaticaly respond to ping with a pong,” but from the results plugin, I see it is discarding the server’s pings, instead of replying to it; see 180.1 and the subsequent I/O errors upon trying to close the connection. I can also see there is no response data (not pictured in screenshot).

‌

[Peter Doornbosch]

The pong is sent silently, so the fact that you do not see it in the results view does not prove it is not sent.

Please turn on debug logging (see readme) and look for debug message “Automatically replying to ping with a pong.”. Or capture a session with WireShark and check if you see the plugin responding to a ping.

[Peter Doornbosch]

Solved? Happy?

[Myer Nore]

@Peter, when I look in wireshark, I can see that the websocket ping from the server is not responded to by JMeter.

Here’s my test plan, including the WS Ping/Pong Frame Filter (with “Automatically respond to ping with a pong” checked)

Here is a screenshot of the wireshark capture (this is the entire capture, filtered for websockets). JMeter is 192.168.33.1, the server is at 192.168.33.11. You can see that two consecutive pings were sent from the server to JMeter, with no pong response.

When I increase the loglevel for twisted, the underlying network provider for daphne, I see this in the logs when the connection is pruned:

{"levelname": "WARNING", "asctime": "2021-08-12 15:39:54,012", "module": "_legacy", "message": "dropping connection to peer tcp4:192.168.33.1:57261 with abort=True: WebSocket ping timeout (peer did not respond with pong in time)"}

Here’s the results tree for the same run, showing the “WebSocket I/O error: Broken pipe“ on the WebSocketClose for Concept 1 after the server pruned the connection:

I’ve tried increasing the loglevel of JMeter Websocket Samplers, by putting the following in debug_websockets_jmeter.properties and referencing it by running jmeter -q debug_websockets_jmeter.properties --logfile=local_dev_samplelog.xml --jmeterlogfile=local_run_jmeter.log -t 2021-08-11_wed_pmn_runserver.jmx:

log_level.eu.luminis.jmeter=DEBUG
log_level.eu.luminis.websocket=DEBUG

However, while I see several <sample entries relevant to websockets in the resulting logs, none of them mention pings or pongs.

Do you have any further guidance on how to configure JMeter Websocket Samplers to respond to pings? Here is some of the provenance of my observation:

o.a.j.JMeter: Version 5.4.1
o.a.j.JMeter: java.version=16.0.2
o.a.j.JMeter: java.vm.name=Java HotSpot(TM) 64-Bit Server VM
o.a.j.JMeter: os.name=Mac OS X
o.a.j.JMeter: os.arch=x86_64
o.a.j.JMeter: os.version=10.14.6
websocket-samplers=1.2.8

Next, as a workaround, I’ll try configuring my script to send unsolicited messages every twenty seconds, to avoid the need for ping/pong, but I’m not exactly sure how best to do this in a maintainable way.

[Peter Doornbosch]

Strange, your setup seems correct to me and should work. I’ll investigate, hang on.

[Myer Nore]

Here’s a sample ping that was sent:

338 11:54:37.958555 192.168.33.11   192.168.33.1    WebSocket   72  WebSocket Ping [FIN] 
hex dump: 
0000   0a 00 27 00 00 00 08 00 27 d9 f9 93 08 00 45 02
0010   00 3a 49 88 40 00 40 06 2d d7 c0 a8 21 0b c0 a8
0020   21 01 1f 41 e0 05 37 51 53 53 21 e7 d8 60 80 18
0030   01 f5 a3 4d 00 00 01 01 08 0a a0 3b 9d 80 99 00
0040   76 40 89 04 59 6f 5a 6b
escaped string: 
"\x0a\x00\x27\x00\x00\x00\x08\x00\x27\xd9\xf9\x93\x08\x00\x45\x02" \
"\x00\x3a\x49\x88\x40\x00\x40\x06\x2d\xd7\xc0\xa8\x21\x0b\xc0\xa8" \
"\x21\x01\x1f\x41\xe0\x05\x37\x51\x53\x53\x21\xe7\xd8\x60\x80\x18" \
"\x01\xf5\xa3\x4d\x00\x00\x01\x01\x08\x0a\xa0\x3b\x9d\x80\x99\x00" \
"\x76\x40\x89\x04\x59\x6f\x5a\x6b"

‌

[Peter Doornbosch]

I see a “Constant Timer” element in your test plan. If the JMeter test thread is waiting in the timer when the ping arrives, it will not immediately respond with a ping (because no sampler that could perform this action is active or running). It the timeout of the timer is longer than the time the server is willing to wait for a pong, this might cause the connection to fail. Please try with shorter timer values, just to check if this might be the case.

[Myer Nore]

The ping timeout for daphne is 30 seconds - meaning that each ping from the server needs a response within 30 seconds. The constant timers I’ve used in above 3 seconds.

If a ping arrives during a constant timer’s pause, will they get queued up, and still get processed by the plugin?

‌

[Peter Doornbosch]

Yes, the ping frame will be in the receive buffer and will be read and processed by the plugin as soon as a sampler is becoming active.

In the screenshot of the test plan, the title of the ping filter contains “(no autorespond)”. If this means what i think it means , this could be the reason the ping is not answered…

[Peter Doornbosch]

Solved?