HTTPAPI Performance questions

Discussions related to HTTPAPI (An HTTP Client Package for RPG programming.) http://www.scottklement.com/httpapi/
assignment400
Posts: 12
Joined: Mon Aug 29, 2022 10:39 pm

HTTPAPI Performance questions

Post by assignment400 »

Scott,
I have developed my first program to consume a REST web service rendered by SAP. I am using HTTPAPI but not YAJL. The program is working as designed so results are good but there is a lag when the web service is consumed. What type of timing should I expect from the API's vs the delays while waiting for the web service to respond?

The times I am seeing are
- preparing to call is about .02 seconds
- Consuming the web service is between .8 to 5 seconds

3 fields are passed in addition to the header stuff: Code 1 = 3A, Part = 15A and the quantity (returned) = 25A.

I also see the first call takes longer than the rest of the calls.

I am trying to improve the 5 seconds.

Is there anything I should look at?

TIA, Darryl Freinkel.
assignment400
Posts: 12
Joined: Mon Aug 29, 2022 10:39 pm

Re: HTTPAPI Performance questions

Post by assignment400 »

The version should be current. I downloaded it in the past month.

<snippet>
request = '{'
+ wQQ
+ 'CustomerAccountNumber'
+ wQQ
+ ': "'
+ %trim(dsRequest.CustomerAccountNumber)
+ '", "AuthKey" : '
+ %trim(dsRequest.AuthKey)
+ ', "Parts": ['
+ wQQ
+ %trim(dsRequest.Part_no)
+ wQQ
+ ']'
+ '}';

monitor;
Response = http_string('POST': url : Request :
'application/json');
on-error;
wHttp_error = http_error();
endmon;

// return the result
</snippet>
Scott Klement
Site Admin
Posts: 635
Joined: Sun Jul 04, 2021 5:12 am

Re: HTTPAPI Performance questions

Post by Scott Klement »

assignment400 wrote: Wed Oct 12, 2022 10:18 pm The times I am seeing are
- preparing to call is about .02 seconds
- Consuming the web service is between .8 to 5 seconds
What is meant by "preparing to call" and "consuming the web service"? How are you deriving these numbers?
assignment400
Posts: 12
Joined: Mon Aug 29, 2022 10:39 pm

Re: HTTPAPI Performance questions

Post by assignment400 »

I have attached a copy of the logging I do in the program. I log a record when the program is called, when it calls the SAP program (web service), when SAP responds and when I return the data to the calling RPG program.

I made a small change this morning to do a RETURN and not set on LR and that helped some but the times are still about 3 seconds per call.

I am including the code here.

