Uploaded image for project: 'mod-source-record-storage'
  1. mod-source-record-storage
  2. MODSOURCE-278

Record from chunk is not saved occasionally

    XMLWordPrintable

Details

    • Folijet Sprint 113, Folijet Sprint 114, Folijet Sprint 115
    • 3
    • Folijet
    • R1 2021 Hot Fix #1
    • Yes

    Description

      This issue has been observed in a iris-bugfest environment.

      The error occurs occasionally on saving records from received event "DI_RAW_RECORDS_CHUNK_PARSED" to database.

      This is an issue that causes jobs to get stuck, so if no stuck jobs, that's a good indication that things are better

      Module log contains the following snippet:

      2021-04-26T05:15:55.631Z 05:15:55.631 [vert.x-worker-thread-15] DEBUG rdChunksKafkaHandler [210340650eqId] RecordCollection has been received, correlationId: 2a400513-5918-4b02-bf4a-ce97c6083cac, starting processing... chunkNumber 232-73
      2021-04-26T05:15:55.799Z 05:15:55.797 [vert.x-worker-thread-15] ERROR ?                    [210340816eqId] Unhandled exception
      2021-04-26T05:15:55.799Z org.jooq.exception.DataAccessException: SQL [null]; ERROR: insert or update on table "raw_records_lb" violates foreign key constraint "fk_raw_records_records"
      2021-04-26T05:15:55.799Z   Detail: Key (id)=(b73ab5c9-28bb-407f-9fab-2dbefbc739e4) is not present in table "records_lb".
      2021-04-26T05:15:55.799Z 	at org.jooq.impl.Tools.translate(Tools.java:2753) ~[ms.jar:?]
      2021-04-26T05:15:55.799Z 	at org.jooq.impl.LoaderImpl.executeRows(LoaderImpl.java:723) ~[ms.jar:?]
      2021-04-26T05:15:55.799Z 	at org.jooq.impl.LoaderImpl.execute(LoaderImpl.java:649) ~[ms.jar:?]
      2021-04-26T05:15:55.799Z 	at org.jooq.impl.LoaderImpl.execute(LoaderImpl.java:97) ~[ms.jar:?]
      2021-04-26T05:15:55.799Z 	at org.folio.dao.RecordDaoImpl.lambda$24(RecordDaoImpl.java:432) ~[ms.jar:?]
      2021-04-26T05:15:55.799Z 	at org.jooq.impl.DefaultDSLContext$3.run(DefaultDSLContext.java:636) ~[ms.jar:?]
      2021-04-26T05:15:55.799Z 	at org.jooq.impl.DefaultDSLContext$3.run(DefaultDSLContext.java:633) ~[ms.jar:?]
      2021-04-26T05:15:55.799Z 	at org.jooq.impl.DefaultDSLContext.lambda$transactionResult0$0(DefaultDSLContext.java:564) ~[ms.jar:?]
      2021-04-26T05:15:55.799Z 	at org.jooq.impl.Tools$12$1.block(Tools.java:4926) ~[ms.jar:?]
      2021-04-26T05:15:55.799Z 	at java.util.concurrent.ForkJoinPool.managedBlock(ForkJoinPool.java:3128) ~[?:?]
      2021-04-26T05:15:55.799Z 	at org.jooq.impl.Tools$12.get(Tools.java:4923) ~[ms.jar:?]
      2021-04-26T05:15:55.799Z 	at org.jooq.impl.DefaultDSLContext.transactionResult0(DefaultDSLContext.java:616) ~[ms.jar:?]
      2021-04-26T05:15:55.799Z 	at org.jooq.impl.DefaultDSLContext.transactionResult(DefaultDSLContext.java:533) ~[ms.jar:?]
      2021-04-26T05:15:55.799Z 	at org.jooq.impl.DefaultDSLContext.transaction(DefaultDSLContext.java:633) ~[ms.jar:?]
      2021-04-26T05:15:55.799Z 	at org.folio.dao.RecordDaoImpl.saveRecords(RecordDaoImpl.java:362) ~[ms.jar:?]
      2021-04-26T05:15:55.799Z 	at org.folio.services.RecordServiceImpl.saveRecords(RecordServiceImpl.java:114) ~[ms.jar:?]
      2021-04-26T05:15:55.799Z 	at org.folio.services.ParsedRecordChunksKafkaHandler.handle(ParsedRecordChunksKafkaHandler.java:79) ~[ms.jar:?]
      2021-04-26T05:15:55.799Z 	at org.folio.kafka.KafkaConsumerWrapper.handle(KafkaConsumerWrapper.java:173) ~[ms.jar:?]
      2021-04-26T05:15:55.799Z 	at org.folio.kafka.KafkaConsumerWrapper.handle(KafkaConsumerWrapper.java:24) ~[ms.jar:?]
      2021-04-26T05:15:55.799Z 	at io.vertx.kafka.client.consumer.impl.KafkaConsumerImpl.lambda$handler$1(KafkaConsumerImpl.java:81) ~[ms.jar:?]
      2021-04-26T05:15:55.799Z 	at io.vertx.kafka.client.consumer.impl.KafkaReadStreamImpl.run(KafkaReadStreamImpl.java:237) ~[ms.jar:?]
      2021-04-26T05:15:55.799Z 	at io.vertx.kafka.client.consumer.impl.KafkaReadStreamImpl.lambda$schedule$8(KafkaReadStreamImpl.java:192) ~[ms.jar:?]
      2021-04-26T05:15:55.799Z 	at io.vertx.core.impl.AbstractContext.dispatch(AbstractContext.java:96) ~[ms.jar:?]
      2021-04-26T05:15:55.799Z 	at io.vertx.core.impl.WorkerContext.lambda$run$1(WorkerContext.java:102) ~[ms.jar:?]
      2021-04-26T05:15:55.799Z 	at io.vertx.core.impl.TaskQueue.run(TaskQueue.java:76) ~[ms.jar:?]
      2021-04-26T05:15:55.799Z 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
      2021-04-26T05:15:55.799Z 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
      2021-04-26T05:15:55.799Z 	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [ms.jar:?]
      2021-04-26T05:15:55.799Z 	at java.lang.Thread.run(Thread.java:829) [?:?]
      2021-04-26T05:15:55.799Z Caused by: org.postgresql.util.PSQLException: ERROR: insert or update on table "raw_records_lb" violates foreign key constraint "fk_raw_records_records"
      2021-04-26T05:15:55.799Z   Detail: Key (id)=(b73ab5c9-28bb-407f-9fab-2dbefbc739e4) is not present in table "records_lb".
      2021-04-26T05:15:55.799Z 	at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2553) ~[ms.jar:?]
      2021-04-26T05:15:55.799Z 	at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2285) ~[ms.jar:?]
      2021-04-26T05:15:55.799Z 	at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:323) ~[ms.jar:?]
      2021-04-26T05:15:55.799Z 	at org.postgresql.jdbc.PgConnection.executeTransactionCommand(PgConnection.java:857) ~[ms.jar:?]
      2021-04-26T05:15:55.799Z 	at org.postgresql.jdbc.PgConnection.commit(PgConnection.java:879) ~[ms.jar:?]
      2021-04-26T05:15:55.799Z 	at jdk.internal.reflect.GeneratedMethodAccessor307.invoke(Unknown Source) ~[?:?]
      2021-04-26T05:15:55.799Z 	at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
      2021-04-26T05:15:55.799Z 	at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]
      2021-04-26T05:15:55.799Z 	at org.postgresql.ds.PGPooledConnection$ConnectionHandler.invoke(PGPooledConnection.java:348) ~[ms.jar:?]
      2021-04-26T05:15:55.799Z 	at com.sun.proxy.$Proxy88.commit(Unknown Source) ~[?:?]
      2021-04-26T05:15:55.799Z 	at org.jooq.impl.LoaderImpl.commit(LoaderImpl.java:914) ~[ms.jar:?]
      2021-04-26T05:15:55.799Z 	at org.jooq.impl.LoaderImpl.executeSQL(LoaderImpl.java:902) ~[ms.jar:?]
      2021-04-26T05:15:55.799Z 	at org.jooq.impl.LoaderImpl.executeRows(LoaderImpl.java:717) ~[ms.jar:?]
      2021-04-26T05:15:55.799Z 	... 27 more
      

      TestRail: Results

        Attachments

          Issue Links

            Activity

              People

                ruslan_lavrov Ruslan Lavrov
                ruslan_lavrov Ruslan Lavrov
                Votes:
                0 Vote for this issue
                Watchers:
                4 Start watching this issue

                Dates

                  Created:
                  Updated:
                  Resolved:

                  TestRail: Runs

                    TestRail: Cases