Skip to end of metadata
Go to start of metadata

IN PROGRESS

Overview

Per PERF-267 - Getting issue details... STATUS the following tests were performed using the data export workflow (eHoldings, bulk edits, and edifacts) to determine what happens to the export workflows when mod-data-export-worker (with one node) fails and to what load can the exports be run successfully. 

Infrastructure

PTF -environment

  • 10 m6i.2xlarge EC2 instances  (changed. In Lotus it was m5.xlarge)
  • 2 instances of db.r6.xlarge database instances, one reader and one writer
  • MSK
    • 4 m5.2xlarge brokers in 2 zones
    • auto.create-topics.enable = true
    • log.retention.minutes=120
    • 2 partitions per DI topics
  • okapi (running tasks -3)
    • 1024 CPU units, 1360 MB mem
  • mod-users (running tasks -2) 
    • 128 CPU units, 896 MB mem
  • mod-data-export (running tasks -1) 
    • 1024 CPU units, 896 MB mem
  • mod-data-export-spring (running tasks -1) 
    • 256 CPU units, 1844 MB mem
  • mod-data-export-worker (running tasks -1) 
    • 256 CPU units, 1844 MB mem
  • mod-notes (running tasks -2) 
    • 128 CPU units, 896 MB mem
  • mod-agreements (running tasks -2) 
    • 128 CPU units, 1382 MB mem


Software Versions

  • mod-data-export-worker: 1.5.0-SNAPSHOT.54
  • mod-data-export-spring: 1.4.2
  • mod-agreements: 5.2.1
  • mod-notes: 3.1.0
  • mod-users: 18.3.0

Test Runs (initial assumption of the data sets for combo testing)

Bulk edit files are located in: Performance testing data Google Drive

Test Run

Duration

EdifacteHoldings

Bulk-edit

user barcodes

Bulk edit

item barcodes

Bursar

(optional)

Circulation logs (optional)Memory Behavior (Trend)Comment

Record identifier files

 name (bulk edit)
Time to process Results

#1

1-time checkExport 10 orders with 5 order lines each for 1 organization integration. 50 order lines exported to 1 .edi file

Export a "Package" record with small number of "Titles" (<1.000)

https://ptf-rmb.int.aws.folio.org/eholdings/packages/228-1126892 (744)

100 records

file name 100-user-barcodes.csv

100 records

file name 100-item-barcodes.csv








#2

1-time checkExport 10 orders for each account number with 10 order lines each. Each account represents a different organization integration. Meaning 100 order lines exported to 10 different .edi files

Export a "Package" record with close to limit number of "Titles" (between 9.000 and 10.000) without assigned "Notes" records

https://ptf-rmb.int.aws.folio.org/eholdings/packages/413-2605025 (9073)


1 000 records

file name 1000-user-barcodes.csv

1 000 records

file name 1000-item-barcodes.csv








#3

1-time checkExport 100 orders for each account number with 10 order lines each. Each account represents a different organization integration. Meaning 1,000 order lines exported to 10 different .edi files

export "Package" record with "Titles" (about 5k) and assigned 1 large "Note" record


https://ptf-rmb.int.aws.folio.org/eholdings/packages/413-2603523 (4,971 titles and one very large note) 

2 500 records

file name 2500-user-barcodes.csv

10 000 records

file name 10k-item-barcodes.csv








#41-time checkExport 100 orders for each account number with 100 order lines each. Each account represents a different organization integration. Meaning 10,000 order lines exported to 10 different .edi files

export "Package" record with "Titles" (between 9.000 and 10.000) and assigned 1 large "Note" record

https://ptf-rmb.int.aws.folio.org/eholdings/packages/36-6693? (9,825 titles and one very large note) 

5 000 records

file name 5000-user-barcodes.csv

100 000 records

file name 100k-item-barcodes.csv








#5 1-time check????






Test resulst

Test Run

Duration

EdifacteHoldings

Bulk-edit

user barcodes

Bulk edit

item barcodes

Bursar

(optional)

Circulation logs (optional)Memory Behavior (Trend)CommentTime to process Results
#1

3x 100 orders with 100 PO lines each (10k)

