EMS Error when changing Databases on a query using RAD Server

370 Views Asked by At

I have been using RAD Server for a Time Clock application for our organization. Starting yesterday at around 7:00 AM, API calls to one of the companies started to fail with the following error message:

First chance exception at $00007FFAB7A24ED9. Exception class EHTTPProtocolException with message 'HTTP/1.1 500 Internal Server Error'. Process TGCTimeClock.exe (21552)
First chance exception at $00007FFAB7A24ED9. Exception class TCustomRESTResponse.EJSONValueError with message 'Response content is not valid JSON'. Process TGCTimeClock.exe (21552)
First chance exception at $00007FFAB7A24ED9. Exception class EEMSClientHTTPError with message 'EMS Error: <!DOCTYPE html PUBLIC "-//W3C//DTD XHTML 1.0 Strict//EN" "http://www.w3.org/TR/xhtml1/DTD/xhtml1-str'. Process TGCTimeClock.exe (21552)

Since I am running the Time Clock app for 2 separate companies, I pass a database name to my endpoints in order to access the correct data. The client side call is as follows:

      dmTimeClockClient.FDMTEmployee.Close;
      dmTimeClockClient.EMSFDClientEmployee.GetEndpoint.Params.Clear;
      dmTimeClockClient.EMSFDClientEmployee.Resource := 'TimeClock/GetEmployees';
      dmTimeClockClient.EMSFDClientEmployee.GetEndpoint.AddParameter('DEPARTMENT_ID', IntToStr(DepartmentID));
      dmTimeClockClient.EMSFDClientEmployee.GetEndpoint.AddParameter('Database', DBName);
      dmTimeClockClient.EMSFDClientEmployee.GetData;

      dmTimeClockClient.FDMTCostCenters.Close;
      dmTimeClockClient.EMSFDClientCostCenters.GetEndpoint.Params.Clear;
      dmTimeClockClient.EMSFDClientCostCenters.Resource := 'TimeClock/GetCostCenters';
      dmTimeClockClient.EMSFDClientCostCenters.GetEndpoint.AddParameter('DEPARTMENT_ID', IntToStr(DepartmentID));
      dmTimeClockClient.EMSFDClientCostCenters.GetEndpoint.AddParameter('Database', DBName);
      dmTimeClockClient.EMSFDClientCostCenters.GetData;

The server side procedures and queries are very straight forward:

procedure TdmTimeClock.GetCostCenters(const AContext: TEndpointContext; const ARequest: TEndpointRequest; const AResponse: TEndpointResponse);
var ms: TMemoryStream;
begin
  ms := TMemoryStream.Create;

  qryCostCenters.Close;
  qryCostCenters.ParamByName('DEPARTMENT_ID').Value := StrToInt(ARequest.Params.Values['DEPARTMENT_ID']);
  DBName := ARequest.Params.Values['Database'];
  qryCostCenters.Open;

  FDSACostCenters.SaveToStream(ms, TFDStorageFormat.sfJSON);

// Response owns stream
  AResponse.Body.SetStream(ms, 'application/vnd.embarcadero.firedac+json', True);
end;

procedure TdmTimeClock.GetEmployees(const AContext: TEndpointContext; const ARequest: TEndpointRequest; const AResponse: TEndpointResponse);
var ms: TMemoryStream;
begin
  ms := TMemoryStream.Create;

  qryEmpInfo.Close;
  qryEmpInfo.ParamByName('DEPARTMENT_ID').Value := StrToInt(ARequest.Params.Values['DEPARTMENT_ID']);
  DBName := ARequest.Params.Values['Database'];
  qryEmpInfo.Open;

  FDSAEmpInfo.SaveToStream(ms, TFDStorageFormat.sfJSON);

// Response owns stream
  AResponse.Body.SetStream(ms, 'application/vnd.embarcadero.firedac+json', True);
end;

In the before open event of the query I set the database parameters using an INI file as follows:

procedure TdmTimeClock.qryBeforeOpen(DataSet: TDataSet);
begin
  SetConnectionStr(FDConnectionSTIKS);
end;

procedure SetConnectionStr(var FDConnectionSTIKS: TFDConnection);
var ConfigIni: TInifile;
    DBServerName, Path: string;
begin
  Path := GetCurrentDir;
  ConfigIni := TIniFile.Create(System.IOUtils.TPath.Combine(Path, 'Config.ini'));
  DBServerName := ConfigIni.ReadString(AppNode, 'ServerName', 'ZEUS');

  with FDConnectionSTIKS.Params as TFDPhysMSSQLConnectionDefParams do
  begin
    DriverID := 'MSSQL';
    Server := DBServerName;
    Database := DBName;
    UserName := DBUserID;
    Password := DBPassword;
  end;

  ConfigIni.Free;
