FameFlower Test Results

Overview

Using the Carrier-io framework for capturing and analyzing performance test results, the following tests for the export instance UUIDs workflows were executed.

Backend:
- mod-inventory-storage-19.1.2
- mod-inventory-14.1.3
- mod-authtoken-2.4.0
- mod-permissions-5.9.0
- okapi-2.38.0

...

High Level Summary

• Most of failed requests were related to GET_/inventory/instances and GET_/instance-bulk/ids that use mod-inventory-storage service, even in a 1-user 30-min test run.
• mod-inventory-storage used significant memory on a machine with 8GB RAM to return 50K to 100K records.
• mod-inventory-storage was crashing a few times due to OutOfMemory exception during the test runs

• The workflow that retrieves more than 100K records became unresponsive even with 1 user

• The workflow with more than 5 users became unresponsive
• fasterxml.jackson.databind.ObjectMapper.readValue method of mod-inventory-storage service consumed high CPU resources as there were a lot of JSON decoding, this implementation could be reviewed for optimization possibilities.
• FOLIO performs better without being profiled when the tests are running 

Test Runs

30-min Runs for export instance UUIDs workflow:

...

Test

...

Virtual Users

...

Duration

...

OKAPI log level

...

Profiled

...

FameFlower Test Results

Overview

Using the Carrier-io framework for capturing and analyzing performance test results, the following tests for the export instance UUIDs workflows were executed.  The slowness depends on the number of records retrieved from the database, so we modeled the JMeter test scripts to make queries for a batch of keywords that return anywhere from 10K to 50K instances, and another batch of keywords that results in between 50K and 100K hits. Since these are resource-intensive operations, we did not test these scenarios with more than 5 concurrent users. 

The tests were ran with 1 and 5 user with queries which return 10K~50K instances and 50K~100K instances

Backend:
- mod-inventory-storage-19.1.2
- mod-inventory-14.1.3
- mod-authtoken-2.4.0
- mod-permissions-5.9.0
- okapi-2.38.0

Frontend:
- folio_inventory-2.0.2

Folio build was deployed with 50+ ECS services distributed randomly across four m5.large  EC2 instances and the database was created on the db.r5.xlarge AWS RDS instance. Logging level was set to default INFO.

High Level Summary

• Most of failed requests were related to GET_/inventory/instances and GET_/instance-bulk/ids that uses mod-inventory-storage, even in a 1-user 30-min test run. This is due to a combination of slow running queries, high memory usage when exporting more than 100K records.
• mod-inventory-storage used 99% of container memory on a machine with 8GB RAM to return 50K to 100K records.

  • The workflow that retrieves more than 100K records became non-responsive even with 1 user

  • The workflow with more than 5 users became non-responsive, indicative of exhausted memory usage.  Consider add more memory to mod-inventory-storage container.
• fasterxml.jackson.databind.ObjectMapper.readValue method of mod-inventory-storage consumed high CPU resources as there were a lot of JSON decoding, this implementation could be reviewed for optimization possibilities.
• Some mod-inventory-storage's SQL queries took more than 500ms to run, see the Slow Queries section and Recommended Improvements for the JIRAs created to address these SQL queries.
• mod-inventory-storage generated missing indexes warnings, see Recommended Improvements for the JIRAs that were created by this testing effort.

Test Runs

30-min Runs for export instance UUIDs workflow:

...

The following data shows memory consumption of ECS services, most notably of mod-inventory-storage during the 5 users and 10K-50K instances retrieved test run.Image Removed

Image Added

  Fig 3.1: mod-inventory-storage service consumed 99% of allocated RAM memory in the 5 users and 10K-50K instances retrieved test run.

...

Image Added

  Fig 3.1: mod-inventory-storage

...

Image Removed

Fig 3.2: In a 30 minutes test run mod-inventory-storage is shown 

4. Disk IO

Image Removed

Image Removed

5. Database CPU Utilization

For 1 user - 30 min run
Image Removed

For 5 users - 30 min run

...

6.  Database Slow queries

Slowest queries which took the most of execution time were initiated by the mod-inventory-storage service presented in the following table:

...

Percent of total time

...

Average Time,ms

...

Calls

...

Query

...

32%

...

10,796

...

15

SELECT jsonb,id FROM fs09000000_mod_inventory_storage.instance WHERE to_tsvector($1, f_unaccent(concat_space_sql(instance.jsonb->>$2 , concat_array_object_values(instance.jsonb->$3,$4) , concat_array_object_values(instance.jsonb->$5,$6)))) @@ (to_tsquery($7, f_unaccent($8))) ORDER BY left(lower(f_unaccent(instance.jsonb->>$9)),$10), lower(f_unaccent(instance.jsonb->>$11))

...

23%

...

22,250

...

5

...

service consumed 99% of allocated RAM memory in the 5 users and 50K-100K instances retrieved test run.

Note that when turning on the profiler on mod-inventory-storage, the performance took a nose dive and mod-inventory-storage crashed a few times in a 30 minutes test run. Obviously this put more stress on the module (and no one would run the profiler in production) but it's consistent with observations in bug fest environment that when returning more records, mod-inventory-storage would experience OOM exception and crashed.  What is seen here is mod-inventory-storage being at the edge of getting an OOM.

4. Disk IO

Image Added

Image Added

5. Database CPU Utilization

For 1 user - 30 min run
Image Added

For 5 users - 30 min run

Image Added
Database CPU usage was not high, but the queries took a long time to return, see below.

6.  Database Slow queries 

Anchor
slowQueries slowQueries

Slowest queries which took the most of execution time were initiated by the mod-inventory-storage service presented in the following table:

...

7.  Database Missing indexes

Image Removed

8. JVM Profiling result

JVM profiling of the most resources consuming mod-inventory-storage service showed 6 methods which had a high CPU usage and impact on the overall service performance.

Image Removed

fasterxml.jackson.databind.ObjectMapper.readValue method uses most of CPU capacity which leads to performance degradation

7.  Database Missing indexes 

Image Added

8. JVM Profiling result 

Anchor
profiling profiling

JVM profiling of the most resources consuming mod-inventory-storage service showed 6 methods which had a high CPU usage and impact on the overall service performance.

Image Added

fasterxml.jackson.databind.ObjectMapper.readValue method uses most of CPU capacity which leads to performance degradation

Image Added

Recommended improvement

Anchor
recommendedImprovements recommendedImprovements

Consider adding more memory to mod-inventory-storage container if there is a need to export over 100K UUIDs.

The following JIRAs are created for mod-inventory-storage missing indexes and 

Jira Legacy
server System JIRA serverId 01505d01-b853-3c2e-90f1-ee9b165564fc key MODINVSTOR-500

Appendix

See Attached FameFlower Performance Test Runs.xlsx for details