TWSocketClient.OnDataAvailable not firing off after a day or two

[aehimself 396]

Hello,

 

Most probably this is NOT going to be an issue with ICS as I experienced the very same symptom with TServerSocket before I made the switch. I'm mainly looking for tips on where can I start debugging the issue as for the time being I'm completely out of ideas.

 

I have an application which is connecting to a server on a single, TCP socket. On average, 80 bytes (binary) are sent from the clients to the server each minute, in one packet. The TCP channel is unidirectional, messages are only going from the client to the server. Everything is working perfectly, until a seemingly random time; when for a seemingly random client the data is not received anymore. The TCP connection is still established, the client is still sending the packet and WireShark confirms that it arrives to the server machine. It seems that the socket's receive event stops firing off. What is even more interesting, that it affects random clients (with different OSes, sometimes Windows 2000, sometimes 2012 R2, sometimes 2019), only causes one client to get stuck at a time, but multiple clients can get stuck during the process. The application can remain in this state for days without memory increase (so I'm not inflating the local buffer endlessly, without triggering the data processing), memory or handle leaks. If I restart the client or the server, forcing the client to reconnect, everything jumps back to normal.

 

As for a little background, the very same logic was working perfectly, when the binary data was converted to, and sent as text. By switching to binary the sent data size was reduced from 200-500 bytes to 60-100. I don't know why but I suspect this change triggered the error I'm seeing now; and maybe because of the data size.

 

https://docs.microsoft.com/en-us/troubleshoot/windows/win32/data-segment-tcp-winsock mentions that TCP is not really efficient with unidirectional, small data packets but it only will result delivery delay. For me it seems to be irrelevant.

 

Sending code looks something like this (TBufferLength = Word):

Function TCommunicationEngine.Send(Const inText: String): Boolean;
Var
 buf, len: TBytes;
 sent: Integer;
Begin
 Result := False;
 Try
  // Step 1 - String to TBytes
  buf := TEncoding.UTF8.GetBytes(inText);

  // Step 2 - Encryption of "buf"
  // ...
  
  // If the buffer exceeds the maximum length allowed, raise an error as it can not be sent!
  If Length(buf) > TBufferLength.MaxValue Then Raise ETCPPortError.Create('Buffer overflow, cannot send ' + Length(buf).ToString + ' bytes!');

  // Step 3 - Append the length of the buffer to the beginning of the buffer
  SetLength(len, SizeOf(TBufferLength));
  PBufferLength(@len[0])^ := Length(buf);
  SetLength(buf, Length(buf) + Length(len));
  Move(buf[0], buf[Length(len)], Length(buf) - Length(len));
  Move(len[0], buf[0], Length(len));

  // Step 4 - Send the completed buffer
  sent := _tcpport.Send(@buf[0], Length(buf));

  // Step 5 - Post-sending verifications
  If sent < 1 Then Raise ETCPPortError.Create('No data was sent!');
  Log(LOG_TCP, '> ' + BytesToString(buf) + ' (' + sent.ToString + ' bytes)');
  Result := True;
 Except
  On E:Exception Do HandleException(E, 'while sending data');
 End;
End;

Receiving block looks like this (TClientConnection is a descendant of TWSocketClient, _data is a strict private TBytes, _count is a strict private Integer):

Procedure TClientConnection.ConnectionDataAvailable(inSender: TObject; inError: Word);
Var
 buf: TBytes;
 need, len, read: Integer;
 debuglog: String;
