Skip to end of metadata
Go to start of metadata

MODKBEKBJ-572 - Getting issue details... STATUS

1st test case

Description: 1 tenant - 4 credentials
Run parameters: Xmx128m
Result: FAILED WITH OOM
Logsone-tenant-4-creds-OOM.log
Heap dumpsone-tenant-heap-dump.7z

Credentials:

API Endpoint

Customer ID

https://api.ebsco.io

apidvgvmt

https://api.ebsco.io

apidvcorp

https://api.ebsco.io

apie2esch1

https://api.ebsco.io

ns273786

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

  1. 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
Logsone-tenant-4-creds-success.log
Heap dumps: -

Credentials:

API Endpoint

Customer ID

https://api.ebsco.io

apidvgvmt

https://api.ebsco.io

apidvcorp

https://api.ebsco.io

apie2esch1

https://api.ebsco.io

ns273786

Details

During the process of loading several exceptions happened:

  1. Creation of snapshot was failed on RMAPI side. The retrying process worked successfully and the creation of the snapshot succeeded in 3 hours.
  2. 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.
  3. 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

  1. Investigate why snapshot creation could fail.
  2. Investigate why the "title_id" property could be empty.
  3. 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

  1. 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
Logstwo-tenants-8-creds-success-log.zip
Heap dumps: - 

Credentials:

Details

During the process of loading several exceptions happened:

  1. Creation of snapshot was failed on RMAPI side. The retrying process worked successfully and the creation of the snapshot succeeded in 3 hours.
  2. 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.
  3. 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

    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

  1. Investigate why holdings_status failed to update.

Open questions

  1. 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.
  2. Consider moving the process of holdings loading to a new module. This will reduce the load on kb-ebsco module.
  • No labels