...

...

• 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.

JVM Profiling

Database

The following queries took more than 100ms to execute under load

The following table showing average CPU and memory percentages.CPU and Memory Utilization

...

Image RemovedGoldenrod test runs:

Image Added

Honeysuckle test runs:

Image Added

Clearly Okapi is using more CPU cycles in Honeysuckle than in Goldenrod, 1 user 

Other relevant modules' CPU utilizations in Goldenrod

Image Added

Same modules in Honeysuckle:

Image Added

A few things to note:

1. 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
2. mod-circulation's CPU utilization in Honeysuckle averages over 20% lower than in Goldenrod.
3. mod-circulation's CPU utilization in Honeysuckle is about 10-30% higher than in Goldenrod
4. mod-inventory's CPU utilization in Honeysuckle averages 30% more than in Goldenrod
5. mod-inventory-storage's CPU utilization in Honeysuckle averages 20% more than in Goldenrod 
6. mod-pubsub's CPU utilization in Honeysuckle is about 15% less than in Goldenrod
7. 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.

The slowest methods in Honeysuckle are once again the Logger and Jackson serialization methods

Image Added

Compared to Goldenrod:

Image Added

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.

Image Added

Image Added

Database

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

Honeysuckle's 

Image Added

Goldenrod's

Image Added

Honeysuckle's database memory utilization is much much better than Goldenrod's.  For the most part Honeysuckle's consecutive test runs did not produce signs of aggressive memory leaks that were seen in Goldenrod. 

Image Added

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

Image Added

Missing Indexes

Honeysuckle tests revealed the following missing indexes:

mod-circulation missing indexes

WARNING: Doing LIKE search without index for jsonb->>'requestId', CQL >>> SQL: requestId == 920e1d64-c221-48a0-a44d-ff50f3ad6cd6 >>> lower(f_unaccent(jsonb->>'requestId')) LIKE lower(f_unaccent('920e1d64-c221-48a0-a44d-ff50f3ad6cd6'))
WARNING: Doing FT search without index for request.jsonb->>'requesterId', CQL >>> SQL: requesterId = ae4c1cf3-0738-4465-8112-e75089e5b5c6 >>> get_tsvector(f_unaccent(request.jsonb->>'requesterId')) @@ tsquery_phrase(f_unaccent('ae4c1cf3-0738-4465-8112-e75089e5b5c6'))
WARNING: Doing FT search without index for request.jsonb->>'pickupServicePointId', CQL >>> SQL: pickupServicePointId = 7068e104-aa14-4f30-a8bf-71f71cc15e07 >>> get_tsvector(f_unaccent(request.jsonb->>'pickupServicePointId')) @@ tsquery_phrase(f_unaccent('7068e104-aa14-4f30-a8bf-71f71cc15e07'))
WARNING: Doing LIKE search without index for patron_action_session.jsonb->>'patronId', CQL >>> SQL: patronId == d7cabcb2-7431-43ea-a2cc-0dfe5bee17c6 >>> lower(f_unaccent(patron_action_session.jsonb->>'patronId')) LIKE lower(f_unaccent('d7cabcb2-7431-43ea-a2cc-0dfe5bee17c6'))
WARNING: Doing LIKE search without index for patron_action_session.jsonb->>'actionType', CQL >>> SQL: actionType == Check-out >>> lower(f_unaccent(patron_action_session.jsonb->>'actionType')) LIKE lower(f_unaccent('Check-out'))

The following warnings are captured when the background tasks are running

WARNING: Doing LIKE search without index for jsonb->'noticeConfig'>>'timing', CQL >>> SQL: noticeConfig.timing == After >>> lower(f_unaccent(jsonb>'noticeConfig'->>'timing')) LIKE lower(f_unaccent('After'))
WARNING: Doing LIKE search without index for jsonb->>'loanId', CQL >>> SQL: loanId == 671233fd-5c15-4f9e-8fab-f86330c389bd >>> lower(f_unaccent(jsonb->>'loanId')) LIKE lower(f_unaccent('671233fd-5c15-4f9e-8fab-f86330c389bd'))
WARNING: Doing LIKE search without index for jsonb->>'triggeringEvent', CQL >>> SQL: triggeringEvent == "Due date" >>> lower(f_unaccent(jsonb->>'triggeringEvent')) LIKE lower(f_unaccent('Due date'))

mod-feesfines missing indexes:

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'))

Appendix

CIRC-1014

https://issues.folio.org/browse/MODPATBLK-70

...