Overview

• This document contains the results of testing Data Import for MARC Bibliographic records with an update job in the Quesnelia release on qcp1 environments with Kafka consolidated topics and file splitting features enabled on a non-ecs environment.

PERF-832 - Getting issue details... STATUS  

Summary

• Data import tests finished successfully, only Test №5 had one failed record for Tenant 2(qcp1-01) when processed 50k files. Duration of DI grew in correspondence with the number of records in files.
• Check-in and Check-out with 5 virtual users was performed during DI Create new MARC authority records jobs for non-matches No issues.
• Data Import in Quesnelia without CICO perform faster than with it.
• Comparing Poppy and Quesnelia releases
  • Check-in / Check-out perform better in Quesnelia.  Response time improved during Create jobs for long period of work time on 15% in Average.
  • DI durations improved  - 11%-14% in Average.
• During testing, we noticed spikes in the mod permissions module. To mitigate this issue and prevent system slowdowns, we adjusted the order of loading files, starting with Tenant 3 (qcp1-02), followed by Tenant 2 (qcp1-01), and finally Tenant 1 (qcp1-00).

Test Results and Comparison

Test №1

Test with 1k, 10k, 25k and 50k records files DI started on one tenant only, and comparative results between Poppy and Quesnelia.

Test №2

Test with CICO 5 concurrent users and DI 1K, 5K, 10K, 25K and 50K started on one tenant only.

Test №3

Multitenant testing

File with 50K, 25K, 10K, 5K, 1K loaded sequences and launched on Tenant1, Tenant2, and Tenant3 for Poppy 

File with 50K, 25K, 10K, 5K, 1K loaded sequences and launched on Tenant3, Tenant2 and Tenant1 for Quesnelia

Test №4

Order for load files with pause between files: 50k, 25k, 10k, 5k, and 1k  for order tenants : Tenant 3(qcp1-02), Tenant 1(qcp1-00) and Tenant 2(qcp1-01)

Test №5

Order for load files without pause between files: 1k, 5k, 10k, 25k and 50k for order tenants : Tenant 3(qcp1-02), Tenant 2(qcp1-01) and Tenant 1(qcp1-00)

Service CPU Utilization

Here we can see that mod-inventory-b module used 50% CPU and mod-source-record-storage-b 46% CPU 

Service Memory Utilization

Here we can see that all modules show a stable trend.

DB CPU Utilization

DB CPU in the average was 90%.

DB Connections

DB connections was 1151.

DB load

Top SQL-queries

INSERT INTO fs09000000_mod_source_record_manager.events_processed (handler_id, event_id) VALUES ($1, $2)

INSERT INTO fs09000000_mod_source_record_manager.journal_records (id, job_execution_id, source_id, source_record_order, entity_type, entity_id, entity_hrid, action_type, action_status, error, action_date, title, instance_id, holdings_id, order_id, permanent_location_id, tenant_id) VALUES ($1, $2, $3, $4, $5, $6, $7, $8, $9, $10, $11, $12, $13, $14, $15, $16, $17)

insert into "marc_records_lb" ("id", "content") values (cast($1 as uuid), cast($2 as jsonb)) on conflict ("id") do update set "content" = cast($3 as jsonb)

WITH input_rows(record_id, authority_id) AS (
   VALUES ($1::uuid,$2::uuid)
)
, ins AS (
   INSERT INTO fs09000000_mod_inventory.records_authorities(record_id, authority_id)
   SELECT * FROM input_rows
   ON CONFLICT (record_id) DO UPDATE SET record_id=EXCLUDED.record_id
   RETURNING record_id::uuid, authority_id::uuid
   )
SELECT record_id, authority_id
FROM   ins
UNION  ALL
SELECT c.record_id, c.authority_id 
FROM   input_rows
JOIN   fs09000000_mod_inventory.records_authorities c USING (record_id);

UPDATE fs09000000_mod_source_record_manager.job_execution_progress SET succeeded_records_count = succeeded_records_count + $2, error_records_count = error_records_count + $3 WHERE job_execution_id = $1 Returning *

Service CPU Utilization

Here we can see that mod-inventory-b module and nginx-okapi used 50% CPU

Service Memory Utilization

Here we can see that all modules show a stable trend.

DB CPU Utilization

DB CPU was 93%.

DB Connections

DB connections was 1580.

DB load

Top SQL-queries

INSERT INTO fs09000000_mod_source_record_manager.events_processed (handler_id, event_id) VALUES ($1, $2)

INSERT INTO fs09000000_mod_source_record_manager.journal_records (id, job_execution_id, source_id, source_record_order, entity_type, entity_id, entity_hrid, action_type, action_status, error, action_date, title, instance_id, holdings_id, order_id, permanent_location_id, tenant_id) VALUES ($1, $2, $3, $4, $5, $6, $7, $8, $9, $10, $11, $12, $13, $14, $15, $16, $17)

UPDATE fs09000000_mod_source_record_manager.job_execution_progress SET succeeded_records_count = succeeded_records_count + $2, error_records_count = error_records_count + $3 WHERE job_execution_id = $1 Returning *