Code: Select all

      /if defined(*CRTBNDRPG)
         Ctl-Opt DFTACTGRP(*NO) ACTGRP('KLEMENT');
      /endif
       Ctl-Opt option(*srcstmt);
       // Ctl-Opt BNDDIR('HTTPAPI':'YAJL');
       Ctl-Opt BNDDIR('HTTPAPI');

      /include httpapi_h
      //include yajl_h


      // ----------------------------------------------------------
      // Procedure interface - passed Parameters
      // ----------------------------------------------------------

       dcl-pi json_05    extpgm;
         pCustomer          char(3);
         pPart_no           char(15);
         PQuantityAvailable Char(25);
       end-pi;

      // ----------------------------------------------------------
      // Local Variables
      // ----------------------------------------------------------

        Dcl-S uri               Varchar(5000);
        Dcl-S url               Varchar(2000);
        Dcl-S rc                Int(10);
        Dcl-S target            Char(3);
        Dcl-S result            varchar(2000);
        dcl-s request           varchar(2000);
        dcl-s response          varchar(200);
        Dcl-S wQQ               Char(1)    inz('"');
        dcl-s wScan_Found_at    int(10);
        dcl-s wField_Start      int(10);
        dcl-s wField_end        int(10);
        dcl-s wPart_No          char(15);
        dcl-s wQuantity_in      char(15);
        dcl-s wQuantity         int(5);
        dcl-s wMessage1         varchar(256);
        dcl-s wMessage2         varchar(256);
        dcl-s wMessage3         varchar(2000);
        Dcl-S wCmd              Char(3000);
        Dcl-S wCmdLen           Packed(15:0);
        dcl-s wTime_Called      timestamp;
        dcl-s wTime_SAP_Called  timestamp;
        dcl-s wTime_SAP_Responded timestamp;
        dcl-s wError            varchar(1000);
        dcl-s wHTTP_Error       varchar(2000);
        dcl-s wRcd_Type         like(Rcd_Type);
        dcl-s wCount            int(10);
        dcl-s wAccess_Key       char(30);

        //--------------------------------------------------------------
        //Program status Data structure
        //--------------------------------------------------------------

        Dcl-DS PgmStatus  PSDS;
          #Program       Char(10)   Pos(1);
          #dbLib         Char(10)   Pos(93);
          #job           Char(10)   Pos(244);
          #user          Char(10)   Pos(254);
          #job_number    char(6)    Pos(264);
        End-DS;


      // --------------------------------------------------------
      // data structures
      // --------------------------------------------------------

        Dcl-DS dsICLOGP  extname('ICLOGP');
        End-DS;

      // --------------------------------------------------------
      // REQUEST data structure
      // --------------------------------------------------------

        Dcl-DS dsRequest  qualified;
          CustomerAccountNumber Char(10);
          AuthKey        Char(128);
          Part_No        char(15);
        End-DS;
        // Dcl-DS dsPart  qualified ;
        //   Part_no        Char(20) dim(999);
        // End-DS;


      // --------------------------------------------------------
      // RECEIVED data structure
      // --------------------------------------------------------

        Dcl-DS dsResult  qualified;
          Dcl-DS dsParts  ;
            PartNumber     Char(20);
            AvailableQuantity Char(10);
            Price          Char(10);
            Message1       Char(256);
            Message2       Char(256);
          End-DS;
        End-DS;


      // --------------------------------------------------------
      // External Procedures
      // --------------------------------------------------------

        Dcl-PR QCMDEXC  ExtPgm('QCMDEXC');
          Cmd            Char(3000) Options(*varSize);
          CmdLen         Packed(15:5) Const;
          CmdDbcs        Char(3)    Const Options(*nopass);
        End-PR;

        // --------------------------------------------------------
        // Initialization
        // --------------------------------------------------------

        wTime_Called      = %timestamp();
        wRcd_Type         = '*Entry';
        wAccess_Key       = #job_number + %char(%TIMESTAMP());

        exsr log_Alert;
        exsr Initialize;

        // --------------------------------------------------------
        // REQUEST data structure
        // --------------------------------------------------------

         exec sql  set option closqlcsr = *endmod,
                              commit    = *none,
                              datfmt    = *ISO,
                              datsep    = '-',
                              timfmt    = *ISO,
                              naming    = *SYS,
                              alwcpydta = *yes;

        clear Request;
        clear Result;

        request = '{'
                + wQQ
                + 'CustomerAccountNumber'
                + wQQ
                + ': "'
                + %trim(dsRequest.CustomerAccountNumber)
                + '", "AuthKey" : '
                + %trim(dsRequest.AuthKey)
                + ', "Parts": ['
                + wQQ
                + %trim(dsRequest.Part_no)
                + wQQ
                + ']'
                + '}';

        // create the json

        // DATA-INTO  Request %data(dsRequest) %gen('YAJLDTAGEN');

        wTime_SAP_Called = %timestamp();
        wRcd_Type        = '*SAP Called';

        exsr Log_Alert;

        monitor;
          Response = http_string('POST': url : Request :
                                 'application/json');
        on-error;
          wHttp_error = http_error();
        endmon;

        // return the result

        wTime_SAP_Responded = %timestamp();
        wRcd_Type         = '*SAP Responded';

        exsr Log_Alert;

        // parse out the response

        wScan_Found_at = 0;
        wScan_Found_at = %scan('PartNumber':response:1);
        if wScan_Found_at <> 0;
          wTime_SAP_Responded = %timestamp();
          Exsr Parse_response;
        else;
          pQuantityAvailable = 'N/A';
        endif;

        wRcd_Type = '*Exit';

        Exsr Log_Alert;


        Return;  // *inlr = *on;

        // ----------------------------------------------------
        // Parse_Result into fields
        // ----------------------------------------------------

        begsr Parse_Response;

        // find the part number

        wScan_Found_at = %scan(':"':response:wScan_Found_at:wScan_Found_at);
        wField_Start   = wScan_Found_at + 2;
        wScan_Found_at = %scan('",':Response:wField_Start);
        wField_end     = wScan_Found_at - 1;
        wPart_No       = %subst(response : wField_Start :
                               (wField_end - wField_Start + 1 ));

        // find the quantity

        wScan_Found_at = 0;
        wScan_Found_at = %scan('AvailableQuantity":':response:1);
        if wScan_Found_at <> 0;
           wField_Start   = wScan_Found_at + 19;
           wScan_Found_at = %scan(',' : Response : wField_Start );
           wField_end     = wScan_Found_at - 1;
           wQuantity_in   = %subst(response :
                                   wField_Start :
                                  (wField_end - wField_Start + 1 ));
           if %subst(wQuantity_in:1:8) = '-99999.0';
              pQuantityAvailable = 'N/A';
           else;
              wQuantity          = %Int(wQuantity_in);
              pQuantityAvailable = %char(wQuantity);
           endif;

        else;
          pQuantityAvailable = 'N/A';
        endif;

        // find message 1

        wScan_Found_at = 0;
        wScan_Found_at = %scan('Message1"",' : response:1);

        if wScan_Found_at = 0;                            // no message
           wMessage1 = '';
        else;

          wScan_Found_at = %scan('Message1":"' : response:1);
          if wScan_Found_at <> 0;
             wField_Start   = wScan_Found_at + 11;
             wScan_Found_at = %scan('"",' : Response : wField_Start );
             wField_end     = wScan_Found_at - 1;
             wMessage1      = %subst(response :
                                     wField_Start :
                                    (wField_end - wField_Start + 1 ));
          else;
            pQuantityAvailable = 'N/A';
          endif;
        endif;

        // find message 2

        wScan_Found_at = 0;
        wScan_Found_at = %scan('Message2"",' : response:1);

        if wScan_Found_at = 0;                            // no message
           wMessage2 = '';
        else;

          wScan_Found_at = %scan('Message2":"' : response:1);
          if wScan_Found_at <> 0;
             wField_Start   = wScan_Found_at + 11;
             wScan_Found_at = %scan('"",' : Response : wField_Start );
             wField_end     = wScan_Found_at - 1;
             wMessage2      = %subst(response :
                                     wField_Start :
                                    (wField_end - wField_Start + 1 ));
          else;
            wMessage2          = 'N/A';
            pQuantityAvailable = 'N/A';
          endif;
        endif;

        // Find HTTP 400 and 500 Messages

        wScan_Found_at = 0;
        wScan_Found_at = %scan('ErrorMessage":null' : response:1);

        if wScan_Found_at = 0;                            // no message
           wMessage3 = '*None';
        else;

          wScan_Found_at = %scan('ErrorMessage":"' : response:1);
        if wScan_Found_at <> 0;
             wField_Start   = wScan_Found_at + 15;
             wScan_Found_at = %scan('"}' : Response : wField_Start );
             wField_end     = wScan_Found_at - 1;
             wMessage3      = %subst(response :
                                     wField_Start :
                                    (wField_end - wField_Start + 1 ));
          else;
            wMessage3          = '*None';
            // pQuantityAvailable = 'N/A';
          endif;
        endif;

        endsr;

        // ----------------------------------------------------
        // Initialization and setup.
        // ----------------------------------------------------

        begsr Initialize;

        // dsRequest.CustomerAccountNumber = '1000171';

        exec sql  Select  substr(refdat,1,7)
                    into  :dsRequest.CustomerAccountNumber
                    from  REFERP
                   where  REFCAT = 'SAP'
                     and  REFKEY = :pCustomer;

        if sqlcod <> 0;      // Record not found
           pQuantityAvailable = 'N/A';
           exec sql  insert into iclogp
                     (Vendor_drop_ship_code ,
                      PART_NO ,
                      RCVTIME ,
                      HTTPERROR ,
                      Alert_Sent,
                      Alert_Processed ,
                      RECORD_TYPE ,
                      QUANTITY_AVAILABLE ,
                      ACCESS_KEY ,
                      SND_SAP

                      )
               Values(:pCustomer ,
                      :pPart_No ,
                      Current Timestamp ,
                      'Customer record for VDS not found.',
                      '',
                      '' ,
                      '*Exit' ,
                      'N/A' ,
                      :wAccess_Key ,
                      :wTime_SAP_Called
                     );
           return;
        endif;

        // dsRequest.dsParts.Part_no       = '924-125';
        dsRequest.Part_no       = pPart_No;

        // Retrieve Authorization code from REFERP.

        // dsRequest.AuthKey  = '"TESTENV"';
        exec sql  Select  trim(refdat)
                    into  :dsRequest.AuthKey
                    from  REFERP
                   where  REFCAT = 'SAP'
                     and  REFKEY = 'AUTH_CODE';

        if sqlcod  = 0;      // Record found
          dsRequest.AuthKey = '"' + %trim(dsRequest.AuthKey) + '"';
        else;              // not found
           pQuantityAvailable = 'N/A';
           exec sql  insert into iclogp
                     (Vendor_drop_ship_code ,
                      PART_NO ,
                      RCVTIME ,
                      HTTPERROR,
                      RCD_TYPE ,
                      ACCESS_KEY
                      )
               Values(:pCustomer ,
                      :pPart_No ,
                      Current Timestamp ,
              'Authorization Code is invalid or does not exist in REFERP.',
                      '*Entry' ,
                      :wAccess_Key
                     );
           return;
        endif;

        // Validate the part number

        exec sql  Select  count(*)
                    into  :wCount
                    from  DE100M
                   where  IZPN   = :pPart_no;

        if wCount  = 0;                                    // Item number is invalid
           pQuantityAvailable = 'N/A';
           exec sql  insert into iclogp
                     (Vendor_drop_ship_code ,
                      PART_NO ,
                      RCVTIME ,
                      HTTPERROR,
                      RCD_TYPE ,
                      QUANTITY_AVAILABLE ,
                      ACCESS_KEY
                      )
               Values(:pCustomer ,
                      :pPart_No ,
                      :wTime_Called ,
                      'Invalid part number',
                      '*Exit' ,
                      'N/A' ,
                      :wAccess_Key
                     );
           return;
        endif;


        // http_setAuth( HTTP_AUTH_BASIC: 'apikey':'"TESTENV"');
        http_setAuth( HTTP_AUTH_BASIC: 'apikey' : dsRequest.AuthKey );

        http_debug(*on: '/tmp/json_05-debug.txt');
        uri = 'http://xxxxx/wwwww/api/'
            + 'ProductPriceAndAvailability';
        url = 'http://xxxxx/wwwww/DormanOrderingLibrary/api/'
            + 'ProductPriceAndAvailability';

        endsr;

        // ----------------------------------------------------
        // Log called in time
        // ----------------------------------------------------

        begsr Log_Alert;

        Select;
          when wRcd_Type = '*Entry';
            exec sql  Insert into ICLOGP
                      (VDS, PART_NO, QUANTITY_AVAILABLE,
                       RCVTIME, RCV_SAP, RPY2CALLER, WSREQUEST,
                       WSRESPONSE, HTTPERROR, RCD_TYPE,
                       ALERT_SENT, ALERT_PROCESSED, ACCESS_KEY)
                      Values( :pCustomer
                            , :pPart_No
                            , :pQuantityAvailable
                            , :wTime_Called         -- receive time
                            , :wTime_SAP_Called     -- time called SAP
                            , :wTime_SAP_Responded    -- time replied to caller
                            , :request
                            , :response
                            , :wHTTP_ERROR          -- http error
                            , :wRcd_Type
                            , ''                    -- Alert sent
                            , ''                    -- Alert processed
                            , :wAccess_Key
                            );

          when wRcd_Type = '*Exit';
            exec sql  update  ICLOGP
                         set  RCD_TYPE           = :wRcd_Type,
                              RPY2CALLER         = Current Timestamp ,
                              Quantity_Available = :pQuantityAvailable
                       where  ACCESS_KEY = :wAccess_Key;

          when wRcd_Type = '*SAP Called';
            exec sql  update  ICLOGP
                         set  RCD_TYPE  = :wRcd_Type,
                              SND_SAP   = Current Timestamp ,
                              WSREQUEST = :Request
                       where  ACCESS_KEY = :wAccess_Key;

          when wRcd_Type = '*SAP Responded';
            exec sql  update  ICLOGP
                         set  RCD_TYPE   = :wRcd_Type ,
                              RCV_SAP    = :wTime_SAP_Responded ,
                              WSRESPONSE = :Response
                       where  ACCESS_KEY = :wAccess_Key;

          other;
        endsl;
        endsr; // Log_Alert

        // ----------------------------------------------------
        //
        // ----------------------------------------------------