3[10k files as output

3x 4472 w/o Note

https://ptf-rmb.int.aws.folio.org/eholdings/packages/58-2110695?searchfield=title


1 user Folio

3 jobs for 1250 records (unique dataset for each file)

1 user Folio

3 jobs for 5000 records (unique dataset for each file)

--

No visible growing of memory usage on 

mod-data-export-worker

and 

mod-data-export spring see pic#1

Edifact - success

eHoldings - success

Bulk users - ok

Bulk Items - ok

in total ±16 min

Edifact files being created;

Eholdings files being created

Comment

15-16 sec

Status - "success"

±4 min 10 s

Status -"success"

±15sec -upload (1/3 stuck "IN_PROGRESS")±21sec -for update (2 jobs)

±3min-upload

±6 min 35 sec- for update

(1/3 job failed at the beginning and was restarted)







#2

3x 100 orders with 100 PO lines each (10k)

3x 10k files as output

3x 4472 w/o Note

https://ptf-rmb.int.aws.folio.org/eholdings/packages/58-2110695?searchfield=title


3*12503*5000


Java heap space - out of memory exceptions on eHoldings 

Abstract fatal error executing job - ..-worker




14s 

1/3 job failed after 4 minutes with 

Index out of bounds: 347 >= 345 (IndexOutOfBoundsException)

4 min 30 s (2/3 jobs failed with Java heap space (OutOfMemoryError))

±17sec -upload ±31sec -for update

Status -"success"

±3min-upload

±7 min - for update

Status -"success"







#3

2x 100 orders with 100 PO lines each (10k)

2x 10k files as output

2x 4472 w/o Note

https://ptf-rmb.int.aws.folio.org/eholdings/packages/58-2110695?searchfield=title

2*12502*5000
















Failover testing. Behavior of the workflows when 'killing' the module

  • mod-data-export-worker
  • mod-data-export-spring


EdifacteHoldings

Bulk-edit

user barcodes

Bulk edit

item barcodes

Bursar

Circulation logs
mod-data-export-workerJobs resumed successfullyjob in status "scheduled " can proceed and be completed successfully after module restart.
job in status "in progress" resumed successfully

The job stuck "IN_PROGRESS" for file upload

If users were already uploaded, after failover- the edited file upload and the update will successful.

The job fails for edited file upload.  Status - "Scheduled". Error message "Fail to upload the file"

If the edited file was already uploaded, after failover- the update will fail. Error message "Something went wrong"

The job stuck "IN_PROGRESS" for the update step.


The job stuck "IN_PROGRESS" for file upload

If items were already uploaded, after failover- updating will not start.

Job did not resume, but the status changed to "Successful" for the updating process.

Did not test

Did not test

On perf bulk edit rancher job resumed successfully 

mod-data-export-spring

Jobs resumed successfully. With OOM some jobs failedJobs resumed successfullyJobs resumed successfully for all of the steps (file upload+ edited file upload +updating) Jobs resumed successfully for all of the steps (file upload +updating)Did not test

Did not test on PTF

On perf bulk edit rancher job resumed successfully 

Memory Trends of Repeated concurrent eHoldings and Edifact jobs:

Concurrent Edifact exports ( >6)

Concurrent eHolding jobs (6 with 4.2K each)

Memory usage of Repeated concurrent Bulk Edit Items App

  • Memory trend: memory usage increases over time for mod-data-export-worker increases from 37% to 46% in 2 steps at the start of the changes commitment process for 10000 and 20000 records. for mod-data-export-spring increases from 24% to 26% and become stable. All other services without changes. Related issue MODEXPW-214 - Getting issue details... STATUS

  • 5 parallel jobs for 10k records can be performed simultaneously only if started with the ramp-up of a minimum of 10sec (for both upload and editing processes). If the jobs started with fewer 10s intervals they will have IN_PROGRESS status forever.

Memory usage of Repeated concurrent Bulk Edit Users App

  • Memory trend: memory usage is stable.

Parallel jobs can be performed simultaneously only if started with the ramp-up of a minimum of 10sec (for both upload and editing processes). If the jobs started with fewer 10s intervals they will have IN_PROGRESS status forever.

Test #1

pic#1 Memory usage mod-data-export-worker/spring

pic#2 CPU usage

For Bulk-edit user barcodes job stuck "IN_PROGRESS"

Field	Value
@ingestionTime	1660122311768
@log 054267740449:lcp2-folio-eis
@logStream	lcp2/mod-data-export-spring/f8eefca0df4c4fe8aaa1339b2b020eb8
@message	

09:05:07 [950679/bulk-edit] [fs09000000] [9eb67301-6f6e-468f-9b1a-6134dc39a684] [mod-data-export-spring] INFO JobUpdatesService Received Job(id=6a4f73c5-e485-4384-a3b1-a89bd5365cd8, name=null, description=null, source=null, isSystemSource=null, type=BULK_EDIT_IDENTIFIERS, exportTypeSpecificParameters=null, status=null, files=null, fileNames=null, startTime=Wed Aug 10 09:05:07 UTC 2022, endTime=Wed Aug 10 09:05:07 UTC 2022, createdDate=Wed Aug 10 09:05:07 UTC 2022, createdByUserId=null, createdByUsername=null, updatedDate=Wed Aug 10 09:05:07 UTC 2022, updatedByUserId=null, updatedByUsername=null, outputFormat=null, errorDetails=null, batchStatus=STARTED, exitStatus=null, identifierType=null, entityType=USER, progress=class Progress {
@timestamp	
1660122307431


Field	Value
@ingestionTime	1660122312075
@log	054267740449:lcp2-folio-eis
@logStreamlcp2/mod-data-export-worker/6768ddc692484bd5917f409e9cc10e10
@message	

09:05:07 [] [] [] [] INFO SimpleJobLauncher$1 Job: [FlowJob: [name=BULK_EDIT_IDENTIFIERS-USER]] completed with the following parameters: [{jobId=6a4f73c5-e485-4384-a3b1-a89bd5365cd8, tempOutputFilePath=/tmp/mod-data-export-worker/2022-08-10-Matched-Records-1250-user4-barcodes, fileName=/tmp/mod-data-export-worker/1250-user4-barcodes.csv, totalCsvLines=1250, exportType=BULK_EDIT_IDENTIFIERS, identifierType=BARCODE, entityType=USER}] and the following status: [COMPLETED] in 14s649ms
@timestamp	

1660122307435

For Bulk-edit item barcodes job "FAILED"

Field                           Value
@ingestionTime     1660122427065
@log               054267740449:lcp2-folio-eis
@logStream         lcp2/mod-data-export-worker/6768ddc692484bd5917f409e9cc10e10
@message              09:07:06 [] [] [] [] ERROR AbstractStep Encountered an error executing step bulkEditItemStep in job BULK_EDIT_IDENTIFIERS-ITEM
@timestamp          1660122426706
Field                 Value
@ingestionTime      1660122427065
@log                054267740449:lcp2-folio-eis
@logStream          lcp2/mod-data-export-worker/6768ddc692484bd5917f409e9cc10e10
@message09:07:07 [] [] [] [] INO SimpleJobLauncher$1 Job: [FlowJob: [name=BULK_EDIT_IDENTIFIERS-ITEM]] completed with the following parameters: [{jobId=f31385ce-a129-4a81-be69-431caf72788f, tempOutputFilePath=/tmp/mod-data-export-worker/2022-08-10-Matched-Records-5000-item-barcodes_version2, fileName=/tmp/mod-data-export-worker/5000-item-barcodes_version2.csv, totalCsvLines=5000, exportType=BULK_EDIT_IDENTIFIERS, identifierType=BARCODE, entityType=ITEM}] and the following status: [FAILED] in 2m41s288ms
@timestamp       1660122427035


Test #2

note: Memory usage doesn't seems to be growing significantly, however 2/3 jobs of eholdings export failed with OOM. 

OutOfMemory exception trace (mod-data-export-worker)

09:30:43 [] [] [] [] ERROR AbstractJob Encountered fatal error executing jobjava.lang.OutOfMemoryError: Java heap spaceat java.util.Arrays.copyOf(Arrays.java:3745) ~[?:?]at java.io.ByteArrayOutputStream.toByteArray(ByteArrayOutputStream.java:211) ~[?:?]at org.springframework.batch.core.repository.dao.JdbcExecutionContextDao.serializeContext(JdbcExecutionContextDao.java:303) ~[spring-batch-core-4.3.6.jar!/:4.3.6]at org.springframework.batch.core.repository.dao.JdbcExecutionContextDao.updateExecutionContext(JdbcExecutionContextDao.java:146) ~[spring-batch-core-4.3.6.jar!/:4.3.6]at org.springframework.batch.core.repository.support.SimpleJobRepository.updateExecutionContext(SimpleJobRepository.java:223) ~[spring-batch-core-4.3.6.jar!/:4.3.6]at jdk.internal.reflect.GeneratedMethodAccessor350.invoke(Unknown Source) ~[?:?]at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344) ~[spring-aop-5.3.20.jar!/:5.3.20]at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198) ~[spring-aop-5.3.20.jar!/:5.3.20]at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) ~[spring-aop-5.3.20.jar!/:5.3.20]at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:123) ~[spring-tx-5.3.20.jar!/:5.3.20]at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:388) ~[spring-tx-5.3.20.jar!/:5.3.20]at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:119) ~[spring-tx-5.3.20.jar!/:5.3.20]at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.20.jar!/:5.3.20]at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:215) ~[spring-aop-5.3.20.jar!/:5.3.20]at com.sun.proxy.$Proxy121.updateExecutionContext(Unknown Source) ~[?:?]at jdk.internal.reflect.GeneratedMethodAccessor350.invoke(Unknown Source) ~[?:?]at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344) ~[spring-aop-5.3.20.jar!/:5.3.20]at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198) ~[spring-aop-5.3.20.jar!/:5.3.20]at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) ~[spring-aop-5.3.20.jar!/:5.3.20]at org.springframework.batch.core.configuration.annotation.SimpleBatchConfiguration$PassthruAdvice.invoke(SimpleBatchConfiguration.java:128) ~[spring-batch-core-4.3.6.jar!/:4.3.6]at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.20.jar!/:5.3.20]at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:215) ~[spring-aop-5.3.20.jar!/:5.3.20]at com.sun.proxy.$Proxy121.updateExecutionContext(Unknown Source) ~[?:?]at org.springframework.batch.core.job.SimpleStepHandler.handleStep(SimpleStepHandler.java:163) ~[spring-batch-core-4.3.6.jar!/:4.3.6]at org.springframework.batch.core.job.AbstractJob.handleStep(AbstractJob.java:413) ~[spring-batch-core-4.3.6.jar!/:4.3.6]at org.springframework.batch.core.job.SimpleJob.doExecute(SimpleJob.java:136) ~[spring-batch-core-4.3.6.jar!/:4.3.6]at org.springframework.batch.core.job.AbstractJob.execute(AbstractJob.java:320) ~[spring-batch-core-4.3.6.jar!/:4.3.6]at org.springframework.batch.core.launch.support.SimpleJobLauncher$1.run(SimpleJobLauncher.java:149) ~[spring-batch-core-4.3.6.jar!/:4.3.6]09:30:43 [] [] [] [] INFO NotificationListener Job update JobExecution: id=54, version=1, startTime=Wed Aug 10 09:26:12 UTC 2022, endTime=Wed Aug 10 09:30:43 UTC 2022, lastUpdated=Wed Aug 10 09:26:12 UTC 2022, status=FAILED, exitStatus=exitCode=FAILED;exitDescription=java.lang.OutOfMemoryError: Java heap spaceat java.base/java.util.Arrays.copyOf(Arrays.java:3745)at java.base/java.io.ByteArrayOutputStream.toByteArray(ByteArrayOutputStream.java:211)at org.springframework.batch.core.repository.dao.JdbcExecutionContextDao.serializeContext(JdbcExecutionContextDao.java:303)at org.springframework.batch.core.repository.dao.JdbcExecutionContextDao.updateExecutionContext(JdbcExecutionContextDao.java:146)at org.springframework.batch.core.repository.support.SimpleJobRepository.updateExecutionContext(SimpleJobRepository.java:223)at jdk.internal.reflect.GeneratedMethodAccessor350.invoke(Unknown Source)at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)at java.base/java.lang.reflect.Method.invoke(Method.java:566)at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344)at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198)at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:123)at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:388)at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:119)at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:215)at com.sun.proxy.$Proxy121.updateExecutionContext(Unknown Source)at jdk.internal.reflect.GeneratedMethodAccessor350.invoke(Unknown Source)at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)at java.base/java.lang.reflect.Method.invoke(Method.java:566)at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344)at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198)at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)at org.springframework.batch.core.configuration.annotation.SimpleBatchConfiguration$PassthruAdvice.invoke(SimpleBatchConfiguration.java:128)at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:215)at com.sun.proxy.$Proxy121.updateExecutionContext(Unknown Source)at org.springframework.batch.core.job.SimpleStepHandler.handleStep(SimpleStepHandler.java:163)at org.springframework.batch.core.job.AbstractJob.handleStep(AbstractJob.java:413)at org.springframework.batch.core.job.SimpleJob.doExecute(SimpleJob.java:136)at org.springframework.batch.core.job.AbstractJob.execute(AbstractJob.java:320)at org.springframework.batch.core.launch.support.SimpleJobLauncher$1.run(SimpleJobLauncher.java:149), job=[JobInstance: id=54, version=0, Job=[E_HOLDINGS]], jobParameters=[{eHoldingsExportConfig={"recordId":"58-2110695","recordType":"PACKAGE","titleSearchFilters":"searchfield=title","packageFields":["providerName","providerId","packageName","packageId","packageType","packageContentType","packageHoldingsStatus","packageCustomCoverage","packageShowToPatrons","packageAutomaticallySelect","packageProxy","packageAccessStatusType","packageTags","packageAgreements","packageNotes"],"titleFields":["titleName","alternateTitles","titleId","publicationType","titleType","titleHoldingsStatus","titleShowToPatrons","managedCoverage","managedEmbargo","customCoverage","customEmbargo","coverageStatement","titleProxy","url","titleAccessStatusType","titleTags","contributors","edition","publisher","ISSNPrint","ISSNOnline","ISBNPrint","ISBNOnline","subjects","peerReviewed","description","customValue1","customValue2","customValue3","customValue4","customValue5","titleAgreements","titleNotes"]}, jobId=bf697955-8d8e-4bb9-b1ae-af3210298a7e, tempOutputFilePath=/tmp/mod-data-export-worker/2022-08-10_09-26-12_0072_58-2110695_package}].09:30:43 [] [] [] [] INFO KafkaService Sending Job(id=bf697955-8d8e-4bb9-b1ae-af3210298a7e, name=null, description=null, source=null, isSystemSource=null, type=null, exportTypeSpecificParameters=null, status=null, files=null, fileNames=null, startTime=Wed Aug 10 09:26:12 UTC 2022, endTime=Wed Aug 10 09:30:43 UTC 2022, createdDate=Wed Aug 10 09:26:12 UTC 2022, createdByUserId=null, createdByUsername=null, updatedDate=Wed Aug 10 09:26:12 UTC 2022, updatedByUserId=null, updatedByUsername=null, outputFormat=null, errorDetails=Java heap space (OutOfMemoryError), batchStatus=FAILED, exitStatus=exitCode=FAILED;exitDescription=java.lang.OutOfMemoryError: Java heap spaceat java.base/java.util.Arrays.copyOf(Arrays.java:3745)at java.base/java.io.ByteArrayOutputStream.toByteArray(ByteArrayOutputStream.java:211)at org.springframework.batch.core.repository.dao.JdbcExecutionContextDao.serializeContext(JdbcExecutionContextDao.java:303)at org.springframework.batch.core.repository.dao.JdbcExecutionContextDao.updateExecutionContext(JdbcExecutionContextDao.java:146)at org.springframework.batch.core.repository.support.SimpleJobRepository.updateExecutionContext(SimpleJobRepository.java:223)at jdk.internal.reflect.GeneratedMethodAccessor350.invoke(Unknown Source)at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)at java.base/java.lang.reflect.Method.invoke(Method.java:566)at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344)at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198)at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:123)at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:388)at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:119)at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:215)at com.sun.proxy.$Proxy121.updateExecutionContext(Unknown Source)at jdk.internal.reflect.GeneratedMethodAccessor350.invoke(Unknown Source)at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)at java.base/java.lang.reflect.Method.invoke(Method.java:566)at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344)at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198)at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)at org.springframework.batch.core.configuration.annotation.SimpleBatchConfiguration$PassthruAdvice.invoke(SimpleBatchConfiguration.java:128)at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:215)at com.sun.proxy.$Proxy121.updateExecutionContext(Unknown Source)at org.springframework.batch.core.job.SimpleStepHandler.handleStep(SimpleStepHandler.java:163)at org.springframework.batch.core.job.AbstractJob.handleStep(AbstractJob.java:413)at org.springframework.batch.core.job.SimpleJob.doExecute(SimpleJob.java:136)at org.springframework.batch.core.job.AbstractJob.execute(AbstractJob.java:320)at org.springframework.batch.core.launch.support.SimpleJobLauncher$1.run(SimpleJobLauncher.java:149), identifierType=null, entityType=null, progress=null).09:30:43 [] [] [] [] INFO KafkaService Sent Job(id=bf697955-8d8e-4bb9-b1ae-af3210298a7e, name=null, description=null, source=null, isSystemSource=null, type=null, exportTypeSpecificParameters=null, status=null, files=null, fileNames=null, startTime=Wed Aug 10 09:26:12 UTC 2022, endTime=Wed Aug 10 09:30:43 UTC 2022, createdDate=Wed Aug 10 09:26:12 UTC 2022, createdByUserId=null, createdByUsername=null, updatedDate=Wed Aug 10 09:26:12 UTC 2022, updatedByUserId=null, updatedByUsername=null, outputFormat=null, errorDetails=Java heap space (OutOfMemoryError), batchStatus=FAILED, exitStatus=exitCode=FAILED;exitDescription=java.lang.OutOfMemoryError: Java heap spaceat java.base/java.util.Arrays.copyOf(Arrays.java:3745)at java.base/java.io.ByteArrayOutputStream.toByteArray(ByteArrayOutputStream.java:211)at org.springframework.batch.core.repository.dao.JdbcExecutionContextDao.serializeContext(JdbcExecutionContextDao.java:303)at org.springframework.batch.core.repository.dao.JdbcExecutionContextDao.updateExecutionContext(JdbcExecutionContextDao.java:146)at org.springframework.batch.core.repository.support.SimpleJobRepository.updateExecutionContext(SimpleJobRepository.java:223)at jdk.internal.reflect.GeneratedMethodAccessor350.invoke(Unknown Source)at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)at java.base/java.lang.reflect.Method.invoke(Method.java:566)at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344)at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198)at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:123)at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:388)at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:119)at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:215)at com.sun.proxy.$Proxy121.updateExecutionContext(Unknown Source)at jdk.internal.reflect.GeneratedMethodAccessor350.invoke(Unknown Source)at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)at java.base/java.lang.reflect.Method.invoke(Method.java:566)at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344)at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198)at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)at org.springframework.batch.core.configuration.annotation.SimpleBatchConfiguration$PassthruAdvice.invoke(SimpleBatchConfiguration.java:128)at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:215)at com.sun.proxy.$Proxy121.updateExecutionContext(Unknown Source)at org.springframework.batch.core.job.SimpleStepHandler.handleStep(SimpleStepHandler.java:163)at org.springframework.batch.core.job.AbstractJob.handleStep(AbstractJob.java:413)at org.springframework.batch.core.job.SimpleJob.doExecute(SimpleJob.java:136)at org.springframework.batch.core.job.AbstractJob.execute(AbstractJob.java:320)at org.springframework.batch.core.launch.support.SimpleJobLauncher$1.run(SimpleJobLauncher.java:149), identifierType=null, entityType=null, progress=null).