Begin
 // Note that due to how TCP works, if packets are arriving at high speed they might be appended to one single ReceiveText event.
 If BanList.IsBanned(Self.PeerAddr) Then Self.Close // If the IP where the data is coming from is banned, disconnect
   Else Begin
        len := Self.RcvdCount;
        If len = 0 Then Exit;
        Repeat
         debuglog := Self.PeerAddr + ' > Read cycle starts. received data size: ' + len.ToString + ', socket data size: ' + Length(_data).ToString + ', position: ' + _pos.ToString + '. ';
         If _pos = 0 Then Begin
                          // Position is 0 = there is no fragment. Read the data size first
                          If len < SizeOf(Word) Then Begin
                                                     BanList.Failed(Self.PeerAddr, 'Packet size is incorrect');
                                                     Self.Close; // Packet is corrupted, reset the connection
                                                     Exit;
                                                     End;
                          SetLength(buf, SizeOf(TBufferLength));
                          Self.Receive(@buf[0], Length(buf));
                          // buf now contains the data size. Resize socket's data length
                          SetLength(_data, PBufferLength(@buf[0])^);
                          // As the data size is read out, reduce the received length
                          len := len - Length(buf);
                          debuglog := debuglog + 'Prepared a ' + Length(_data).ToString + ' byte buffer. ';
                          End;
         need := Length(_data) - _pos;
         If need < 0 Then Begin
                          // this should never happen. I'll just keep it here for debugging purposes...
                          Log(LOG_STD, 'Possible memory corruption happened. Data size of ' + Self.PeerAddr + ' is ' + Length(_data).ToString + ', position is ' + _pos.ToString);
                          Self.Close;
                          Exit;
                          End
           Else
         If need > 0 Then Begin
                          If len < need Then SetLength(buf, len) // If we received less bytes than needed to fill the buffer, read everything
                            Else SetLength(buf, need); // If we received more bytes than needed to fill th buffer, only read what is needed
                          debuglog := debuglog + 'Reading out ' + Length(buf).ToString + ' bytes. ';
                          read := Self.Receive(@buf[0], Length(buf));
                          If read > 0 Then Begin
                                           debuglog := debuglog + read.ToString + ' bytes read. ';
                                           // Something was read from the buffer. Append it to the socket's data
                                           Move(buf[0], _data[_pos], read);
                                           // Increase data position
                                           Inc(_pos, read);
                                           // Reduce received length
                                           len := len - read;
                                           End
                            Else debuglog := debuglog + 'Nothing was read. ';
                          End;
         If _pos = Length(_data) Then Begin
                                      Log(LOG_TCP, debuglog.TrimRight);
                                      Log(LOG_TCP, Self.PeerAddr + ' > ' + BytesToString(_data) + ' (' + _pos.ToString + ' bytes)');
                                      // Buffer is full. Process the data.
                                      
                                      // Decrypt the buffer...
                                      // ...

                                      Try
                                       ProcessLine(Self.PeerAddr, timestamp, TEncoding.UTF8.GetString(_data));
                                      Except
                                       On E:Exception Do Begin
                                                         Log(LOG_STD, TranslateException(E, 'processing client data'));
                                                         BanList.Failed(Self.PeerAddr, 'data processing error: ' + E.Message);
                                                         Self.Close;
                                                         End;
                                      End;
                                      _pos := 0;
                                      SetLength(_data, 0);
                                      End
           Else
         If Not debuglog.IsEmpty Then Log(LOG_TCP, debuglog.TrimRight);
        Until len = 0;
        If (Length(_data) > 0) Or (_pos > 0) Then Log(LOG_TCP, 'Storing a fragment for ' + Self.PeerAddr + ': Data size: ' + Length(_data).ToString + ', position: ' + _pos.ToString);
        End;
End;

I know that there are a couple of premature exits before the actual data processing, but even when I added temporary logging before these, none of them was reached.

 

I'll investigate on how I can, and will try to add TCP_NODELAY and SO_SNDBUF, but I doubt that they will make any difference. Until then, I'm really interested what are the aspects what I did not even think of until now.

 

I'm using ICS v8.64, application is compiled using Delphi 10.4.1 as a 32-bit executable, and is executed as a Windows service on a Server 2012 R2 machine.

 

Any help is greatly appreciated 🙂

Edited September 27, 2020 by aehimself

[FPiette 382]

Do not rely on RcvdCount to know if data is ready to be read. In some case, winsock returns 0 even if more data is available. Just call Receive and use the return value. Call Receive again until Receive returns < 0.

 

This is not an ICS issue but a known Winsock behaviour, that's why you experience the issue with both ICS and your old socket component.

 

[Guest]