insert into "marc_records_lb" ("id", "content") values (cast($1 as uuid), cast($2 as jsonb)) on conflict ("id") do update set "content" = cast($3 as jsonb)

WITH input_rows(record_id, authority_id) AS (
   VALUES ($1::uuid,$2::uuid)
)
, ins AS (
   INSERT INTO fs09000000_mod_inventory.records_authorities(record_id, authority_id)
   SELECT * FROM input_rows
   ON CONFLICT (record_id) DO UPDATE SET record_id=EXCLUDED.record_id
   RETURNING record_id::uuid, authority_id::uuid
   )
SELECT record_id, authority_id
FROM   ins
UNION  ALL
SELECT c.record_id, c.authority_id 
FROM   input_rows
JOIN   fs09000000_mod_inventory.records_authorities c USING (record_id);

Service CPU Utilization

Here we can see that mod-inventory-b module used 57% CPU, mod-inventory-b used 43% CPU and mod-permissions-b spiked up to 150% CPU

Service Memory Utilization

Here we can see that all modules show a stable trend.

DB CPU Utilization

DB CPU was 95%.

DB Connections

DB connections was 1823.

DB load

Top SQL-queries

INSERT INTO fs07000002_mod_source_record_manager.events_processed (handler_id, event_id) VALUES ($1, $2)

INSERT INTO fs09000000_mod_source_record_manager.journal_records (id, job_execution_id, source_id, source_record_order, entity_type, entity_id, entity_hrid, action_type, action_status, error, action_date, title, instance_id, holdings_id, order_id, permanent_location_id, tenant_id) VALUES ($1, $2, $3, $4, $5, $6, $7, $8, $9, $10, $11, $12, $13, $14, $15, $16, $17)

INSERT INTO fs07000001_mod_source_record_manager.journal_records (id, job_execution_id, source_id, source_record_order, entity_type, entity_id, entity_hrid, action_type, action_status, error, action_date, title, instance_id, holdings_id, order_id, permanent_location_id, tenant_id) VALUES ($1, $2, $3, $4, $5, $6, $7, $8, $9, $10, $11, $12, $13, $14, $15, $16, $17)

INSERT INTO fs09000000_mod_source_record_manager.events_processed (handler_id, event_id) VALUES ($1, $2)

INSERT INTO fs07000001_mod_source_record_manager.events_processed (handler_id, event_id) VALUES ($1, $2)

Service CPU Utilization

Here we can see that mod-inventory-b module used 91% CPU, nginx-okapiused 44% CPU and mod-permissions-b spiked up to used 170% CPU

Service Memory Utilization

Here we can see that all modules show a stable trend.

DB CPU Utilization

DB CPU was 90%.

DB Connections

DB connections was 1450.

DB load

Top SQL-queries

INSERT INTO fs09000000_mod_source_record_manager.journal_records (id, job_execution_id, source_id, source_record_order, entity_type, entity_id, entity_hrid, action_type, action_status, error, action_date, title, instance_id, holdings_id, order_id, permanent_location_id, tenant_id) VALUES ($1, $2, $3, $4, $5, $6, $7, $8, $9, $10, $11, $12, $13, $14, $15, $16, $17)

INSERT INTO fs07000002_mod_source_record_manager.events_processed (handler_id, event_id) VALUES ($1, $2)

INSERT INTO fs09000000_mod_source_record_manager.events_processed (handler_id, event_id) VALUES ($1, $2)

INSERT INTO fs07000002_mod_source_record_manager.journal_records (id, job_execution_id, source_id, source_record_order, entity_type, entity_id, entity_hrid, action_type, action_status, error, action_date, title, instance_id, holdings_id, order_id, permanent_location_id, tenant_id) VALUES ($1, $2, $3, $4, $5, $6, $7, $8, $9, $10, $11, $12, $13, $14, $15, $16, $17)

INSERT INTO fs07000001_mod_source_record_manager.journal_records (id, job_execution_id, source_id, source_record_order, entity_type, entity_id, entity_hrid, action_type, action_status, error, action_date, title, instance_id, holdings_id, order_id, permanent_location_id, tenant_id) VALUES ($1, $2, $3, $4, $5, $6, $7, $8, $9, $10, $11, $12, $13, $14, $15, $16, $17)

Service CPU Utilization

Here we can see that mod-inventory-b module used 63% CPU in avarage, and mod-permissions-b spiked up to 130% CPU

Service Memory Utilization

Here we can see that all modules show a stable trend.

DB CPU Utilization

DB CPU was 90%.

DB Connections

DB connections was 1757.

DB load

Top SQL-queries

INSERT INTO fs09000000_mod_source_record_manager.events_processed (handler_id, event_id) VALUES ($1, $2)

INSERT INTO fs09000000_mod_source_record_manager.journal_records (id, job_execution_id, source_id, source_record_order, entity_type, entity_id, entity_hrid, action_type, action_status, error, action_date, title, instance_id, holdings_id, order_id, permanent_location_id, tenant_id) VALUES ($1, $2, $3, $4, $5, $6, $7, $8, $9, $10, $11, $12, $13, $14, $15, $16, $17)

