PTF -RTAC Workflow Test Report (Honeysuckle)

































PERF-117 - Getting issue details... STATUS

WIP

Work in progress...

Overview

PERF-117 - Getting issue details... STATUS was created to re-run RTAC performance test in the Honeysuckle environment which will verify performance issues reported by MODRTAC-38 - Getting issue details... STATUS

 We tested mod-rtac, edge-rtac with 1, 15, 20 virtual users for 15, 30 minutes with different combinations of instance size.

Backend:

  • mod-circulation-19.2.3
  • mod-circulation-storage-12.1.2
  • mod-inventory-storage-19.4.3
  • mod-inventory-16.1.0
  • okapi-4.2.2
  • mod-authtoken-2.6.0
  • mod-permissions-5.12.2

Environment:

  • 63 back-end modules deployed in 110 ECS services
  • 3 okapi ECS services
  • 10 m5.large  EC2 instances
  • 2 db.r5.xlarge AWS RDS instance (1 reader, 1 writer)

High Level Summary

  1. On average edge-rtac GET_/rtac?instanceIds=id1,id2,id3,idn API call takes 721.40 ms for 1 instance with 300+ holdings. This is an improvement from 17.5 seconds in Fameflower.
  2. On average mod-rtac POST_/rtac-batch API call takes 529 ms for 1 instance with 300+ holdings. This is an improvement from 17 seconds in Fameflower.
  3. On running mod-rtac POST_/rtac-batch API for more than 5 users for 15 minutes test run, mapping errors were seen. Please see MODRTAC-53 in recommended improvements below. 
  4. See Recommended Improvements for the JIRAs that were created/covered by this testing effort.

Test Runs

Test

Virtual Users

Duration

OKAPI metrics

Holdings per instance

API call

1. 

1

30 min

DISABLE

greater than 300

edge-rtac GET https://edge-honeysuckle-cap1.int.aws.folio.org/rtac?instanceIds=id1,id2,id3,id4,id5,id6,id7,id8,id9,id10&apikey={API_KEY}&fullPeriodicals=true

2. 

1

30 min

DISABLE

greater than 300

mod-rtac POST https://okapi-honeysuckle-cap1.int.aws.folio.org/rtac-batch
3.130 minDISABLE50 instances with a mix of 3,4,5,6,7 holdings per instanceedge-rtac GET https://edge-honeysuckle-cap1.int.aws.folio.org/rtac?instanceIds=id1,id2,id3,id4,id5,id6,id7,id8,id9,id10&apikey={API_KEY}&fullPeriodicals=true
4.130 minDISABLE50 instances with a mix of 3,4,5,6,7 holdings per instancemod-rtac GET https://okapi-honeysuckle-cap1.int.aws.folio.org/rtac-batch
5.2015 minENABLE50 instances with a mix of 3,4,5,6,7 holdings per instancemod-rtac POST https://okapi-honeysuckle-cap1.int.aws.folio.org/rtac-batch
6.1515 minENABLE50 instances with a mix of 3,4,5,6,7 holdings per instancemod-inventory-storage POST https://okapi-honeysuckle-cap1.int.aws.folio.org/inventory-hierarchy/items-and-holdings 
7.2015 minENABLE50 instances with a mix of 3,4,5,6,7 holdings per instancemod-inventory-storage POST https://okapi-honeysuckle-cap1.int.aws.folio.org/inventory-hierarchy/items-and-holdings 


Results

mod-rtac and inventory-hierarchy

A mod-rtac level request to get all open loans for greater than 300 holdings per instance

POST /rtac-batch for 30 minutesTotal InstancesTotal HoldingsAverage 75th %tile
1 user1333529 ms456 ms
1 user50mix of 3,4,5,6,72.57 seconds2.37 seconds

This test was run to exaggerate with 20 users to recreate an error from mod-rtac. Out of 50 instance lookups, 3 lookups failed with facade error mapping.