The point Francois pointed is critical here, and you are corruptting your own data by depending on RcvdCount, example RcvdCount returned 100 while when Self.Receive (@buf[0], Length(buf)) called, new data arrived and the Receive call got 200, you went ahead and clipped them and got unexpected, incomplete and lost data.

 

I would suggest that you can simplify the whole thing as it is way complicated for no good reason, consider changing such function to something like the following ( food for thought)

var // those are local fields 
  InBuf: TBytes;            // initialize before establishing the connection
  InBufferCount: Integer;   // we also can have InBufferSize if you prefer to reflect the length of InBuf

Procedure TClientConnection.ConnectionDataAvailable(inSender: TObject; inError: Word);
var
  BytesRecived, PacketSize: Integer;
begin
  BytesRecived := Self.Receive(@InBuf[InBufferCount], Length(InBuf) - InBufferCount);
  if BytesRecived > 0 then
    begin
      Inc(InBufferCount, BytesRecived);
		
      PacketSize := PBufferLength(@buf[0])^;
      if PacketSize > 0 then
        while PacketSize <= InBufferCount do
          begin
            // we have full packet and we handle it
            HandleOnePacket(InBuf,PacketSize);
            // also it can be done without copy or sliding the data, but for simplicity here we remove the handled data
            Move(InBuf[InBufferCount], InBuf[0], PacketSize {+ header size depends if included = SizeOf(BufferLength) } );
            Dec(InBufferCount, PacketSize {+ same as above above});

            PacketSize := PBufferLength(@buf[0])^;
            if PacketSize <= 0 then
              Break;
          end;
       if PacketSize <= 0 then
        begin
          // corruption or hack
        end;
    end else
    begin
      // here we handle 0 or -1
    end;
end;

I have no idea if that code will work out of the box or not, but it is here to show that the return value from Receive (BytesRecived := Self.Receive ) is the key to do it right, while in your code you are gambling on data to arrive in pattern that might not be always there. 

[Guest]

And forgot to mention in my sample above there is no mention to the situation were it might fail, it is with the buffer size, example client send two 4k packets and server triggered the DataAvailable event but read only 3k then the rest of the first and the second received, in this case server will read the 2k only and might not get another event to receive again, so the buffer length should be large enough (twice your largest packet will be enough) or the loop above should reformatted to read again from socket if the buffer was filled.

[aehimself 396]

29 minutes ago, Kas Ob. said:

And forgot to mention in my sample above there is no mention to the situation were it might fail, it is with the buffer size, example client send two 4k packets and server triggered the DataAvailable event but read only 3k then the rest of the first and the second received, in this case server will read the 2k only and might not get another event to receive again,

I will be honest, I did not understand how it can stop receiving, up until this point. It all makes sense now.

I'm in the progress of re-writing it this way, we'll see if that will bring success.

 

Edit: the lockup indeed happens when there is a significantly larger amount of data incoming (6-7 * 150 bytes instead of 80) so that also confirms this theory. I finished converting the read-out logic and deployed it on the test server. We will see in a couple of days if it worked 🙂

Edited September 27, 2020 by aehimself

[aehimself 396]

The code you sent will not work, as it is always reading out the packet size. If the following scenario occurs:

 

 

it will consider the beginning of the second event as a new packet size.

 

[Guest]

You lost me, my sample code is using 

PacketSize := PBufferLength(@buf[0])^;

to get the packet size, and no matter how packet you received it ( in that format ) will slide the next one to the start and use above line again, as long your buffer is twice the maximum packet you are sending then everything should work just fine.

Now, no matter how much events there is, it will add received data, then check for complete packet then remove it (aka slide the rest if any to the start).

 

Unless you are talking about how InBuf allocated and resized, then i pointed up there, it is a field in class will be allocated when the connection established, so no problem there too and you don't need to adjust/resize it.

 

 

 

[aehimself 396]

2 minutes ago, Kas Ob. said:

You lost me

Indeed I did! My brain simply didn't process that the event is not placing the data in the beginning of InBuf... guess I'd finally need some sleep?

 