INSERT INTO fs07000002_mod_source_record_manager.events_processed (handler_id, event_id) VALUES ($1, $2)

INSERT INTO fs07000001_mod_source_record_manager.journal_records (id, job_execution_id, source_id, source_record_order, entity_type, entity_id, entity_hrid, action_type, action_status, error, action_date, title, instance_id, holdings_id, order_id, permanent_location_id, tenant_id) VALUES ($1, $2, $3, $4, $5, $6, $7, $8, $9, $10, $11, $12, $13, $14, $15, $16, $17)

INSERT INTO fs07000002_mod_source_record_manager.journal_records (id, job_execution_id, source_id, source_record_order, entity_type, entity_id, entity_hrid, action_type, action_status, error, action_date, title, instance_id, holdings_id, order_id, permanent_location_id, tenant_id) VALUES ($1, $2, $3, $4, $5, $6, $7, $8, $9, $10, $11, $12, $13, $14, $15, $16, $17)

Appendix

Infrastructure

PTF - environment Quesnelia (qcp1)

• 10 db.r6g.xlarge EC2 instances located in US East (N. Virginia)us-east-1

• 1 database  instances, writer

  Name	Memory GIB	vCPUs
  db.r6g.xlarge	32 GiB	4 vCPUs

• MSK ptf-mobius-testing2
  
  • 4 m5.2xlarge brokers in 2 zones

  • Apache Kafka version 2.8.0

  • EBS storage volume per broker 300 GiB

  • auto.create.topics.enable=true
  • log.retention.minutes=480
  • default.replication.factor=3

Additional links and Errors

Test №5 had one failed record for Tenant 2(qcp1-01) when processed 50k files.

• 09:55:16 [526300/metadata-provider] [fs07000001] [] [mod-authtoken] ERROR Api Access for user 'folio' (9eb67301-6f6e-468f-9b1a-6134dc39a684) requires permission: metadata-provider.incomingrecords.get
• 09:55:16 [815600/metadata-provider] [fs07000001] [9eb67301-6f6e-468f-9b1a-6134dc39a684] [mod_source_record_manager] ERROR PostgresClient queryAndAnalyze: ERROR: invalid input syntax for type uuid: "undefined" (22P02) - SELECT * FROM get_record_processing_log('3e63f944-40ea-477c-ac21-79bb24780bc5', 'undefined')
• 09:55:16 [526300/metadata-provider] [fs07000001] [] [mod-authtoken] ERROR FilterApi Permission missing in []

Link to Jira ticket: https://folio-org.atlassian.net/browse/PERF-801

Also we used different order for Tenants when load files, we decided started load files from Tenant 3(qcp1-02) → Tenant 2(qcp1-01) → Tenant 1(qcp1-00) to avoid problem when mod-permissions spiked and  system stacked.

CPU Utilization when mod-permissions spiked and  system stacked.

CPU Utilization when mod-permissions spiked and  system stacked.

Methodology/Approach

DI tests scenario a data import job profile that creates new MARC authority records for non-matches (Job Profile: KG - Create SRS MARC Authority on nonmatches to 010 $a DUBLICATE for Q) were started from UI on Quesnelia (qcp1) env with  file splitting features enabled on a non-ecs environment.. 

• Action for non-matches:  Create MARC authority record 

• The above files are all stored here - MARC Resources
  - 22k file what was provided from MARC Resources  does nor work, so 50k file was split to file with 25k records and used instead of 22k file.
• At the time of the test run, Grafana was not available. As a result, response times for Check-In/Check-Out were parsed manually from a .jtl file, using the start and finish dates of the data import tests. These results were visualized in JMeter using a Listener (Response Times Over Time).

Test set

• Test 1: Manually tested 1k, 10k, 25k and 50k records files DI started on one tenant only.
• Test 2: Manually tested 1k, 10k, 25k and 50k records files DI started on one tenant only plus Check-in and Checkout (CICO) for 5 concurrent users.
• Test 3: Manually tested 1k, 10k, 25k and 50k records files DI started on 3 tenants concurrently. Order for load file without pause between files: 50k, 25k, 10k, 5k, and 1k for order tenants : Tenant 3(qcp1-02), Tenant 2(qcp1-01) and Tenant 1(qcp1-00)
• Test 4: Manually tested 1k, 10k, 25k and 50k records files DI started on 3 tenants concurrently. Order for load file with pause between files: 50k, 25k, 10k, 5k, and 1k for order tenants : Tenant 3(qcp1-02), Tenant 1(qcp1-00) and Tenant 2(qcp1-01)
• Test 5: Manually tested 1k, 10k, 25k and 50k records files DI started on 3 tenants concurrently. Order for load file without pause between files: 1k, 5k, 10k, 25k and 50k for order tenants : Tenant 3(qcp1-02), Tenant 2(qcp1-01) and Tenant 1(qcp1-00)