Overview

This document contains the results of testing Data Import for MARC Bibliographic records with create and update profiles and different file sizes (10K, 25K, 50K, 100K) at Sunflower release [ECS] and Critical service path 2(CSP2).
Ticket: https://folio-org.atlassian.net/browse/PERF-1219

Summary

• All Data-imports jobs finished successfully without errors.

• The duration of data imports for creates and updates has a noticeable improvement compared to CSP1
  (More detailes are in the report https://folio-org.atlassian.net/wiki/spaces/FOLIJET/pages/1200652289 )

  • CSP2 Updates are faster than CSP 1 likely due to a mod-search query that was running in CSP 1 (which created locking waits in the DB) not running in CSP 2.

  • CSP2’s Create imports MSK CPU utilizations are much lower compared to CSP 1 Create imports

• DI duration growth correlates with the number of records imported. 

• No memory leak is suspected for DI modules.

• Services CPU utilization, Service memory utilization, and DB CPU utilization have the same utilization trend and values as in previous reports

Recommendations & Jiras

1. Improve the performance of the SQL query that causes Lock on DB: https://folio-org.atlassian.net/browse/MODORDSTOR-491

2. Before running regression testing, please discuss the possibility of changing the contribution and subject field in MRC files that are used for DI to avoid this issue:
   https://folio-org.atlassian.net/browse/MSEARCH-972
   https://folio-org.atlassian.net/browse/MODDATAIMP-1242

Results

Testing results from previous reports
*-https://folio-org.atlassian.net/wiki/spaces/FOLIJET/pages/1200750594
*2-https://folio-org.atlassian.net/wiki/spaces/FOLIJET/pages/1289814018

Resource utilization graphs

CPU Utilization

Test 1.1 - 1.5 (5k-10k-25k-50k-100k)

Open

Test 2.1 - 2.5 (5k-10k-25k-50k-100k)

Open

Memory Utilization 

Memory utilisation showing stable trend, without spikes and drops. No signs for memory leaks.

Test 1.1 - 1.5 (5k-10k-25k-50k-100k)

Open

Test 2.1 - 2.5 (5k-10k-25k-50k-100k)

Open

RDS Metrics 

Test 1.1 - 1.5 (5k-10k-25k-50k-100k)

Open

Test 2.1 - 2.5 (5k-10k-25k-50k-100k)

Open

DB Connections

Test 1.1 - 1.5 (5k-10k-25k-50k-100k)

Open

Test 2.1 - 2.5 (5k-10k-25k-50k-100k)

Open

Performance insight metrics

Test 1.1 - 1.5 (5k-10k-25k-50k-100k)
High resource utilization of SELECT * FROM cs00000int_0001_mod_orders_storage.internal_lock WHERE lock_name = $1 FOR UPDATE is described in addtional section

Open

Open

Test 2.1 - 2.5 (5k-10k-25k-50k-100k)

Open

Open

MSK service

CPU usage by broker
Test 1.1 - 1.5 (5k-10k-25k-50k-100k) - Test 2.1 - 2.5 (5k-10k-25k-50k-100k)

Open

Disk usage by broker
Test 1.1 - 1.5 (5k-10k-25k-50k-100k) - Test 2.1 - 2.5 (5k-10k-25k-50k-100k)

Open

Additional information

Analysis of High Lock:tuple Wait Events on internal_lock Table

Executive Summary

The high database load observed during the test, specifically characterized by the Lock:tuple wait event, is expected behavior and not a performance defect. This load is intentionally generated by the mod-orders-storage service to ensure data consistency when processing audit events.

The behavior is the direct result of a pessimistic locking mechanism (SELECT FOR UPDATE) implemented as per the user story, "Implement lock mechanism for Outbox Event Log."

Detailed Analysis

1. Observed Symptom: The AWS Performance Insights dashboard shows a high number of Average Active Sessions (AAS) where the dominant wait event is Lock:tuple. This load is directly attributed to the following query: SELECT * FROM {tenant}_mod_orders_storage.internal_lock WHERE lock_name = ...

2. Design and Business Rationale: This lock is a deliberate design choice to solve a potential data integrity problem:

   • Function: The mod-orders-storage service reads events from an outbox_events table and sends them to Kafka for auditing (the "Outbox Pattern").

   • Problem: The system runs multiple instances of this service in parallel. Without a lock, two or more instances could read the same batch of events simultaneously and send duplicate audit messages to Kafka.

   • Solution: A distributed lock was implemented using a single row in the internal_lock table.

3. Mechanism of Action:

   • Before an instance of mod-orders-storage can read events, it must first execute a SELECT ... FOR UPDATE query on the internal_lock table.

   • The first instance to execute this query acquires an exclusive, row-level "tuple lock" on that row.

   • All other service instances that try to run the same query are forced to wait. This "waiting" state is what Performance Insights reports as the Lock:tuple wait event.

   • Once the first instance has finished processing its batch (reading events, sending to Kafka) and its transaction is complete, the lock is released. The database then grants the lock to the next waiting instance in the queue.

Conclusion 

The high Lock:tuple wait time is a direct and healthy sign that the locking mechanism is working as intended. It represents the time service instances spend "waiting in line" to process audit events sequentially.

This behavior is by design and essential for guaranteeing that audit events are sent to Kafka exactly once, preventing data duplication. It should be documented as an accepted system characteristic rather than a performance bottleneck to be fixed.

Feature: https://folio-org.atlassian.net/browse/UXPROD-3215

User Story: https://folio-org.atlassian.net/browse/MODORDSTOR-332  

Appendix

Infrastructure

PTF -environment secon

• 8 r7g.2xlarge EC2 instances located in US East (N. Virginia)us-east-1

• db.r7g.xlarge database instances, writer

• MSK fse-test

  • 4 kafka.m7g.xlarge brokers in 2 zones

  • Apache Kafka version 3.7.x (KRaft mode)

  • EBS storage volume per broker 300 GiB

  • auto.create.topics.enable=true

  • log.retention.minutes=480

  • default.replication.factor=3

Cluster Resources - secon-pvt