I went on with the more difficult version however. I'm reading a fixed size (let's say 200 bytes). If the packet buffer is empty, I read the size and set the packet buffer to that size. If not, I'm appending as many bytes as needed / possible from this 200. If all was processed, I read the next 200 until there's none left. If it works (and I do have my hopes high) I'll move some processing parts to submethods to make the main one easier to read.

[Guest]

Sleep deprivation is the worst.

 

32 minutes ago, aehimself said:

I went on with the more difficult version however. I'm reading a fixed size (let's say 200 bytes). If the packet buffer is empty, I read the size and set the packet buffer to that size. If not, I'm appending as many bytes as needed / possible from this 200. If all was processed, I read the next 200 until there's none left. If it works (and I do have my hopes high) I'll move some processing parts to submethods to make the main one easier to read.

It will work.

 

One thing though when speed is important then change it to something else, points to know with sockets is 

1) TCP, to get the best speed you must make sure to minimize the time between traffic received by the driver/hardware and your software grabbing it, so the afd driver can acknowledge it.

2) UDP, the speed always fast but, if there is many traffic filling the driver buffers, then the new ones will be dropped silently.

So your algorithm of grabbing 200 then the rest, might be a bottleneck in the future, until then, have good sleep portion and build it as you wish and feel comfortable.

[FPiette 382]

One more important thing: In the OnDataAvailable event, you should read ALL data arriving. So you should make a loop calling Receive until it return < 0. If the buffer used for receive is to small, read anyway in a secondary small buffer and throw data away, then signal the error to the user "buffer to small".

 

[aehimself 396]

Just now, FPiette said:

One more important thing: In the OnDataAvailable event, you should read ALL data arriving. So you should make a loop calling Receive until it return < 0. If the buffer used for receive is to small, read anyway in a secondary small buffer and throw data away, then signal the error to the user "buffer to small".

Yep, that's exactly what I do now. I have an outer cycle:

        Repeat
         // Receive the fixed size buffer (set in constructor)
         read := Self.Receive(@_rcvbuf[0], Length(_rcvbuf));
         If read <= 0 Then Break;
         [...]
        Until False;

Within this cycle, I have an internal cycle which is assembling the packets to be decrypted from _rcvbuf; based on the size indicator. If the packet did not fit in _rcvbuf, the next outer cycle will read out the next fragment.

 

This method seems to be working, packets are flowing in and being decrypted correctly. I just have to wait a couple of days to see if the lock-up happens again or not.
 

[Fr0sT.Brutal 900]

15 hours ago, FPiette said:

One more important thing: In the OnDataAvailable event, you should read ALL data arriving. So you should make a loop calling Receive until it return < 0. If the buffer used for receive is to small, read anyway in a secondary small buffer and throw data away, then signal the error to the user "buffer to small".

I have no issues not caring about this. TCustomWSocket.TriggerDataAvailable has the loop already while Receive gets full buffer requested and TCustomWSocket.ASyncReceive loops as well unless the socket has wsoNoReceiveLoop option set. Anyway in my stream-reading classes I especially set wsoNoReceiveLoop, just making sure OnDataAvailable handler calls Receive in any condition (even 0-byte read is fine). With this setup ASyncReceive is called again and again until all data is read.

18 hours ago, aehimself said:

I went on with the more difficult version however. I'm reading a fixed size (let's say 200 bytes). If the packet buffer is empty, I read the size and set the packet buffer to that size. If not, I'm appending as many bytes as needed / possible from this 200. If all was processed, I read the next 200 until there's none left. If it works (and I do have my hopes high) I'll move some processing parts to submethods to make the main one easier to read. 

Just foresee that your fixed size could arrive incomplete if it's > 1 byte. I usually read data to buffer to fill header and only then start reading the contents.

[aehimself 396]

14 minutes ago, Fr0sT.Brutal said:

Just foresee that your fixed size could arrive incomplete if it's > 1 byte. I usually read data to buffer to fill header and only then start reading the contents.

