Table of Contents

outline	true

Overview

This is a report for a series of Check-in-check-out test runs against the Honeysuckle release.

Jira Legacy

server	System JiraJIRA
serverId	01505d01-b853-3c2e-90f1-ee9b165564fc
key	PERF-135

...

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

High Level Summary

Check-out: Honeysuckle is slower by 9%-28% than Goldenrod
Check-in: 4%-22% slower than Goldenrod
APIs turned slower in Honeysuckle: GET /automated-patron-blocks/{id} (150% slower) and GET /circulation/loans (60%). These are covered by MODPATBLK-70 and CIRC-1014, respectively
Okapi v4.3.3 seem to be using 2x-3x CPU cycles than in v1.3.2 (Goldenrod). Potential issue found with the logging methods OKAPI-964
mod-pubsub has a memory leak that would drag down performance under high loads (see section on longevity test): MODPUBSUB-136
Caching Okapi tokens in Okapi reduced mod-authtoken's CPU usage by over 90%
Database's memory usage improved dramatically from Goldenrod's - little memory consumptions observed.

Test Runs

Test	Virtual Users	Duration	OKAPI log level
1.	1	30 mins	INFO
2.	5	30 mins	INFO
3.	8	30 mins	INFO
4.	20	30 mins	INFO
5.	20	24 Hours	INFO

Results

Response Times

	Average (seconds)		50th %tile (seconds)		75th %tile (seconds)		95th %tile (seconds)
	Check-in	Check-out	Check-in	Check-out	Check-in	Check-out	Check-in	Check-out
1 user	0.967	1.989	0.889	1.832	0.984	2.201	1.254	2.815
5 users	1.053	2.171	0.981	1.969	1.114	2.253	1.528	3.370
8 users	1.193	2.244	1.076	2.022	1.339	2.372	1.895	3.544
20 users	2.391	3.901	1.639	3.073	2.263	4.12	4.811	8.784

...

Subsequent investigations (
Jira Legacy
server System JiraJIRA
serverId 01505d01-b853-3c2e-90f1-ee9b165564fc
key PERF-140
AND
Jira Legacy
server System JiraJIRA
serverId 01505d01-b853-3c2e-90f1-ee9b165564fc
key CIRC-1014
) on GET /circulation/loans do not show degradations by the API itself. We hypothesize that other API calls that were executed during the test run may have dragged down the response time, particularly if it was trying to read and write to the same rows in the database at the same time.

...

Services Modules Memory utilizations
- No modules exhibited memory leaks except for mod-pubsub
Although there were two instances of mod-pubsub running on two different ec2 instances, mod-pubsub's traffic seemed to have been stickied to one instance. Here are graphs showing mod-pubsub's on one instance using up memory and CPU resources, and on another instance not showing much activities:
- mod-pubsub and Okapi on another node - Okapi's CPU utilization dwindles while mod-pubsub does not seem to be busy at all

CPUs and Memories

Okapi was profiled because of the apparent 3x CPU utilization compared to the Goldenrod runs.

...

mod-authtoken uses much less CPU in Honeysuckle, over 90% reduction across all tests! This is because of the token caching functionality that was added to Okapi 4.x
mod-circulation's CPU utilization in Honeysuckle averages over 20% lower than in Goldenrod.
mod-circulation's CPU utilization in Honeysuckle is about 10-30% higher than in Goldenrod
mod-inventory's CPU utilization in Honeysuckle averages 30% more than in Goldenrod
mod-inventory-storage's CPU utilization in Honeysuckle averages 20% more than in Goldenrod
mod-pubsub's CPU utilization in Honeysuckle is about 15% less than in Goldenrod
mod-patron-blocks CPU utilization in Honeysuckle is at least 30% less than in Goldenrod

JVM Profiling

Because Okapi's CPU utilization in Honeysuckle seemed to have averaged 2x to 3x higher than in Goldenrod, it was profiled to get more insights of what happened inside it.

...

Note that the AbstractLogger.Info method in Okapi 4.3.3 total CPU time is about 3x higher than in Goldenrod. This is confirmed by Okapi 4.3.3's metrics showing ProxyContext.logRequest and ProxyContext.logResponse methods' response times degrade over time. These two methods need to be investigated.

Database

The database CPU utilizations are about the same between the Honeysuckle and Goldenrod

...

Goldenrod's memory profile shows quick claims of memory over 30 minutes tests runs.

Missing Indexes

Honeysuckle tests revealed the following missing indexes:

...

Code Block

WARNING: Doing LIKE search without index for accounts.jsonb->>'userId', CQL >>> SQL: userId == e96618a9-04ee-4fea-aa60-306a8f4dd89b >>> lower(f_unaccent(accounts.jsonb->>'userId')) LIKE lower(f_unaccent('e96618a9-04ee-4fea-aa60-306a8f4dd89b'))
WARNING: Doing LIKE search without index for accounts.jsonb->'status'>>'name', CQL >>> SQL: status.name <> Closed >>> lower(f_unaccent(accounts.jsonb>'status'->>'name')) NOT LIKE lower(f_unaccent('Closed'))
WARNING: Doing LIKE search without index for manualblocks.jsonb->>'userId', CQL >>> SQL: userId == a79b533d-8f29-4be1-9415-5f5cd936623b >>> lower(f_unaccent(manualblocks.jsonb->>'userId')) LIKE lower(f_unaccent('a79b533d-8f29-4be1-9415-5f5cd936623b'))

Results for okapi-4.5.2

Results for okapi-4.5.2 for 1,5,8,20 users for 30 minute run. From the response times below, the average Check-out for 20 users is slower. On average 60% slower than okapi-4.3.3.

'+' means performance improvement from okapi-4.3.3

'-' means performance degradation from okapi-4.3.3

For 20 users - 4 requests failed out of 113642

Response Times

	Average (seconds)		50th %tile (seconds)		75th %tile (seconds)		95th %tile (seconds)
	Check-in	Check-out	Check-in	Check-out	Check-in	Check-out	Check-in	Check-out
1 user	0.971	2.072	0.92	1.906	1.013	2.093	1.326	2.905
5 users	1.

003

092 +

2.

114

584 -

0.

925

978 +

1

2.

947

323 +

1.

055

16 +

2.

235

746 +

1.

458

622 +

3

4.

149

021 -
8 users	1.

217

429 -

2

3.

467

057 -

1.

099

285 -

2.

207

747 -

1.

357

62 -

2

3.

648

354 -

1

2.

931

415 -

4

5.

095

079 -

20 users

2

3.

409

073 +

5

7.

213

877 -

2.

141

595 +

4

6.

478

307 +

2

3.

763

411 +

5

8.

682

287 +

4

6.

233

409 +

8

14.

484

703 +