end;

I have googled the error message and it looks like the DOCTYPE information is somehow getting truncated as I found the following DOCTYPE example

DOCTYPE html PUBLIC "-I /W3C/ /DTD XHTML 1.0 Strict! /EN". "http://w.t.~.w3.org/TR/xhtml1/DTD/xhtml1-strict.dtd"

The "ict.dtd" is truncated on the error message.

I cannot find anywhere this DOCTYPE is defined or why it would be different for the one database. The tables being accessed are the same. I have 2 other 'Test' databases that work just fine. This started happening yesterday morning but there were no changes to the bpl or application. It looks like a Windows Update occurred on our IIS server around that time, though.

The other odd thing is that the first call to 'GetEmployees' is successful but the second call to GetCostCenters fails. If I comment out the call to GetEmployees, the call to GetCostCenters as well as subsequent similar calls still fail.

The IIS Log file has the following entries:

2021-07-20 14:09:24 192.168.1.162 GET /RADServer/EMSServer.dll/Security/Login Database=TR_WESTEK&USERNAME=lenm&PASSWORD=******** 80 - 216.123.235.214 Embarcadero+RESTClient/1.0 - 200 0 0 31
2021-07-20 14:10:04 192.168.1.162 GET /RADServer/EMSServer.dll/TimeClock/GetEmployees DEPARTMENT_ID=1&Database=TR_WESTEK 80 - 216.123.235.214 Embarcadero+RESTClient/1.0 - 200 0 0 46
2021-07-20 14:10:08 192.168.1.162 GET /RADServer/EMSServer.dll/TimeClock/GetCostCenters DEPARTMENT_ID=1&Database=TR_WESTEK 80 - 216.123.235.214 Embarcadero+RESTClient/1.0 - 500 0 0 93

Successful calls to the Test Database produce the following log entries:

2021-07-20 14:04:10 192.168.1.162 GET /RADServer/EMSServer.dll/Security/Login Database=WESTEK_TEST&USERNAME=lenm&PASSWORD=******** 80 - 216.123.235.214 Embarcadero+RESTClient/1.0 - 200 0 0 15
2021-07-20 14:04:20 192.168.1.162 GET /RADServer/EMSServer.dll/TimeClock/GetEmployees DEPARTMENT_ID=1&Database=WESTEK_TEST 80 - 216.123.235.214 Embarcadero+RESTClient/1.0 - 200 0 0 125
2021-07-20 14:04:35 192.168.1.162 GET /RADServer/EMSServer.dll/TimeClock/GetCostCenters DEPARTMENT_ID=1&Database=WESTEK_TEST 80 - 216.123.235.214 Embarcadero+RESTClient/1.0 - 200 0 0 46
2021-07-20 14:04:38 192.168.1.162 GET /RADServer/EMSServer.dll/TimeClock/GetShifts Database=WESTEK_TEST 80 - 216.123.235.214 Embarcadero+RESTClient/1.0 - 200 0 0 62
2021-07-20 14:04:38 192.168.1.162 GET /RADServer/EMSServer.dll/TimeClock/GetPayGroups Database=WESTEK_TEST 80 - 216.123.235.214 Embarcadero+RESTClient/1.0 - 200 0 0 62
2021-07-20 14:04:38 192.168.1.162 GET /RADServer/EMSServer.dll/TimeClock/GetPayPeriods Database=WESTEK_TEST&TaxYear=2020&PayGroupID=0 80 - 216.123.235.214 Embarcadero+RESTClient/1.0 - 200 0 0 46
2021-07-20 14:04:38 192.168.1.162 GET /RADServer/EMSServer.dll/TimeClock/GetAbsenteeCodes Database=WESTEK_TEST 80 - 216.123.235.214 Embarcadero+RESTClient/1.0 - 200 0 0 46
2021-07-20 14:04:38 192.168.1.162 GET /RADServer/EMSServer.dll/TimeClock/GetTimeClock DEPARTMENT_ID=1&START_DATE=07%2F20%2F2021&END_DATE=07%2F20%2F2021&Database=WESTEK_TEST 80 - 216.123.235.214 Embarcadero+RESTClient/1.0 - 200 0 0 62