I'm not exactly sure if I got what you meant. The fixed size buffer is only used in the dataavailable evnt to read x bytes out from the socket. Then, there is an inner cycle to process the data in this inner buffer. If a packet ended within it, it copies the missing bytes to a different (variable size; set by the size indicator) buffer, sends that for processing, reads the size indicator and resets it. Until there is nothing else to be processed.

 

Since I made the latest modifications, this logic seems to function properly - however there was no fragmented packet yet (when the beginning and the end arrive in two different handlers, possibly delayed)

[Guest]

11 minutes ago, Fr0sT.Brutal said:

Just foresee that your fixed size could arrive incomplete if it's > 1 byte. I usually read data to buffer to fill header and only then start reading the contents.

That is the right thing to do, instead of receiving 200 bytes then make them 64kb and free the socket buffers, then process the data as you wish, just reduce the overhead.

 

12 minutes ago, Fr0sT.Brutal said:

(even 0-byte read is fine).

It is not fine, it is a must ! 

I am not experienced in ICS internals per se, but when ever IO operation issued pointing to zero length, then follow the logic design and read it or write it, faulty or not, right or wrong, it is that component (or OS part) designer job to decide if such should be happening or not, so if it does issued 0 length operation then do it.

[FPiette 382]

33 minutes ago, Fr0sT.Brutal said:

I have no issues not caring about this. TCustomWSocket.TriggerDataAvailable has the loop already while Receive gets full buffer requested and TCustomWSocket.ASyncReceive loops as well unless the socket has wsoNoReceiveLoop option set.

Sure, but if data is not read, the program get stuck in that loop forever. That is why it is important to read all data and throw away what is not possible to keep, raising an exception or showing an error because throwing away data silently will make the program have unexpected results - for the less.

 

[FPiette 382]

16 minutes ago, aehimself said:

however there was no fragmented packet yet

One more warning: When using TCP, there is no packet at all, just a stream of bytes. What the receiver sees is totally independent of how the sender send data. The sender may call a single send and the receiver have two OnDataAvailable events and the sender may call several send but the receiver receive only one single OnDataAvailable event for all data.

 

Writing a program using TCP assuming there is a correlation between sender's send() and receiver OnDataAvailable will sooner or later explode on your face! (Frecnh expression).

[aehimself 396]

6 minutes ago, FPiette said:

One more warning: When using TCP, there is no packet at all, just a stream of bytes.

I know. When I used the term "packet" I referred to the packet the Client sent and which has to be re-assembled on server side from the stream of bytes 🙂

[Fr0sT.Brutal 900]

2 hours ago, aehimself said:

I'm not exactly sure if I got what you meant

Yeah, I must've expressed my point a bit unclear. I mean, if you have algo like this

Recv(MsgSize, SizeOfMsgField);

while MsgRecv < MsgSize do

  recvd := Recv(Buf[MsgRecv], MsgSize - MsgRecvd);

 

and SizeOfMsgField > 1 there's a little probability to not have whole SizeOfMsgField of data in socket. So the reliable workflow is to read everything to buffer until you get the whole header and then start reading message body (considering the chunk you've already got). It's a universal pattern of reading with parsing. If a header is pretty big, reader could start parsing before it gets the whole header (f.ex., HTTP) but it splits data to logical parts anyway (CRLF-delimited lines).

2 hours ago, FPiette said:

Sure, but if data is not read, the program get stuck in that loop forever. That is why it is important to read all data and throw away what is not possible to keep, raising an exception or showing an error because throwing away data silently will make the program have unexpected results - for the less.

Well, I'd say "it is important to read at least some data". As TWSocket implements the read loop already internally, it's not necessary to create another loop in one's code. Sometimes it's more convenient and simple to read just as much as needed (f.ex. when parsing some message, read just one to the end and then exit OnDataAvail)

[Guest]

1 hour ago, Fr0sT.Brutal said:

Yeah, I must've expressed my point a bit unclear. I mean, if you have algo like this

Recv(MsgSize, SizeOfMsgField);

while MsgRecv < MsgSize do

  recvd := Recv(Buf[MsgRecv], MsgSize - MsgRecvd);