Index out of bounds: 347 >= 345 (IndexOutOfBoundsException) trace. (mod-data-export-worker)

09:30:52 [] [] [] [] ERROR AbstractJob Encountered fatal error executing joborg.springframework.dao.TransientDataAccessResourceException: PreparedStatementCallback; SQL [UPDATE BATCH_JOB_EXECUTION_CONTEXT SET SHORT_CONTEXT = ?, SERIALIZED_CONTEXT = ? WHERE JOB_EXECUTION_ID = ?]; java.lang.IndexOutOfBoundsException: Index out of bounds: 347 >= 345; nested exception is java.sql.SQLException: java.lang.IndexOutOfBoundsException: Index out of bounds: 347 >= 345at org.springframework.jdbc.support.SQLStateSQLExceptionTranslator.doTranslate(SQLStateSQLExceptionTranslator.java:110) ~[spring-jdbc-5.3.20.jar!/:5.3.20]at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:70) ~[spring-jdbc-5.3.20.jar!/:5.3.20]at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:79) ~[spring-jdbc-5.3.20.jar!/:5.3.20]at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:79) ~[spring-jdbc-5.3.20.jar!/:5.3.20]at org.springframework.jdbc.core.JdbcTemplate.translateException(JdbcTemplate.java:1541) ~[spring-jdbc-5.3.20.jar!/:5.3.20]at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:667) ~[spring-jdbc-5.3.20.jar!/:5.3.20]at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:960) ~[spring-jdbc-5.3.20.jar!/:5.3.20]at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:1015) ~[spring-jdbc-5.3.20.jar!/:5.3.20]at org.springframework.batch.core.repository.dao.JdbcExecutionContextDao.persistSerializedContext(JdbcExecutionContextDao.java:236) ~[spring-batch-core-4.3.6.jar!/:4.3.6]at org.springframework.batch.core.repository.dao.JdbcExecutionContextDao.updateExecutionContext(JdbcExecutionContextDao.java:148) ~[spring-batch-core-4.3.6.jar!/:4.3.6]at org.springframework.batch.core.repository.support.SimpleJobRepository.updateExecutionContext(SimpleJobRepository.java:223) ~[spring-batch-core-4.3.6.jar!/:4.3.6]at jdk.internal.reflect.GeneratedMethodAccessor350.invoke(Unknown Source) ~[?:?]at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344) ~[spring-aop-5.3.20.jar!/:5.3.20]at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198) ~[spring-aop-5.3.20.jar!/:5.3.20]at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) ~[spring-aop-5.3.20.jar!/:5.3.20]at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:123) ~[spring-tx-5.3.20.jar!/:5.3.20]at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:388) ~[spring-tx-5.3.20.jar!/:5.3.20]at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:119) ~[spring-tx-5.3.20.jar!/:5.3.20]at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.20.jar!/:5.3.20]at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:215) ~[spring-aop-5.3.20.jar!/:5.3.20]at com.sun.proxy.$Proxy121.updateExecutionContext(Unknown Source) ~[?:?]at jdk.internal.reflect.GeneratedMethodAccessor350.invoke(Unknown Source) ~[?:?]at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344) ~[spring-aop-5.3.20.jar!/:5.3.20]at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198) ~[spring-aop-5.3.20.jar!/:5.3.20]at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) ~[spring-aop-5.3.20.jar!/:5.3.20]at org.springframework.batch.core.configuration.annotation.SimpleBatchConfiguration$PassthruAdvice.invoke(SimpleBatchConfiguration.java:128) ~[spring-batch-core-4.3.6.jar!/:4.3.6]at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.20.jar!/:5.3.20]at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:215) ~[spring-aop-5.3.20.jar!/:5.3.20]at com.sun.proxy.$Proxy121.updateExecutionContext(Unknown Source) ~[?:?]at org.springframework.batch.core.job.SimpleStepHandler.handleStep(SimpleStepHandler.java:163) ~[spring-batch-core-4.3.6.jar!/:4.3.6]at org.springframework.batch.core.job.AbstractJob.handleStep(AbstractJob.java:413) ~[spring-batch-core-4.3.6.jar!/:4.3.6]at org.springframework.batch.core.job.SimpleJob.doExecute(SimpleJob.java:136) ~[spring-batch-core-4.3.6.jar!/:4.3.6]at org.springframework.batch.core.job.AbstractJob.execute(AbstractJob.java:320) ~[spring-batch-core-4.3.6.jar!/:4.3.6]at org.springframework.batch.core.launch.support.SimpleJobLauncher$1.run(SimpleJobLauncher.java:149) ~[spring-batch-core-4.3.6.jar!/:4.3.6]at org.springframework.core.task.SyncTaskExecutor.execute(SyncTaskExecutor.java:50) ~[spring-core-5.3.20.jar!/:5.3.20]at org.springframework.batch.core.launch.support.SimpleJobLauncher.run(SimpleJobLauncher.java:140) ~[spring-batch-core-4.3.6.jar!/:4.3.6]at jdk.internal.reflect.GeneratedMethodAccessor651.invoke(Unknown Source) ~[?:?]at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344) ~[spring-aop-5.3.20.jar!/:5.3.20]at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198) ~[spring-aop-5.3.20.jar!/:5.3.20]at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) ~[spring-aop-5.3.20.jar!/:5.3.20]at org.springframework.batch.core.configuration.annotation.SimpleBatchConfiguration$PassthruAdvice.invoke(SimpleBatchConfiguration.java:128) ~[spring-batch-core-4.3.6.jar!/:4.3.6]at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.20.jar!/:5.3.20]at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:215) ~[spring-aop-5.3.20.jar!/:5.3.20]at com.sun.proxy.$Proxy182.run(Unknown Source) ~[?:?]at org.springframework.batch.integration.launch.JobLaunchingMessageHandler.launch(JobLaunchingMessageHandler.java:50) ~[spring-batch-integration-4.3.6.jar!/:4.3.6]at org.folio.dew.batch.ExportJobManager.launchJob(ExportJobManager.java:29) ~[classes!/:1.5.0-SNAPSHOT]at org.folio.dew.service.JobCommandsReceiverService.receiveStartJobCommand(JobCommandsReceiverService.java:139) ~[classes!/:1.5.0-SNAPSHOT]at jdk.internal.reflect.GeneratedMethodAccessor641.invoke(Unknown Source) ~[?:?]at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]at org.springframework.messaging.handler.invocation.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:169) ~[spring-messaging-5.3.20.jar!/:5.3.20]at org.springframework.messaging.handler.invocation.InvocableHandlerMethod.invoke(InvocableHandlerMethod.java:119) ~[spring-messaging-5.3.20.jar!/:5.3.20]at org.springframework.kafka.listener.adapter.HandlerAdapter.invoke(HandlerAdapter.java:56) ~[spring-kafka-2.8.6.jar!/:2.8.6]at org.springframework.kafka.listener.adapter.MessagingMessageListenerAdapter.invokeHandler(MessagingMessageListenerAdapter.java:347) ~[spring-kafka-2.8.6.jar!/:2.8.6]at org.springframework.kafka.listener.adapter.RecordMessagingMessageListenerAdapter.onMessage(RecordMessagingMessageListenerAdapter.java:92) ~[spring-kafka-2.8.6.jar!/:2.8.6]at org.springframework.kafka.listener.adapter.RecordMessagingMessageListenerAdapter.onMessage(RecordMessagingMessageListenerAdapter.java:53) ~[spring-kafka-2.8.6.jar!/:2.8.6]at org.springframework.kafka.listener.KafkaMessageListenerContainer$ListenerConsumer.doInvokeOnMessage(KafkaMessageListenerContainer.java:2645) ~[spring-kafka-2.8.6.jar!/:2.8.6]at org.springframework.kafka.listener.KafkaMessageListenerContainer$ListenerConsumer.invokeOnMessage(KafkaMessageListenerContainer.java:2625) ~[spring-kafka-2.8.6.jar!/:2.8.6]at org.springframework.kafka.listener.KafkaMessageListenerContainer$ListenerConsumer.doInvokeRecordListener(KafkaMessageListenerContainer.java:2552) ~[spring-kafka-2.8.6.jar!/:2.8.6]at org.springframework.kafka.listener.KafkaMessageListenerContainer$ListenerConsumer.doInvokeWithRecords(KafkaMessageListenerContainer.java:2433) ~[spring-kafka-2.8.6.jar!/:2.8.6]at org.springframework.kafka.listener.KafkaMessageListenerContainer$ListenerConsumer.invokeRecordListener(KafkaMessageListenerContainer.java:2311) ~[spring-kafka-2.8.6.jar!/:2.8.6]at org.springframework.kafka.listener.KafkaMessageListenerContainer$ListenerConsumer.invokeListener(KafkaMessageListenerContainer.java:1982) ~[spring-kafka-2.8.6.jar!/:2.8.6]at org.springframework.kafka.listener.KafkaMessageListenerContainer$ListenerConsumer.invokeIfHaveRecords(KafkaMessageListenerContainer.java:1366) ~[spring-kafka-2.8.6.jar!/:2.8.6]at org.springframework.kafka.listener.KafkaMessageListenerContainer$ListenerConsumer.pollAndInvoke(KafkaMessageListenerContainer.java:1357) ~[spring-kafka-2.8.6.jar!/:2.8.6]at org.springframework.kafka.listener.KafkaMessageListenerContainer$ListenerConsumer.run(KafkaMessageListenerContainer.java:1252) ~[spring-kafka-2.8.6.jar!/:2.8.6]at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) ~[?:?]at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]at java.lang.Thread.run(Thread.java:829) ~[?:?]Caused by: java.sql.SQLException: java.lang.IndexOutOfBoundsException: Index out of bounds: 347 >= 345at org.hsqldb.jdbc.JDBCUtil.sqlException(Unknown Source) ~[hsqldb-2.5.2.jar!/:2.5.2]at org.hsqldb.jdbc.JDBCUtil.sqlException(Unknown Source) ~[hsqldb-2.5.2.jar!/:2.5.2]at org.hsqldb.jdbc.JDBCPreparedStatement.fetchResult(Unknown Source) ~[hsqldb-2.5.2.jar!/:2.5.2]at org.hsqldb.jdbc.JDBCPreparedStatement.executeUpdate(Unknown Source) ~[hsqldb-2.5.2.jar!/:2.5.2]at com.zaxxer.hikari.pool.ProxyPreparedStatement.executeUpdate(ProxyPreparedStatement.java:61) ~[HikariCP-4.0.3.jar!/:?]at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeUpdate(HikariProxyPreparedStatement.java) ~[HikariCP-4.0.3.jar!/:?]at org.springframework.jdbc.core.JdbcTemplate.lambda$update$2(JdbcTemplate.java:965) ~[spring-jdbc-5.3.20.jar!/:5.3.20]at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:651) ~[spring-jdbc-5.3.20.jar!/:5.3.20]... 68 moreCaused by: org.hsqldb.HsqlException: java.lang.IndexOutOfBoundsException: Index out of bounds: 347 >= 345at org.hsqldb.error.Error.error(Unknown Source) ~[hsqldb-2.5.2.jar!/:2.5.2]at org.hsqldb.SessionData.allocateLobForResult(Unknown Source) ~[hsqldb-2.5.2.jar!/:2.5.2]at org.hsqldb.Session.allocateResultLob(Unknown Source) ~[hsqldb-2.5.2.jar!/:2.5.2]at org.hsqldb.jdbc.JDBCPreparedStatement.performPreExecute(Unknown Source) ~[hsqldb-2.5.2.jar!/:2.5.2]at org.hsqldb.jdbc.JDBCPreparedStatement.fetchResult(Unknown Source) ~[hsqldb-2.5.2.jar!/:2.5.2]at org.hsqldb.jdbc.JDBCPreparedStatement.executeUpdate(Unknown Source) ~[hsqldb-2.5.2.jar!/:2.5.2]at com.zaxxer.hikari.pool.ProxyPreparedStatement.executeUpdate(ProxyPreparedStatement.java:61) ~[HikariCP-4.0.3.jar!/:?]at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeUpdate(HikariProxyPreparedStatement.java) ~[HikariCP-4.0.3.jar!/:?]at org.springframework.jdbc.core.JdbcTemplate.lambda$update$2(JdbcTemplate.java:965) ~[spring-jdbc-5.3.20.jar!/:5.3.20]at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:651) ~[spring-jdbc-5.3.20.jar!/:5.3.20]... 68 moreCaused by: java.lang.IndexOutOfBoundsException: Index out of bounds: 347 >= 345at org.hsqldb.lib.HsqlArrayList.get(Unknown Source) ~[hsqldb-2.5.2.jar!/:2.5.2]at org.hsqldb.persist.LobStoreMem.setBlockBytes(Unknown Source) ~[hsqldb-2.5.2.jar!/:2.5.2]at org.hsqldb.persist.LobManager.setBytesISNormal(Unknown Source) ~[hsqldb-2.5.2.jar!/:2.5.2]at org.hsqldb.persist.LobManager.setBytesIS(Unknown Source) ~[hsqldb-2.5.2.jar!/:2.5.2]at org.hsqldb.persist.LobManager.setCharsForNewClob(Unknown Source) ~[hsqldb-2.5.2.jar!/:2.5.2]at org.hsqldb.SessionData.allocateLobForResult(Unknown Source) ~[hsqldb-2.5.2.jar!/:2.5.2]at org.hsqldb.Session.allocateResultLob(Unknown Source) ~[hsqldb-2.5.2.jar!/:2.5.2]at org.hsqldb.jdbc.JDBCPreparedStatement.performPreExecute(Unknown Source) ~[hsqldb-2.5.2.jar!/:2.5.2]at org.hsqldb.jdbc.JDBCPreparedStatement.fetchResult(Unknown Source) ~[hsqldb-2.5.2.jar!/:2.5.2]at org.hsqldb.jdbc.JDBCPreparedStatement.executeUpdate(Unknown Source) ~[hsqldb-2.5.2.jar!/:2.5.2]at com.zaxxer.hikari.pool.ProxyPreparedStatement.executeUpdate(ProxyPreparedStatement.java:61) ~[HikariCP-4.0.3.jar!/:?]at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeUpdate(HikariProxyPreparedStatement.java) ~[HikariCP-4.0.3.jar!/:?]at org.springframework.jdbc.core.JdbcTemplate.lambda$update$2(JdbcTemplate.java:965) ~[spring-jdbc-5.3.20.jar!/:5.3.20]at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:651) ~[spring-jdbc-5.3.20.jar!/:5.3.20]... 68 more
  • No labels