Attachments
ICIFC Logging - Copy.pdf
(130.47 KiB) Downloaded 172 times
assignment400
Posts: 12
Joined: Mon Aug 29, 2022 10:39 pm

Re: HTTPAPI Performance questions

Post by assignment400 »

I have attached a copy of the logging I do in the program. I log a record when the program is called, when it calls the SAP program (web service), when SAP responds and when I return the data to the calling RPG program.

I made a small change this morning to do a RETURN and not set on LR and that helped some but the times are still about 3 seconds per call.

I have attached a copy of the program.
Thank you.
jonboy49
Posts: 200
Joined: Wed Jul 28, 2021 8:18 pm

Re: HTTPAPI Performance questions

Post by jonboy49 »

Can you please edit the post to put code tags around the source so it is readable.
i.e. the word code in square brackets [ ] use /code to end it.

Code: Select all

    That will    produce correctly   spaced results like this    ssss
assignment400
Posts: 12
Joined: Mon Aug 29, 2022 10:39 pm

Re: HTTPAPI Performance questions

Post by assignment400 »

@jonboy49 - I am not sure I understand what you are requesting. Can you give an example? Thanks
jonboy49
Posts: 200
Joined: Wed Jul 28, 2021 8:18 pm

Re: HTTPAPI Performance questions

