Versions Compared

Version Old Version 4 New Version 5
Changes made by

Varun Javalkar

Varun Javalkar

Saved on

Key

  • This line was added.
  • This line was removed.
  • Formatting was changed.

WORK IN PROGRESS

Jira Legacy
serverSystem Jira
columnskey,summary,type,created,updated,due,assignee,reporter,priority,status,resolution
serverId01505d01-b853-3c2e-90f1-ee9b165564fc
keyPERF-39

Table of Contents

Overview

...

WORK IN PROGRESS

Jira Legacy
serverSystem Jira
columnskey,summary,type,created,updated,due,assignee,reporter,priority,status,resolution
serverId01505d01-b853-3c2e-90f1-ee9b165564fc
keyPERF-39

Table of Contents

Overview

In this workflow, we are checking the performance of the renewal of loan items for the Goldenrod release.

We tested it with 1, 2 virtual users for 30 minutes.  

Backend:

  • mod-users-17.1.0
  • mod-users-bl-6.0.0
  • mod-authtoken-2.5.1
  • mod-permissions-5.11.2
  • mod-circulation-19.0.9
  • mod-circulation-storage-12.0.1
  • okapi-3.1.1

Environment:

  • 55 back-end modules deployed in 110 ECS services
  • 3 okapi ECS services
  • 8 m5.large  EC2 instances
  • 1  db.r5.xlarge AWS RDS instance
  • INFO logging level

High Level Summary

  1. On average POST_/circulation/renew-by-barcode API call takes average 671.12 seconds as we gradually increase the number of loans and users to 200 and 2 respectively.
  2. POST_/circulation/renew-by-barcode API barcode API makes 26 different API requests to gather userBarcode and itemBarcode information. 34% of those are calls are to mod-authtoken.
    see See Recommended Improvements for the JIRAs that were created/ covered by this testing effort.

...

API callGET rtac/${instanceId}

Test

Virtual Users

Duration

OKAPI log level

Profiled

Holdings per instance

Loans per User

1. 

1

30 min

WARNING

No

greater than 300

10, 50, 100, 200

2. 

52

30 min

WARNING

No

greater than 300

GET rtac/${instanceId}
3.130 minWARNINGOffgreater than 300

Mimic above call:

GET inventory/instances/${instanceId} → GET /holdings-storage/holdings → GET /inventory/items → GET /circulation/loans

4.530 minWARNINGOffgreater than 300

Mimic above call:

GET inventory/instances/${instanceId} → GET /holdings-storage/holdings → GET /inventory/items → GET /circulation/loans

Results

...

GET rtac/${instanceId}

...

10, 50, 100, 200

3.130 minINFONo10, 50, 100, 200


Results

  1. Renew all loans by barcode

    For 30 minutesLoansAverage Average POST_/circulation/renew-by-barcode
    1 user10

    6.52 seconds

    585.11 ms

    50

    31.81 seconds

    637.48 ms

    1001.06 minutes

    650.15 ms

    2002.09 minutes

    673.40 ms

    2 users10

    7.42 seconds

    683.76 ms

    50

    32.61 seconds

    686.65 ms

    100

    1.10 minutes

    705.37 ms

    200

    2.27 minutes

    747.04 ms



  2. Because there are no custom metrics inside mod-rtac to expose the wait time of each API call, we needed to mimic the rtac API logic by making subsequent calls to mod-inventory, mod-circulation to get open loans for greater than 300 holdings per instance in the JMeter script.  One caveat is that these calls are synchronous and are end-to-end (over the internet from JMeter to FOLIO) so naturally these API calls will be slower compared to the actual /rtac API calls from mod-rtac which were implemented asynchronously.  Therefore, the response times while are not likely what is seen by the code but should still give us a good idea of the cost of making n^3 API calls even if we take off some percentage for end-to-end over-the-wire latencies.


Calculations:

Total response time to get all holdings, items, open loans per instance(seconds) = time to get current instance + time to get all holdings 

...

time to get all loans = get current_loan * total loans


Get  an instance 

GET inventory/instances/${instanceId}

...


Profileravg(get all holdings per instance) + avg(get all items) + avg(get all loans) = Total average avg(get all holdings per instance) + avg(get all items) + avg(get all loans) = Total average 75th %tile
1 userON174 ms + 39 sec + 15.3 sec = 54.5 sec213 ms + 40.2 sec + 14.3 sec = 54.7 sec
1 userOFF73 ms + 34 sec + 14.3 sec = 48.4 sec86 ms + 40.2 sec + 12.3 sec = 52.6 sec
5 usersON179 ms + 49.3 sec + 17.7 sec = 67.2 sec223 ms + 51.6 sec + 18 sec = 70.1 sec
5 usersOFF71 ms + 42.9 sec + 14.9 sec = 57.840 ms + 42.6 sec + 15.6 sec = 58.2 sec



For each holding, get all items

GET /inventory/items?limit=2147483647&query=holdingsRecordId==${current_holding}

Profileravg(get current_item) * total items = Total average avg(get current_item) * total items = Total average 75th %tile
1 userON119 ms * 333 = 39 sec121 ms * 333 = 40.2 sec
1 userOFF104 ms * 333 = 34 sec106 ms * 333 = 35.2 sec
5 usersON148 ms * 333 = 49.3 sec155 ms * 333 = 51.6 sec
5 usersOFF129 ms * 333 = 42.9 sec128 ms * 333 = 42.6 sec



For each item, get all open loans

GET /circulation/loans?limit=2147483647&query=(itemId==${current_item} and status.name==Open)

...

The slowest query which took the most of execution time was initiated by the mod_inventory_storage service presented in the following table:


Percent of total time

Average Time, ms

Calls

Module

Query

77%14,632 ms21mod_inventory_storage

SELECT COUNT(*) FROM fs09000000_mod_inventory_storage.holdings_record

...


Recommended Improvements 
Anchor
recommendedImprovements
recommendedImprovements

  • The following JIRA has been created for mod-rtacauthtoken optimization:

...

Jira Legacy
serverSystem Jira
columnskey,summary,type,created,updated,due
,assignee,reporter,priority,status,resolutionserverId01505d01-b853-3c2e-90f1-ee9b165564fckeyMODRTAC-38

...

,assignee,reporter,priority,status,resolution
serverId01505d01-b853-3c2e-90f1-ee9b165564fc
keyMODAT-80

Appendix

See Attached rtac-test-report.xlsx for details