MODKBEKBJ-572
-
Getting issue details...
STATUS
1st test case
Description: 1 tenant - 4 credentials
Run parameters: Xmx128m
Result: FAILED WITH OOM
Logs: one-tenant-4-creds-OOM.log
Heap dumps: one-tenant-heap-dump.7z
Credentials:
Details
The app failed with OutOfMemory while the RMAPI respond with a collection of holdings and holdings-iq-client trying to process the response and convert it to Java object.
This process was failed with an exception:
Failed to decode:Unexpected end-of-input in VALUE_STRING\u000a at [Source: (io.netty.buffer.ByteBufInputStream); line: 1, column: 4246837] (through reference chain: org.folio.holdingsiq.model.Holdings["holdings"]->java.util.ArrayList[4607]->org.folio.holdingsiq.model.Holding["title_id"])
After the exception occurred the client tried to log it and include a full response in the log-message and OOM happened.
Possible solutions
- Investigate why the response contains "Unexpected end-of-input in VALUE_STRING\u000a" in "title_id"
2nd test case
Description: 1 tenant - 4 credentials
Run parameters: Xmx128m
Result: SUCCESS
Logs: one-tenant-4-creds-success.log
Heap dumps: -
Credentials:
Details
During the process of loading several exceptions happened:
- Creation of snapshot was failed on RMAPI side. The retrying process worked successfully and the creation of the snapshot succeeded in 3 hours.
- Several times the request for collection of holdings failed with 504 Gateway Timeout and body "Endpoint request timed out". The retrying process worked successfully and the loading of page succeeded in 15 minutes.
- In one of the requests for collection of holdings appeared a holding with empty "title_id". This produced the exception because we expect a number-formated string in the property.
Possible solutions
- Investigate why snapshot creation could fail.
- Investigate why the "title_id" property could be empty.
- Maybe we should decrease size of pages(currently we request 5000 holdings per page) to resolve 504 Gateway Timeout.
MODKBEKBJ-577
-
Getting issue details...
STATUS
3rd test case
Description: 2 tenants - 4 credentials per tenant
Run parameters: Xmx128m
Result: FAILED WITH OOM
Logs: failed to capture
Heap dumps: two-tenants-heap-dump.7z
Credentials:
Details
The app failed with OutOfMemory. The biggest objects in the app run were HttpClientConnection and objects that serve them.
Possible solutions
- Currently, we create Vert.X WebClient each time a request goes to holdings-iq-client. As per Vert.X documentation, we should share an instance of WebClient between requests:
https://vertx.io/docs/vertx-web-client/java/#_creating_a_web_client
FHIQC-10
-
Getting issue details...
STATUS
4th test case
Description: 2 tenants - 4 credentials per tenant
Run parameters: Xmx384m
Result: SUCCESS
Logs: two-tenants-8-creds-success-log.zip
Heap dumps: -
Credentials:
Details
During the process of loading several exceptions happened:
- Creation of snapshot was failed on RMAPI side. The retrying process worked successfully and the creation of the snapshot succeeded in 3 hours.
- Many times the request for collection of holdings failed with 504 Gateway Timeout and body "Endpoint request timed out". The retrying process worked successfully and the loading of page succeeded in 15 minutes.
After some time of loading appeared exceptions while updating "holdings_status" table but holdings loading continued and holdings were saved. The result of this - holdings were loaded but status left in "In Progress" state.
MODKBEKBJ-575
-
Getting issue details...
STATUS
Exception
13:38:12 [] [] [] [] INFO HoldingsServiceImpl Saving holdings to database.
13:38:13 [] [] [] [] INFO DbUtils Transaction was not successful. Roll back changes.
13:38:13 [] [] [] [] ERROR HoldingsServiceImpl Failed to save holdings
java.util.concurrent.CompletionException: org.folio.db.exc.ConstraintViolationException: null value in column "jsonb" violates not-null constraint
at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:331) ~[?:?]
at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:346) ~[?:?]
at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:632) ~[?:?]
at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506) ~[?:?]
at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2088) ~[?:?]
at io.vertx.core.impl.future.Otherwise.onFailure(Otherwise.java:35) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.impl.future.FutureBase.emitFailure(FutureBase.java:79) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.impl.future.FutureImpl.tryFail(FutureImpl.java:198) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.impl.future.Mapping.onFailure(Mapping.java:45) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.impl.future.FutureBase.emitFailure(FutureBase.java:79) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.impl.future.FutureImpl.tryFail(FutureImpl.java:198) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.impl.future.Composition$1.onFailure(Composition.java:66) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.impl.future.FutureBase.emitFailure(FutureBase.java:79) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.impl.future.FailedFuture.addListener(FailedFuture.java:92) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.impl.future.Composition.onFailure(Composition.java:55) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.impl.future.FutureBase.emitFailure(FutureBase.java:79) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.impl.future.FutureImpl.tryFail(FutureImpl.java:198) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.impl.future.PromiseImpl.tryFail(PromiseImpl.java:23) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.impl.future.PromiseImpl.onFailure(PromiseImpl.java:54) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.impl.future.PromiseImpl.handle(PromiseImpl.java:43) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.impl.future.PromiseImpl.handle(PromiseImpl.java:23) ~[mod-kb-ebsco-java-fat.jar:?]
at org.folio.rest.persist.PostgresClient.lambda$94(PostgresClient.java:3355) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.impl.future.FutureImpl$3.onFailure(FutureImpl.java:128) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.impl.future.FutureBase.emitFailure(FutureBase.java:79) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.impl.future.FutureImpl.tryFail(FutureImpl.java:198) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.impl.future.PromiseImpl.tryFail(PromiseImpl.java:23) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.sqlclient.impl.QueryResultBuilder.tryFail(QueryResultBuilder.java:118) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.Promise.fail(Promise.java:89) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.Promise.handle(Promise.java:53) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.sqlclient.impl.TransactionImpl.lambda$null$0(TransactionImpl.java:75) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.impl.future.FutureImpl$3.onSuccess(FutureImpl.java:124) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.impl.future.FutureBase.emitSuccess(FutureBase.java:62) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.impl.future.FutureImpl.tryComplete(FutureImpl.java:179) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.impl.future.PromiseImpl.tryComplete(PromiseImpl.java:23) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.impl.future.PromiseImpl.onSuccess(PromiseImpl.java:49) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.impl.future.PromiseImpl.handle(PromiseImpl.java:41) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.sqlclient.impl.TransactionImpl.lambda$txCommand$2(TransactionImpl.java:169) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.impl.future.FutureImpl$3.onSuccess(FutureImpl.java:124) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.impl.future.FutureBase.lambda$emitSuccess$0(FutureBase.java:54) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.impl.EventLoopContext.execute(EventLoopContext.java:83) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.impl.DuplicatedContext.execute(DuplicatedContext.java:199) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.impl.future.FutureBase.emitSuccess(FutureBase.java:51) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.impl.future.FutureImpl.tryComplete(FutureImpl.java:179) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.impl.future.PromiseImpl.tryComplete(PromiseImpl.java:23) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.impl.future.PromiseImpl.onSuccess(PromiseImpl.java:49) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.impl.future.PromiseImpl.handle(PromiseImpl.java:41) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.impl.future.PromiseImpl.handle(PromiseImpl.java:23) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.pgclient.impl.PgSocketConnection.lambda$doSchedule$2(PgSocketConnection.java:154) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.sqlclient.impl.command.CommandResponse.fire(CommandResponse.java:46) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.sqlclient.impl.SocketConnectionBase.handleMessage(SocketConnectionBase.java:257) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.pgclient.impl.PgSocketConnection.handleMessage(PgSocketConnection.java:99) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.sqlclient.impl.SocketConnectionBase.lambda$init$0(SocketConnectionBase.java:95) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.net.impl.NetSocketImpl.lambda$new$1(NetSocketImpl.java:90) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.streams.impl.InboundBuffer.handleEvent(InboundBuffer.java:240) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.streams.impl.InboundBuffer.write(InboundBuffer.java:130) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.net.impl.NetSocketImpl.lambda$handleMessage$9(NetSocketImpl.java:378) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.impl.EventLoopContext.emit(EventLoopContext.java:52) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.impl.DuplicatedContext.emit(DuplicatedContext.java:194) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.net.impl.NetSocketImpl.handleMessage(NetSocketImpl.java:377) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.net.impl.ConnectionBase.read(ConnectionBase.java:153) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.net.impl.VertxHandler.channelRead(VertxHandler.java:148) ~[mod-kb-ebsco-java-fat.jar:?]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) ~[mod-kb-ebsco-java-fat.jar:?]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) ~[mod-kb-ebsco-java-fat.jar:?]
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) ~[mod-kb-ebsco-java-fat.jar:?]
at io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.fireChannelRead(CombinedChannelDuplexHandler.java:436) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.pgclient.impl.codec.PgEncoder.lambda$write$0(PgEncoder.java:79) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.pgclient.impl.codec.PgCommandCodec.handleReadyForQuery(PgCommandCodec.java:139) [mod-kb-ebsco-java-fat.jar:?]
at io.vertx.pgclient.impl.codec.PgDecoder.decodeReadyForQuery(PgDecoder.java:226) [mod-kb-ebsco-java-fat.jar:?]
at io.vertx.pgclient.impl.codec.PgDecoder.channelRead(PgDecoder.java:86) [mod-kb-ebsco-java-fat.jar:?]
at io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:251) [mod-kb-ebsco-java-fat.jar:?]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) [mod-kb-ebsco-java-fat.jar:?]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) [mod-kb-ebsco-java-fat.jar:?]
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) [mod-kb-ebsco-java-fat.jar:?]
at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410) [mod-kb-ebsco-java-fat.jar:?]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) [mod-kb-ebsco-java-fat.jar:?]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) [mod-kb-ebsco-java-fat.jar:?]
at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919) [mod-kb-ebsco-java-fat.jar:?]
at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166) [mod-kb-ebsco-java-fat.jar:?]
at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:714) [mod-kb-ebsco-java-fat.jar:?]
at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:650) [mod-kb-ebsco-java-fat.jar:?]
at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:576) [mod-kb-ebsco-java-fat.jar:?]
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:493) [mod-kb-ebsco-java-fat.jar:?]
at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989) [mod-kb-ebsco-java-fat.jar:?]
at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [mod-kb-ebsco-java-fat.jar:?]
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [mod-kb-ebsco-java-fat.jar:?]
at java.lang.Thread.run(Thread.java:834) [?:?]
Caused by: org.folio.db.exc.ConstraintViolationException: null value in column "jsonb" violates not-null constraint
at org.folio.db.exc.translation.postgresql.ConstrainViolationTranslation$TFunction.apply(ConstrainViolationTranslation.java:61) ~[mod-kb-ebsco-java-fat.jar:?]
at org.folio.db.exc.translation.postgresql.ConstrainViolationTranslation$TFunction.apply(ConstrainViolationTranslation.java:37) ~[mod-kb-ebsco-java-fat.jar:?]
at org.folio.common.pf.PartialFunctionImpl.applySuccessfully(PartialFunctionImpl.java:28) ~[mod-kb-ebsco-java-fat.jar:?]
at org.folio.common.pf.PartialFunction.applyOrElse(PartialFunction.java:31) ~[mod-kb-ebsco-java-fat.jar:?]
at org.folio.common.pf.PartialFunction.apply(PartialFunction.java:18) ~[mod-kb-ebsco-java-fat.jar:?]
at org.folio.common.pf.OrElse.applySuccessfully(OrElse.java:26) ~[mod-kb-ebsco-java-fat.jar:?]
at org.folio.common.pf.PartialFunction.applyOrElse(PartialFunction.java:31) ~[mod-kb-ebsco-java-fat.jar:?]
at org.folio.common.pf.PartialFunction.apply(PartialFunction.java:18) ~[mod-kb-ebsco-java-fat.jar:?]
at org.folio.common.pf.OrElse.applySuccessfully(OrElse.java:26) ~[mod-kb-ebsco-java-fat.jar:?]
at org.folio.common.pf.PartialFunction.applyOrElse(PartialFunction.java:31) ~[mod-kb-ebsco-java-fat.jar:?]
at org.folio.common.pf.PartialFunction.apply(PartialFunction.java:18) ~[mod-kb-ebsco-java-fat.jar:?]
at org.folio.common.pf.OrElse.applySuccessfully(OrElse.java:26) ~[mod-kb-ebsco-java-fat.jar:?]
at org.folio.common.pf.PartialFunction.applyOrElse(PartialFunction.java:31) ~[mod-kb-ebsco-java-fat.jar:?]
at org.folio.common.pf.PartialFunction.apply(PartialFunction.java:18) ~[mod-kb-ebsco-java-fat.jar:?]
at org.folio.db.exc.translation.postgresql.PostgreSQLExceptionTranslator.doTranslation(PostgreSQLExceptionTranslator.java:29) ~[mod-kb-ebsco-java-fat.jar:?]
at org.folio.db.exc.translation.DBExceptionTranslator.translate(DBExceptionTranslator.java:18) ~[mod-kb-ebsco-java-fat.jar:?]
at org.folio.db.exc.translation.DBExceptionTranslator.lambda$translateOrPassBy$0(DBExceptionTranslator.java:26) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.core.impl.future.Composition.onFailure(Composition.java:50) ~[mod-kb-ebsco-java-fat.jar:?]
... 71 more
Caused by: io.vertx.pgclient.PgException: { "message": "null value in column \"jsonb\" violates not-null constraint", "severity": "ERROR", "code": "23502", "detail": "Failing row contains (b59720d2-c16a-4a16-b158-942f77acd754, null, t, 8e29a743-6532-4074-9652-855a7643d571, 5b1409d1-1b2f-43b4-b0d8-9e99eeca3569).", "file": "execMain.c", "line": "2016", "routine": "ExecConstraints", "schema": "test_mod_kb_ebsco_java", "table": "holdings_status", "column": "jsonb" }
at io.vertx.pgclient.impl.codec.ErrorResponse.toException(ErrorResponse.java:31) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.pgclient.impl.codec.QueryCommandBaseCodec.handleErrorResponse(QueryCommandBaseCodec.java:57) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.pgclient.impl.codec.ExtendedQueryCommandCodec.handleErrorResponse(ExtendedQueryCommandCodec.java:90) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.pgclient.impl.codec.PgDecoder.decodeError(PgDecoder.java:236) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.pgclient.impl.codec.PgDecoder.decodeMessage(PgDecoder.java:122) ~[mod-kb-ebsco-java-fat.jar:?]
at io.vertx.pgclient.impl.codec.PgDecoder.channelRead(PgDecoder.java:102) ~[mod-kb-ebsco-java-fat.jar:?]
... 17 more
Possible solutions
- Investigate why holdings_status failed to update.
Open questions
- Consider not using the Vert.X event bus to load holdings. One of the reasons is that when you restart or update the module, the loading if it is in progress, will not continue.
- Consider moving the process of holdings loading to a new module. This will reduce the load on kb-ebsco module.