WORK IN PROGRESS
...
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
...
Test | Virtual Users | Duration | OKAPI log level | Profiled | Loans per User |
1. | 1 | 30 min | WARNING | No | 10, 50, 100, 200 |
2. | 2 | 30 min | WARNING | No | 10, 50, 100, 200 |
| 3. | 1 | 30 min | INFO | No | 10, 50, 100, 200 |
Results
Renew all loans by barcode
For 30 minutes Loans Average Average Renew all loans (Average) POST_/circulation/renew-by-barcode (Average) 1 user 10 6.52 seconds
585.11 ms
50 31.81 seconds
637.48 ms
100 1.06 minutes 650.15 ms
200 2.09 minutes 673.40 ms
2 users 10 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
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 holdings = get all holdings per instance + time to get all items + time to get all loans
time to get all items = get current_item * total items
time to get all loans = get current_loan * total loans
Get an instance
GET inventory/instances/${instanceId}...
For each instance, get all holdings
GET /holdings-storage/holdings?limit=2147483647&query=instanceId==${instanceId}...
For each holding, get all items
GET /inventory/items?limit=2147483647&query=holdingsRecordId==${current_holding}...
For each item, get all open loans
GET /circulation/loans?limit=2147483647&query=(itemId==${current_item} and status.name==Open)
...
Below is the dependency graph generated from Giraffe for POST_/circulation/renew-by-barcode API. It shows individual calls made by renew-by-barcode to gather prerequisite information from different APIs such as item-storage, location-units, loan-types, request-storage, notice-policy, locations and mod-authtoken.
JVM Profiling
- Overall slow methods (between the modules profiled: mod-rtac, mod-circulation, mod-circulation-storage, mod-inventory, mod-inventory-storage)
...
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 |
...
Recommended Improvements
| Anchor | ||||
|---|---|---|---|---|
|
- The following JIRA has been created for mod-authtoken optimization:
Jira Legacy server System Jira columns key,summary,type,created,updated,due,assignee,reporter,priority,status,resolution serverId 01505d01-b853-3c2e-90f1-ee9b165564fc key MODAT-80
Appendix
See Attached rtac-test-report.xlsx for details