Good point and i missed that in my example above, so it should be like this

  if BytesRecived > 0 then
    begin
      Inc(InBufferCount, BytesRecived);
	  if InBufferCount > SizeOf(BufferLength) then  // make shure we full header, so we know the right length in case the header itself had been fragmented
		begin
      		PacketSize := PBufferLength(@buf[0])^;
      		if PacketSize > 0 then
        		while PacketSize <= InBufferCount do
          		begin

 

[FPiette 382]

Even when you know the length of data supposed to be sent by the sender, it is important to read data as much as it comes in for the reason I explained in my previous messages. More data can come in because the sender queue requests without waiting for prior answer, or maybe the sender is simply trying to hang your application (DOS attack).

 

[aehimself 396]

So, ~ two weeks have passed, no issues experienced so far. Packets are leaving the client and arriving to the server and even decoded properly; which means that the new read-out logic is functioning as planned. As the longest I've seen was about a week with the old solution I'm getting more confident that this was indeed the source of the issue (just to be sure I'll wait some more before considering it fixed, though).

 

Despite the fact that that the old, TClientSocket / TServerSocket doesn't seem to be the root cause I'm glad I went on and changed them with ICS. Now I have one less concern and a ton of opportunities (like IPV6, which did not even exist when the old components were created by... Borland?)

 

On 9/28/2020 at 5:25 PM, FPiette said:

or maybe the sender is simply trying to hang your application (DOS attack).

When I detect an anomaly (like an undecryptable / corrupted packet) I'm force-closing the connection with the client from the server side (by calling Self.Close, calling from a descendant of TWSocketClient). I'm assuming this also clears and destroys the queue so I don't need to read it empty first...? As my assumption was wrong with my initial receive logic, It's safer to ask I suppose 🙂

Edited October 12, 2020 by aehimself

[Guest]

@aehimself Glad to hear you solved your problem.

 

But i want to add few things to think about

1) As you did not follow the samples, then you might still have a problem that did not show, consider pasting here that DataAvailable handler, Francois and Angus might suggest better and more sturdy code, or just spot a problem.

2) Running for two weeks doesn't mean it will not fail doesn't mean it will not fail, so you may consider to record your own test and scenarios for testing, a simple client that designed by you to trigger every "IF" in your code.

3) More Important thing than IPv6 is TLS !, now you can have it.

4) Next step is stressing your server to know its limits, this is more important than worrying about (D)DoS attack for now, so you should have your own stressing client that can add X connections when you can see the throughput reach its limit, only then you can see what DoS attack might do , like simple flooding..., but the most important is to get confidence that your server will still functioning through such flooding, ( by flooding there is two different scenarios where many connection is been established without traffic, just to occupy the resources on server and make it starve, and where many connection been sending traffic and close immediately to establish new, also will make server starve for resources), after such stress comes the next part, for this you don't need to go with your own protocol, but use a different simple protocol like echoing the client without and without encryption.

5) you need to test your server for unusual traffic, for that i suggest to use Clumsy https://jagt.github.io/clumsy/ , and it is clumsy , but will work most the time, the point is to see if your server is handling those situations ( like dropped packets, corrupted...etc) right and will not crash, combine this step with or without the stress in (4), are you raising exception internally ! what its effect on the throughput ? or server stability.

 

You may need all of that or may not, but there is big chance that you need to know how to handle the above in the future, away from that good luck.

 

[FPiette 382]

10 hours ago, aehimself said:

So, ~ two weeks have passed, no issues experienced so far.

Good to know. Thanks for reporting.

[Angus Robertson 574]

I have a stress testing tool ComGen, written using ICS, that will generate multiple TCP or UDP streams (or serial RS232), short or long, sending variable volumes of custom data including HTTP,, with or without SSL/TLS.  It will create up to 2,000 client  simultaneous connections, with x per second, that was used for testing SSL Socket Server where the SSL connection overhead restricts how many connections a single thread can accept per second.   This is all done in a single thread.  

 

ComGen is part of my ComCap package (ComCap collects data) but can be used on it;s own.

 

Angus