Post by jonboy49 »

I did! Look at what I said.
Here's a small extract of your source (with spacing added) wrapped in code tags

Code: Select all

// ----------------------------------------------------------
// Procedure interface - passed Parameters
// ----------------------------------------------------------

dcl-pi json_05 extpgm;
   pCustomer char(3);
   pPart_no char(15);
   PQuantityAvailable Char(25);
end-pi;
Either add them manually or just highlight the whole text and press the 5th from the left formatting button - the one with </> on it.

You will probably have to paste in your original code as all spacing has already gone. Assuming you do indent your code of course <grin>
Scott Klement
Site Admin
Posts: 635
Joined: Sun Jul 04, 2021 5:12 am

Re: HTTPAPI Performance questions

Post by Scott Klement »

I added the code tags for you, this time.

In the future, please post code like this (in the forum message editor):


[code]
/if defined(*CRTBNDRPG)
Ctl-Opt DFTACTGRP(*NO) ACTGRP('KLEMENT');
/endif
... etc ... rest of code here ...
[/code]


Placing [code] before the pasted code and [/code] after it will mark it in the forums as code, so it will retain it's spacing and be much easier to read.
Scott Klement
Site Admin
Posts: 635
Joined: Sun Jul 04, 2021 5:12 am

Re: HTTPAPI Performance questions

Post by Scott Klement »

To get more detail on what is happening, please use HTTPAPI's performance tracing.

To do that, code this near the start of the program:

Code: Select all

HTTP_setDebugLevel(2);
HTTP_Debug(*ON: '/tmp/assignment400_log.txt');
When you run your HTTP requests and reproduce the problem, a plethora of data should be logged to that IFS file, with timestamps indicating how long everything took. If you can send me a sample log showing the typical 3 second delay, I can interpret it to find out what HTTPAPI is doing during the time spent.

Be sure to remove any private information (including authorization: headers) prior to posting it publicly.
Post Reply