I have a Server using TIdTCPServer.
During initial connection of a client, I assign a local DTBClient to it as follows:
class procedure TDTBEventHandlers.IdTCPServer1Connect(AContext: TIdContext);
var
ADTBClient: TDTBClient;
begin
try
AContext.Connection.IOHandler.LargeStream := false;
if (AContext.Connection.IOHandler is TIdSSLIOHandlerSocketBase) then
TIdSSLIOHandlerSocketBase(AContext.Connection.IOHandler).PassThrough := true;
ADTBClient := TDTBClient(AContext);
ADTBClient.IP := AContext.Binding.PeerIP;
ADTBClient.Callsign := MakeRandomCallsign;
// etc
...
end
When thing go wrong with the Client, I try and disconnect them as follows:
Note1: When the List is NOT nil, then the lock/unlock is done by the calling procedure.
Note2: I forced this situation by pulling the network cable from the Client, so there is no TCP reset.
function DisconnectClient(ADTBClient: TDTBClient; List: TIdContextList; Server: TDTBPort):boolean;
var
Index: integer;
UnLock: boolean;
i: integer;
begin
Result := false;
Unlock := false;
try
if List = nil then
begin
if Server = dpOne then List := IdTCPServer1.Contexts.LockList else
if Server = dpTwo then List := IdTCPServer2.Contexts.LockList;
Superlog('DisconnectClient: List=nil? Server='+integer(Server).ToString,d_warning);
Unlock := true;
end;
try
Index := List.IndexOf(TDTBClient(ADTBClient));
if Index >= 0 then
begin
result := true;
SuperLog('DisconnectClient: Disconnecting: Callsign='+ADTBClient.Callsign+' Server='+integer(Server).ToString+'. Index='+Index.ToString);
TIdContext(List[Index]).Connection.Disconnect;
end;
finally
if UnLock then
begin
if Server = dpOne then IdTCPServer1.Contexts.UnlockList else
if Server = dpTwo then IdTCPServer2.Contexts.UnlockList;
end;
end;
end;
The Log shows this:
Aug 20 05:17:16 zeus sartrackserver[32044]: DisconnectClient: Disconnecting: Callsign=_DQKIK Server=1. Index=3
Aug 20 05:17:16 zeus sartrackserver[32044]: IdServerIOHandlerSSLOpenSSL1StatusInfo: SSL status: "SSL negotiation finished successfully"
Aug 20 05:17:21 zeus sartrackserver[32044]: [0] KeepAliveTimerEvent: Port 1: (NOT AllSyncsComplete): Timeout for Client: Callsign=_DQKIK, IP=122.57.206.196 PongCounter=8 Disconnecting on Index: 3
Aug 20 05:17:21 zeus sartrackserver[32044]: Superuser: DisconnectClient: Disconnecting: Callsign=_DQKIK Server=1. Index=3
Aug 20 05:17:21 zeus sartrackserver[32044]: ERROR: DisconnectClient: Client failed to disconnect on Index: 3
Aug 20 05:17:21 zeus sartrackserver[32044]: DisconnectClient: After List: 0: IZ3VIV
Aug 20 05:17:21 zeus sartrackserver[32044]: DisconnectClient: After List: 1: W7QQ-2
Aug 20 05:17:21 zeus sartrackserver[32044]: DisconnectClient: After List: 2: ZL4FOX-5
Aug 20 05:17:21 zeus sartrackserver[32044]: DisconnectClient: After List: 3: _DQKIK <<<<<
It looks like the disconnect has taken place on the TCP level, but the entry has not been removed from the List.
The next big problem is that during shutdown, the TCP server hangs on IdTCPServer1.Active := false; where it is disconnecting all clients, but when it hits the client which was already disconnected it locks up. And this causes the (Linux) server to hang during shutdown, and a kill -9 is required, and other data is lost.
I have never seen this happen before under Windows, but I now see it in the new Linux version.
I am using Delphi 10.4 with the included Indy10 version.
UPDATE 1
I have added load of debug log entries through the Indy10 system. As per Remy's advise, I now call Connection.Socket.Binding.CloseSocket instead of Connection.Disconnect. However, today the intermittend problem happened again, and this time I could see the CloseSocked never happened, and it looks like it it got stuck trying to enter "FConnectionHandle.Enter"
procedure TIdSocketHandle.CloseSocket;
begin
FConnectionHandle.Enter;
try
if HandleAllocated then
begin
// Bart
syslog(LOG_NOTICE, 'IdSocketHandle.CloseSocket: HandleAllocated');
// Must be first, closing socket will trigger some errors, and they
// may then call (in other threads) Connected, which in turn looks at
// FHandleAllocated.
FHandleAllocated := False;
syslog(LOG_NOTICE, 'IdSocketHandle.CloseSocket calls Disconnect');
Disconnect;
SetHandle(Id_INVALID_SOCKET);
end else syslog(LOG_NOTICE, 'IdSocketHandle.CloseSocket: NOT HandleAllocated');
finally
FConnectionHandle.Leave;
end;
end;
So, after a timeout (the Client is no longer answering) I call DisconnectClient:
function DisconnectClient(Call: string; Server: TDTBPort):boolean;
var
Index: integer;
List: TIdContextList;
i: integer;
begin
Result := false;
if Server = dpOne
then List := IdTCPServer1.Contexts.LockList
else List := IdTCPServer2.Contexts.LockList;
try
try
Index := -1;
for i := 0 to List.Count-1 do
begin
if TDTBClient(List[i]).Callsign = Call then
begin
inc(TDTBClient(List[i]).TryDisconnect);
Index := i;
break;
end;
end;
if Index >= 0 then
begin
result := true;
Log('DisconnectClient: Disconnecting: Callsign='+Call+' Port='+integer(Server).ToString+'. Index='+Index.ToString);
// TIdContext(List[Index]).Connection.Disconnect;
TIdContext(List[Index]).Connection.Socket.Binding.CloseSocket;
end else
begin
try
Log('DisconnectClient: Client not found in List Port '+integer(Server).ToString+': '+Call,d_warning);
except
// It may now be invalid.
end;
end;
except
on E:Exception do Log('DisconnectClient: '+E.Message,d_error);
end;
finally
if Server = dpOne then IdTCPServer1.Contexts.UnlockList else
if Server = dpTwo then IdTCPServer2.Contexts.UnlockList;
end;
end;
And in the case last night, the CloseSocket Log entries where not there. This means it never got past the "FConnectionHandle.Enter". Which is almost impossible, as this is only used twice: Once during Connect, and then during Disconnect. I have not been able to find any other references to this CriticalSection. Or, the whole 'Socket' was already invalid? But then I would have expected some Exception. And the log was clean for the last 12 hours.
The Timeout system then keeps calling DisconnectClient. Last night, after 169 times of this, the entire application died under Linux, directly after that call to CloseSocket. No other Log entries. One moment it was there, the next moment it had disappeared.
Any advise is welcome. I am desperate to get this fixed.