Websocket server/client frame sending rate issue

[FrozenK 0]

Hello, 
I'm using the ICS 9.0 C++ package. While testing a websocket server (TSslHttpAppSrv) communication with a client (TSslWebSocketCli), I noticed that both have trouble receiving several frames in a short period.
It doesn't seems to be related to the frame size because sending empty text frames (using WSSendText) doesn't change anything.
Let's suppose I want to send 10 messages from my server to my client, in my small test program I can :
a) click 10 times on a "send" button.

b) click one time on a "send" button but then I loop 10 times on WSSendText.
In the (a) scenario everything is ok but in the (b) scenario the connection is closed at some point, attaching a TIcsLogger to the server and client does not really help as you can see below :
Server side

LoggerLogEvent : 11:00:15:084 00000148B13008B0 TriggerDataSent handle=1476
LoggerLogEvent : 11:00:15:084 00000148B13008B0 TriggerDataSent handle=1476
LoggerLogEvent : 11:00:15:084 00000148B13008B0 TriggerDataSent handle=1476
LoggerLogEvent : 11:00:15:084 00000148B13008B0 TriggerDataSent handle=1476
LoggerLogEvent : 11:00:15:084 00000148B13008B0 TriggerDataSent handle=1476
LoggerLogEvent : 11:00:15:084 00000148B13008B0 TriggerDataSent handle=1476
LoggerLogEvent : 11:00:15:084 00000148B13008B0 TriggerDataSent handle=1476
LoggerLogEvent : 11:00:15:084 00000148B13008B0 TriggerDataSent handle=1476
LoggerLogEvent : 11:00:15:084 00000148B13008B0 TriggerDataSent handle=1476
LoggerLogEvent : 11:00:15:084 00000148B13008B0 TriggerDataSent handle=1476
LoggerLogEvent : 11:00:15:084 00000148B13008B0 TCustomWSocket.Shutdown 1 handle=1476
"11:00:15.084" : WS ClientDisconnect : 0

Client side

LoggerLogEvent : 11:00:15:084 SessionClosed Error: 0
LoggerLogEvent : 11:00:15:084 00000204E35B5B30 TCustomWSocket.Shutdown 1 handle=1468

These tests are done without SSL. Now if I activate SSL, both (a) and (b) scenarios works fine, I do not have any sudden connection close anymore. My understanding is that the extra computation introduced by the transport layer security adds a delay before sending the frame (or maybe the way frames are sent is reorganised) so the client has now time to process each frame without being flooded. I'm a bit surprised because these numbers are quite low (10 frames), I actually doesn't have to send 10 frames to create the issue 3 is enough.

I have the feeling that I'm missing something, either on the server/client configuration side (a missing parameter ?) or on the feedback informations (from the logger) that I get preventing me to understand exactly what is going on.

If someone has a clue on what should I do to get a better grasp on my problem it would be very much appreciated.
Thanks in advance. 

Edited July 25 by FrozenK

[Angus Robertson 659]

There have been a lot of changed to the websocket components since ICS V9.0, and a major rewrite to support newer protocols is coming in a week or so with ICS V9.5.  So please repeat all your tests with ICS from the overnight zip and see if you can still reproduce the same problems. 

 

I'm afraid the debug logs you show are meaningless for diagnostic purposes, they are purely for development use.  

 

I have a public websocket server that is supporting about 50 SQL REST requests each second, for an hour at a time.   

 

Angus

 

[Kas Ob. 151]

40 minutes ago, FrozenK said:

If someone has a clue on what should I do to get a better grasp on my problem it would be very much appreciated.

Hi,

Not really a clue but a guess reading the log above and the steps, the shut down triggered at 16kb of sending, i read this as clue, it looks like the pending response ( aka blocking request) translated into disconnect and wrongly handled as failure instead.

 

So;

1) a question on side but might be important, were did these numbers 1476 and 1468 come from ?, did you calculate the MTU and decided it should be like that ? the lack of client side successful recv means the log entry wasn't from successful send event, track those, (but again of ICS have them, as i don't know)  

2) i can't tell how ICS works for websocket, but i think Angus can tell if the blocking handled right in your version, yet he recommended that you update, then update, also reproducing such behavior should be fairly easy, @FrozenK if you can provide short project reproducing that shutdown trigger, then that behavior can be solved once and for all.

3) Have you missed around with TCP buffers sizes ? (namely sending buffer) , are you tweaking some socket options ? the default send buffer on Windows is 8kb, but this doesn't means you can't send more, it is just little more long story to explain.

4) Also, the problem in my opinion is that ACK hadn't been received and sending party reached some a limit around 16kb (limit but not receiving peer ACK), this triggered blocking request (pending), and this translated into error with lead to shut down, in other words handled, the socket is not checking if ready to send while handling WSAEWOULDBLOCK as fatal connection error, while it is not.

 

Hope that helps.