POST /rtac-batch for 15 minutesTotal InstancesTotal HoldingsAverage 75th %tile
2 user50mix of 3,4,5,6,72.97 seconds2.70 seconds
20 user50mix of 3,4,5,6,721.75 seconds31.37 seconds


Following errors were found in CloudWatch logs:

mod-rtac

2020-11-18T16:13:54.706-05:00	21:13:54 INFO FolioToRtacMapper Rtac handling periodicals: false
2020-11-18T16:13:54.706-05:00	21:13:54 INFO FolioToRtacMapper Rtac handling periodicals: false
2020-11-18T16:13:54.707-05:00	21:13:54 INFO FolioFacade Mapping inventory instances: 47
2020-11-18T16:13:54.707-05:00	21:13:54 INFO FolioFacade Mapping errors: 3
2020-11-18T16:13:54.707-05:00	21:13:54 INFO LogUtil org.folio.rest.RestVerticle start invoking postRtacBatch
2020-11-18T16:13:54.716-05:00	21:13:54 INFO LogUtil 127.0.0.1:44234 POST /rtac-batch null HTTP_1_1 200 338787 15258 tid=fs09000000 OK


10.23.10.246 - - [18/Nov/2020:21:20:10 +0000] "POST /mod-rtac/rtac-batch HTTP/1.1" 504 183 rt=599.997 uct="0.000" uht="600.001" urt="600.001" "Apache-HttpClient/4.5.6 (Java/1.8.0_232)" "fs09000000" "eyJhbGciOiJIUzI1NiJ9.eyJzdWIiOiJmb2xpbyIsInVzZXJfaWQiOiI5ZWI2NzMwMS02ZjZlLTQ2OGYtOWIxYS02MTM0ZGMzOWE2ODQiLCJtb2R1bGUiOiJtb2QtcnRhYy0yLjAuMSIsImV4dHJhX3Blcm1pc3Npb25zIjpbIlNZUyNtb2QtcnRhYy0yLjAuMSNcL3J0YWMtYmF0Y2gjW1BPU1RdIl0sInRlbmFudCI6ImZzMDkwMDAwMDAifQ.ifkt2jQFQauIXc2megNEB88qFYTCZmqZXcjGu2NE7yw" "{\x0D\x0A  \x22instanceIds\x22: [\x0D\x0A    \x2200009a0b-e973-443b-9796-c3373a352f86\x22,\x2200013259-9863-4259-910f-0d7ce90ff338\x22,\x2200017996-3315-4c35-a190-9ba05d845295\x22,\x2200020880-4d98-4875-94ef-bf2004ab67d8\x22,\x220002288a-59aa-4204-866e-7ffdd00fb96a\x22,\x2200042c9f-1019-4d65-9a75-d3a894507386\x22,\x22000516be-39ce-4fd8-8ac6-a45a4c3f702e\x22,\x2200052ca9-14f5-40bd-9a30-bb867a3436c2\x22,\x220005e0e3-5ecd-480b-96db-bab8ab8acff3\x22,\x2200062383-9abf-49c1-8b91-d6b989687ac4\x22,\x220012a59f-a16b-4a91-8c9c-a3d6b9fce816\x22,\x22001ac7b2-a57f-413d-bc30-64de99bac69c\x22,\x220020c571-e6e6-4dbc-a42f-fb8ba8728828\x22,\x220024a79a-bf95-47e9-8295-97ce9759c9c7\x22,\x2200278ebb-0cc3-4c8b-8373-7047096cc4a8\x22,\x2200280262-ac01-4159-b124-17e81cf4dd5e\x22,\x22002ae2e3-59b6-45f7-9b04-873fe03b7909\x22,\x22002b99a6-a75e-4444-ac43-574ea2207b84\x22,\x22003048f4-d47d-4206-a60c-b9b07526cf3a\x22,\x22003162f6-327b-41d2-8983-3fd32da1fb9a\x22,\x22000314cc-85a0-466b-83bc-e87abd73886a\x22,\x22000b35bf-9844-4c2e-bf27-e5aa62a911a4\x22,\x220010c364-fed3-467b-8145-19b48562dc68\x22,\x22001184f6-651d-4265-af5d-690194c31e45\x22,\x220042782b-8dca-4b0c-9dc5-5bde61d03095\x22,\x2200475cd9-d21a-427d-8f56-f3a53f1738b4\x22,\x220049dfb5-3947-405e-9491-c8cf5ae200ff\x22,\x22004e1405-ccda-4525-8e0e-1fd962696d8d\x22,\x2200541e48-6a59-407d-8d94-91fd6a78095e\x22,\x220061fce1-7973-4786-9251-a34944c6cdf9\x22,\x220011a8f1-efe4-44f0-9974-f94f2d6d204d\x22,\x220015fdae-66b1-4d7c-b896-1717b4339132\x22,\x22003d93a2-b27d-4fa4-9be1-50b8a0a80792\x22,\x220040a038-9ce4-451e-a608-cb98dd9edb35\x22,\x22006314ca-17b7-4c72-b760-b6186ad2ec1a\x22,\x22007f943c-6c20-45b8-8a81-d9b9e069f6db\x22,\x22009589d6-2644-4824-b343-5461aaea2d2e\x22,\x2200ae50af-33f7-4d7f-8632-4e6980ac8197\x22,\x2200b3bf8f-24d7-4178-8ceb-ec27c3ee039f\x22,\x2200b8ed0b-f265-499c-98fe-891ad8da4023\x22,\x22005a5bbb-8b80-4f3b-8be0-77021ff3ff56\x22,\x2200db8626-ece0-4b53-9120-b5220e27c491\x22,\x2200f8c674-6808-4d0b-a050-a385a5e345b5\x22,\x220121ebd1-351a-46ae-94c6-c7251bb1273c\x22,\x2201654b4f-a206-4153-af64-4afd2a357b6b\x22,\x2202038995-656d-4a87-8870-7dbf1fd5fe48\x22,\x2202235e2b-9a57-4175-9244-36bbe11beaf4\x22,\x22025e129b-1173-46f1-baa0-6f5ffca00b90\x22,\x220260fffd-3bbf-4664-8db1-e80405719601\x22,\x22030a018c-afe8-4f93-a883-581df5562194\x22\x0D\x0A  ]\x0D\x0A}\x0D\x0A\x0D\x0A"


