| Jira Legacy | ||||||||
|---|---|---|---|---|---|---|---|---|
|
...
In this api, we are checking the performance of RTAC workflow running in the Fameflower release -
We tested it with 1, 5 virtual users for 30 minutes.
Backend:
- mod-circulation-18.0.9
- mod-circulation-storage-11.0.0
- mod-inventory-storage-19.1.2
- mod-inventory-14.1.3
- okapi-2.38.0
- mod-authtoken-2.4.0
- mod-permissions-5.9.0
...
Test | Virtual Users | Duration | OKAPI log level | Profiled | Holdings per instance | API call |
1. | 1 | 30 min | WARNING | No | greater than 300 | GET rtac/${instanceId} |
2. | 5 | 30 min | WARNING | No | greater than 300 | GET rtac/${instanceId} |
| 3. | 1 | 30 min | WARNING | Off | greater than 300 | Mimic above call: GET inventory/instances/${instanceId} → GET /holdings-storage/holdings → GET /inventory/items → GET /circulation/loans |
| 4. | 5 | 30 min | WARNING | Off | greater than 300 | Mimic above call: GET inventory/instances/${instanceId} → GET /holdings-storage/holdings → GET /inventory/items → GET /circulation/loans |
Results
- A rtac-level request to get all open loans for greater than 300 holdings per instance
GET rtac/${instanceId}
For 30 minutes Profiler Average 75th %tile 1 user ON 17.62 seconds 25.47 seconds 1 user OFF 15.44 seconds 20.99 seconds 5 users ON 47.53 seconds 55.01 seconds 5 users OFF 42.06 seconds 49.61 seconds 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}...
| Profiler | avg(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 user | ON | 174 ms + 39 sec + 15.3 sec = 54.5 sec | 213 ms + 40.2 sec + 14.3 sec = 54.7 sec |
| 1 user | OFF | 73 ms + 34 sec + 14.3 sec = 48.4 sec | 86 ms + 40.2 sec + 12.3 sec = 52.6 sec |
| 5 users | ON | 179 ms + 49.3 sec + 17.7 sec = 67.2 sec | 223 ms + 51.6 sec + 18 sec = 70.1 sec |
| 5 users | OFF | 71 ms + 42.9 sec + 14.9 sec = 57.8 | 40 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}| Profiler | avg(get current_item) * total items = Total average | avg(get current_item) * total items = Total average 75th %tile | |
| 1 user | ON | 119 ms * 333 = 39 sec | 121 ms * 333 = 40.2 sec |
| 1 user | OFF | 104 ms * 333 = 34 sec | 106 ms * 333 = 35.2 sec |
| 5 users | ON | 148 ms * 333 = 49.3 sec | 155 ms * 333 = 51.6 sec |
| 5 users | OFF | 129 ms * 333 = 42.9 sec | 128 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 ms | 21 | mod_inventory_storage | SELECT COUNT(*) FROM fs09000000_mod_inventory_storage.holdings_record |
...
This difference below between API and Postgresql query response time is the sum of network time to/back from calling database, deserialization of JSON string into JSON objects, processing time, and network time to/from API. Below are a single API request and SQL query triggered manually for comparison.
| Action | Type of Request | Actual request | Time, ms |
|---|---|---|---|
| get Instance | SQL query | select * from fs09000000_mod_inventory_storage.instance where id = '00009a0b-e973-443b-9796-c3373a352f86'; | 305 |
| API request | https:/{okapi-url}/inventory/instances/00009a0b-e973-443b-9796-c3373a352f86 | 368 | |
| get holdings | SQL query | select * from fs09000000_mod_inventory_storage.holdings_record hr1 where hr1.instanceid = '121063ba-43cc-48f4-a49f-aaf5488127e0'; | 350 |
| API request | https:/{okapi-url}/holdings-storage/holdings?limit=2147483647&query=instanceId==121063ba-43cc-48f4-a49f-aaf5488127e | 503 | |
| get Item | SQL query | select * from fs09000000_mod_inventory_storage.item where holdingsrecordid='95a897e5-2505-4803-a7f1-7da39c9f67cb'; | 353 |
| API request | https://{okapi-url}/inventory/items?limit=2147483647&query=holdingsRecordId%3D%3D95a897e5-2505-4803-a7f1-7da39c9f67cb | 662 | |
| get Open loan | SQL query | select * from fs09000000_mod_circulation_storage.loan where jsonb->>'itemId'='3faad467-fca1-41c8-ad7d-af1dcd3fdc3c' AND jsonb->'status'->>'name'='Open'; | 372 |
| API request | https://{okapi-url}/circulation/loans?limit=2147483647&query=(itemId==3faad467-fca1-41c8-ad7d-af1dcd3fdc3c and status.name==Open) | 400 |
...
Recommended Improvements
| Anchor | ||||
|---|---|---|---|---|
|
- The following JIRA has been created for mod-rtac:
JiraJira Legacy server System JIRA columns key,summary,type,created,updated,due,assignee,reporter,priority,status,resolution serverId 01505d01-b853-3c2e-90f1-ee9b165564fc key MODRTAC-38
- Consider taking advantage of CQL "OR" operator to chain IDs together at each level of getting items, holdings, loans, instead of making API calls. This approach could be faster, although need to be proven.
- Consider doing SQL joins between instance/holdings/items where possible to reduce making API and database calls.
- In mod-circulation, mod-circulation-storage, mod-inventory-storage, consider using a more efficient JSON package or call using the existing Jackson serialization calls in a different way to address the item: JVM profiling shows JSON de/serialization operations one of the slowest operations.
...