Delphi Indy 10 client has 10 second delay when upgrading from 10.2 to 10.4

127 Views Asked by At

Our company develops a Point of Sale system that supports various credit card transation providers. It has a JavaScript web client front end and a Delphi server back end. It uses Indy 10 heavily for HTTP communication.

One of our platforms we support is Adyen. I have developed a plugin that uses Indy 10's HTTP client to connect to an Adyen EFT device running a server which performs credit card transactions, communicating with a back end server on the WWW. I have this working reliably in Delphi 10.2. This year we upgraded to Delphi 10.4, and I find that there is now a considerable delay in the response time of Indy 10 requests to the device, on the order of 10 seconds per request.

Using the OnWorkBegin, OnWork and OnWorkEnd events (with handler methods named HTTPWorkBegin, HTTPWork, and HTTPWorkEnd respectively), I was able to log the timing of the request in Delphi 10.4. From this I discovered that a 10 second delay (nearly to the millisecond) occurs on the request read between the end of the HTTPWork method and the beginning of the HTTPWorkEnd method.

2021.08.12.16.13.36.889  [  5940] +Info  | https://10.50.100.53:8443/nexo/
2021.08.12.16.13.36.890  [  5940] +Info  | POST begin
2021.08.12.16.13.38.904  [  5940] >Enter | TAdyenDisplay.HTTPWorkBegin
2021.08.12.16.13.38.930  [  5940] @Debug | WorkMode = Write; WorkCountMax = 1146
2021.08.12.16.13.38.931  [  5940] <Exit  | TAdyenDisplay.HTTPWorkBegin
2021.08.12.16.13.38.932  [  5940] >Enter | TAdyenDisplay.HTTPWork
2021.08.12.16.13.38.933  [  5940] @Debug | WorkMode = Write; WorkCount = 1146
2021.08.12.16.13.38.933  [  5940] <Exit  | TAdyenDisplay.HTTPWork
2021.08.12.16.13.38.934  [  5940] >Enter | TAdyenDisplay.HTTPWorkEnd
2021.08.12.16.13.38.935  [  5940] @Debug | WorkMode = Write
2021.08.12.16.13.38.936  [  5940] <Exit  | TAdyenDisplay.HTTPWorkEnd
2021.08.12.16.13.39.221  [  5940] >Enter | TAdyenDisplay.HTTPWorkBegin
2021.08.12.16.13.39.222  [  5940] @Debug | WorkMode = Read; WorkCountMax = 0
2021.08.12.16.13.39.223  [  5940] <Exit  | TAdyenDisplay.HTTPWorkBegin
2021.08.12.16.13.39.223  [  5940] >Enter | TAdyenDisplay.HTTPWork
2021.08.12.16.13.39.224  [  5940] @Debug | WorkMode = Read; WorkCount = 973
2021.08.12.16.13.39.225  [  5940] <Exit  | TAdyenDisplay.HTTPWork   ---ten second delay--
2021.08.12.16.13.49.220  [  5940] >Enter | TAdyenDisplay.HTTPWorkEnd
2021.08.12.16.13.49.221  [  5940] @Debug | WorkMode = Read
2021.08.12.16.13.49.222  [  5940] <Exit  | TAdyenDisplay.HTTPWorkEnd
2021.08.12.16.13.49.223  [  5940] +Info  | POST end
2021.08.12.16.13.49.223  [  5940] +Info  | Elapsed Time: 12 seconds

Comparing this to the same request running in Delphi 10.2, the log indicates no delay:

2021.08.13.17.24.40.916   [9724]    Information    https://10.50.100.53:8443/nexo/
2021.08.13.17.24.40.917   [9724]    Information    POST begin
2021.08.13.17.24.42.373   [9724]    >> Entry >>    TAdyenDisplay.HTTPWorkBegin
2021.08.13.17.24.42.373   [9724]    Information    WorkMode = Write; WorkCountMax = 1146
2021.08.13.17.24.42.374   [9724]    << Exit  <<    TAdyenDisplay.HTTPWorkBegin
2021.08.13.17.24.42.374   [9724]    >> Entry >>    TAdyenDisplay.HTTPWork
2021.08.13.17.24.42.375   [9724]    Information    WorkMode = Write; WorkCount = 1146
2021.08.13.17.24.42.375   [9724]    << Exit  <<    TAdyenDisplay.HTTPWork
2021.08.13.17.24.42.376   [9724]    >> Entry >>    TAdyenDisplay.HTTPWorkEnd
2021.08.13.17.24.42.376   [9724]    Information    WorkMode = Write
2021.08.13.17.24.42.377   [9724]    << Exit  <<    TAdyenDisplay.HTTPWorkEnd
2021.08.13.17.24.42.506   [9724]    >> Entry >>    TAdyenDisplay.HTTPWorkBegin
2021.08.13.17.24.42.507   [9724]    Information    WorkMode = Read; WorkCountMax = 0
2021.08.13.17.24.42.508   [9724]    << Exit  <<    TAdyenDisplay.HTTPWorkBegin
2021.08.13.17.24.42.559   [9724]    >> Entry >>    TAdyenDisplay.HTTPWork
2021.08.13.17.24.42.559   [9724]    Information    WorkMode = Read; WorkCount = 975
2021.08.13.17.24.42.560   [9724]    << Exit  <<    TAdyenDisplay.HTTPWork
  --no significant delay--
2021.08.13.17.24.42.561   [9724]    >> Entry >>    TAdyenDisplay.HTTPWorkEnd
2021.08.13.17.24.42.561   [9724]    Information    WorkMode = Read
2021.08.13.17.24.42.562   [9724]    << Exit  <<    TAdyenDisplay.HTTPWorkEnd
2021.08.13.17.24.42.562   [9724]    Information    POST end
2021.08.13.17.24.42.563   [9724]    Information    Elapsed Time: 1 seconds

I am baffled what could be the difference. Any ideas would be appreciated.

0

There are 0 best solutions below