mod-rtac calls inventory-hierarchy. To investigate the error for mod-rtac for concurrent users(2 or more), POST inventory-hierarchy/items-and-holdings API tests were run for 15 users and 20 users. No errors were reported.

POST inventory-hierarchy/items-and-holdings for 15 minutesTotal InstancesTotal HoldingsAverage 75th %tile
15 users50mix of 3,4,5,6,77.11 seconds7.23 seconds
20 users50mix of 3,4,5,6,79.34 seconds9.56 seconds

This proves that the issue is with mod-rtac and hence MODRTAC-53 - Getting issue details... STATUS was created.

edge-rtac

An edge-rtac level request to get all open loans for greater than 300 holdings per instance

GET /rtac for 30 minutesTotal InstancesTotal HoldingsAverage 75th %tile
1 user1333721 ms500 ms
1 user50mix of 3,4,5,6,72.58 seconds2.52 seconds

Slow Queries

1 instance with 333 holdings

Percent of total time

Average Time, ms

Module

Query

60%188 msmod_inventory_storage

select * from get_items_and_holdings_view($1,$2)

50 instances with a mix of 3,4,5,6,7 holdings per instance

Percent of total time

Average Time, ms

Module

Query

58%977 msmod_inventory_storage

select * from get_items_and_holdings_view($1,$2)


RDS CPU Utilization

1 user 1 instance with 333 holdings. CPU is around 24% which is normal.

1 user 50 instances with a mix of 3,4,5,6,7 holdings per instance. CPU is around 27% which is normal.

15 users, 20 users 50 instances with a mix of 3,4,5,6,7 holdings per instance. CPU is close to 100% which is high because DB was fired with 15, 20 different users. This run involved 504 errors from mod-rtac. These many numbers of concurrent users are rare and will not happen in production.