Following is the try/except block I use:

    try
      dmTimeClockClient.FDMTEmployee.Close;
      dmTimeClockClient.EMSFDClientEmployee.GetEndpoint.Params.Clear;
      dmTimeClockClient.EMSFDClientEmployee.Resource := 'TimeClock/GetEmployees';
      dmTimeClockClient.EMSFDClientEmployee.GetEndpoint.AddParameter('DEPARTMENT_ID', IntToStr(DepartmentID));
      dmTimeClockClient.EMSFDClientEmployee.GetEndpoint.AddParameter('Database', DBName);
      dmTimeClockClient.EMSFDClientEmployee.GetData;

      dmTimeClockClient.FDMTCostCenters.Close;
      dmTimeClockClient.EMSFDClientCostCenters.GetEndpoint.Params.Clear;
      dmTimeClockClient.EMSFDClientCostCenters.Resource := 'TimeClock/GetCostCenters';
      dmTimeClockClient.EMSFDClientCostCenters.GetEndpoint.AddParameter('DEPARTMENT_ID', IntToStr(DepartmentID));
      dmTimeClockClient.EMSFDClientCostCenters.GetEndpoint.AddParameter('Database', DBName);
      dmTimeClockClient.EMSFDClientCostCenters.GetData;

      dmTimeClockClient.FDMTShifts.Close;
      dmTimeClockClient.EMSFDClientShifts.GetEndpoint.Params.Clear;
      dmTimeClockClient.EMSFDClientShifts.Resource := 'TimeClock/GetShifts';
      dmTimeClockClient.EMSFDClientShifts.GetEndpoint.AddParameter('Database', DBName);
      dmTimeClockClient.EMSFDClientShifts.GetData;

      dmTimeClockClient.FDMTPayGroups.Close;
      dmTimeClockClient.EMSFDClientPayGroups.GetEndpoint.Params.Clear;
      dmTimeClockClient.EMSFDClientPayGroups.Resource := 'TimeClock/GetPayGroups';
      dmTimeClockClient.EMSFDClientPayGroups.GetEndpoint.AddParameter('Database', DBName);
      dmTimeClockClient.EMSFDClientPayGroups.GetData;

      cbPayGroup.ItemIndex := 0;

      dmTimeClockClient.FDMTPayPeriods.Close;
      dmTimeClockClient.EMSFDClientPayPeriods.GetEndpoint.Params.Clear;
      dmTimeClockClient.EMSFDClientPayPeriods.Resource := 'TimeClock/GetPayPeriods';
      dmTimeClockClient.EMSFDClientPayPeriods.GetEndpoint.AddParameter('Database', DBName);
      dmTimeClockClient.EMSFDClientPayPeriods.GetEndpoint.AddParameter('TaxYear', cbTaxYear.ListBox.ListItems[cbTaxYear.ItemIndex].Text);
      dmTimeClockClient.EMSFDClientPayPeriods.GetEndpoint.AddParameter('PayGroupID', IntToStr(cbPayGroup.ListBox.ListItems[cbPayGroup.ItemIndex].Tag));
      dmTimeClockClient.EMSFDClientPayPeriods.GetData;

      dmTimeClockClient.FDMTAbsenteeCodes.Close;
      dmTimeClockClient.EMSFDClientAbsenteeCodes.GetEndpoint.Params.Clear;
      dmTimeClockClient.EMSFDClientAbsenteeCodes.Resource := 'TimeClock/GetAbsenteeCodes';
      dmTimeClockClient.EMSFDClientAbsenteeCodes.GetEndpoint.AddParameter('Database', DBName);
      dmTimeClockClient.EMSFDClientAbsenteeCodes.GetData;
    except
      on E: Exception do
      begin
        TThread.Synchronize(nil,
          procedure
          begin
            ShowMessageDlg('An Error Occured: ' + E.Message, ditInformation, MsgType);
          end);
      end;
    end;

The following is the a screen shot of the captured traffic for the successful and unsuccessful calls.

enter image description here

Successful Header

enter image description here

Unsuccessful Header

enter image description here

Following is the traffic when running straight from application. The call to GetCostCenters fails; As does any other subsequent calls. This first call to GetEmployees is always successful.

enter image description here

Following is the traffic when I use a browser to run the same call to a different database prior to my application executing the code. As long as I run the call from a browser to a different database, the call is successful.

enter image description here

I am running Windows 10, Rad Studio 10.4.2. My IIS Server 'Windows Server 2016'; IIS 10.

Any help would be greatly appreciated.

1

There are 1 best solutions below

0
Leonard M. On

Well, I managed to solve my problem. However, I have no idea why it suddenly started occurring or why it only affected one database. There was obviously an error occurring on the server side but I could not seem to get a legitimate error message. I finally tried to monitor the SQL queries using SQL Server Profiler.

What I discovered was that my Employee Query was getting executed with every other query. The reason for this is that the Employee Query was left Active on my server module. When I executed the GetCostCenters call, the Employee Query would get executed and then the Cost Center Query was executed. I assume an error was generated. I still do not know what the actual error message was.

This only occurred using IIS. When testing using localhost, the profiler did not show the Employee Query being executed multiple times.

Once I deactivated the Employee Query and installed the change to the IIS, everything worked as expected.

My thanks and apologies to those who responded.