Uploaded image for project: 'Debezium'
  1. Debezium
  2. DBZ-5339

Debezium Outbox Extension throws StaleStateException when configured to remove event after insertion

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Unresolved
    • Icon: Major Major
    • 1.9-backlog, 2.4-backlog
    • 1.9.4.Final
    • None
    • None
    • False
    • None
    • False

       

      Following the  https://issues.redhat.com/browse/DBZ-5251 with the solution, you give I was able to move forward a bit with the example using Debezium 1.9.2 and Quarkus 2.9

       

      But then when I used the Debezium Outbox Quarkus pattern extension, O got the following exception:

       

       

      2022-06-30 17:42:58,701 ERROR [org.jbo.res.rea.com.cor.AbstractResteasyReactiveContext] (executor-thread-1) Request failed: io.quarkus.arc.ArcUndeclaredThrowableException: Error invoking subclass method
          at org.acme.GameService_Subclass.insertGame(Unknown Source)
          at org.acme.GameService_ClientProxy.insertGame(Unknown Source)
          at org.acme.GameResource.insert(GameResource.java:25)
          at org.acme.GameResource_Subclass.insert$$superforward1(Unknown Source)
          at org.acme.GameResource_Subclass$$function$$1.apply(Unknown Source)
          at io.quarkus.arc.impl.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:54)
          at io.quarkus.arc.runtime.devconsole.InvocationInterceptor.proceed(InvocationInterceptor.java:62)
          at io.quarkus.arc.runtime.devconsole.InvocationInterceptor.monitor(InvocationInterceptor.java:49)
          at io.quarkus.arc.runtime.devconsole.InvocationInterceptor_Bean.intercept(Unknown Source)
          at io.quarkus.arc.impl.InterceptorInvocation.invoke(InterceptorInvocation.java:41)
          at io.quarkus.arc.impl.AroundInvokeInvocationContext.perform(AroundInvokeInvocationContext.java:41)
          at io.quarkus.arc.impl.InvocationContexts.performAroundInvoke(InvocationContexts.java:32)
          at org.acme.GameResource_Subclass.insert(Unknown Source)
          at org.acme.GameResource$quarkusrestinvoker$insert_40eed58497ae6e27ee747d9191e3b8c4b716cd21.invoke(Unknown Source)
          at org.jboss.resteasy.reactive.server.handlers.InvocationHandler.handle(InvocationHandler.java:29)
          at io.quarkus.resteasy.reactive.server.runtime.QuarkusResteasyReactiveRequestContext.invokeHandler(QuarkusResteasyReactiveRequestContext.java:108)
          at org.jboss.resteasy.reactive.common.core.AbstractResteasyReactiveContext.run(AbstractResteasyReactiveContext.java:141)
          at io.quarkus.vertx.core.runtime.VertxCoreRecorder$14.runWith(VertxCoreRecorder.java:550)
          at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2449)
          at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1478)
          at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29)
          at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29)
          at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
          at java.base/java.lang.Thread.run(Thread.java:833)
      Caused by: javax.transaction.RollbackException: ARJUNA016053: Could not commit transaction.
          at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1307)
          at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:128)
          at io.quarkus.narayana.jta.runtime.CDIDelegatingTransactionManager.commit(CDIDelegatingTransactionManager.java:105)
          at io.quarkus.narayana.jta.runtime.CDIDelegatingTransactionManager_Subclass.commit$$superforward1(Unknown Source)
          at io.quarkus.narayana.jta.runtime.CDIDelegatingTransactionManager_Subclass$$function$$6.apply(Unknown Source)
          at io.quarkus.arc.impl.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:54)
          at io.quarkus.arc.runtime.devconsole.InvocationInterceptor.proceed(InvocationInterceptor.java:62)
          at io.quarkus.arc.runtime.devconsole.InvocationInterceptor.monitor(InvocationInterceptor.java:49)
          at io.quarkus.arc.runtime.devconsole.InvocationInterceptor_Bean.intercept(Unknown Source)
          at io.quarkus.arc.impl.InterceptorInvocation.invoke(InterceptorInvocation.java:41)
          at io.quarkus.arc.impl.AroundInvokeInvocationContext.perform(AroundInvokeInvocationContext.java:41)
          at io.quarkus.arc.impl.InvocationContexts.performAroundInvoke(InvocationContexts.java:32)
          at io.quarkus.narayana.jta.runtime.CDIDelegatingTransactionManager_Subclass.commit(Unknown Source)
          at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.endTransaction(TransactionalInterceptorBase.java:374)
          at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.invokeInOurTx(TransactionalInterceptorBase.java:166)
          at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.invokeInOurTx(TransactionalInterceptorBase.java:104)
          at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorRequired.doIntercept(TransactionalInterceptorRequired.java:38)
          at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.intercept(TransactionalInterceptorBase.java:58)
          at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorRequired.intercept(TransactionalInterceptorRequired.java:32)
          at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorRequired_Bean.intercept(Unknown Source)
          at io.quarkus.arc.impl.InterceptorInvocation.invoke(InterceptorInvocation.java:41)
          at io.quarkus.arc.impl.AroundInvokeInvocationContext.perform(AroundInvokeInvocationContext.java:41)
          at io.quarkus.arc.impl.InvocationContexts.performAroundInvoke(InvocationContexts.java:32)
          ... 24 more
      Caused by: javax.persistence.OptimisticLockException: Batch update returned unexpected row count from update [0]; actual row count: 0; expected: 1; statement executed: update OutboxEvent set payload=? where id=?
          at org.hibernate.internal.ExceptionConverterImpl.wrapStaleStateException(ExceptionConverterImpl.java:238)
          at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:93)
          at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:181)
          at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:188)
          at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1411)
          at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:489)
          at org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:3290)
          at org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:2425)
          at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:449)
          at org.hibernate.resource.transaction.backend.jta.internal.JtaTransactionCoordinatorImpl.beforeCompletion(JtaTransactionCoordinatorImpl.java:356)
          at org.hibernate.resource.transaction.backend.jta.internal.synchronization.SynchronizationCallbackCoordinatorNonTrackingImpl.beforeCompletion(SynchronizationCallbackCoordinatorNonTrackingImpl.java:47)
          at org.hibernate.resource.transaction.backend.jta.internal.synchronization.RegisteredSynchronization.beforeCompletion(RegisteredSynchronization.java:37)
          at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.beforeCompletion(SynchronizationImple.java:76)
          at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.beforeCompletion(TwoPhaseCoordinator.java:360)
          at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:91)
          at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162)
          at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1295)
          ... 46 more
      Caused by: org.hibernate.StaleStateException: Batch update returned unexpected row count from update [0]; actual row count: 0; expected: 1; statement executed: update OutboxEvent set payload=? where id=?
          at org.hibernate.jdbc.Expectations$BasicExpectation.checkBatched(Expectations.java:67)
          at org.hibernate.jdbc.Expectations$BasicExpectation.verifyOutcome(Expectations.java:54)
          at org.hibernate.engine.jdbc.batch.internal.NonBatchingBatch.addToBatch(NonBatchingBatch.java:47)
          at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:3571)
          at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:3438)
          at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:3852)
          at org.hibernate.action.internal.EntityUpdateAction.execute(EntityUpdateAction.java:201)
          at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:604)

          at org.hibernate.engine.spi.ActionQueue.lambda$executeActions$1(ActionQueue.java:478)
          at java.base/java.util.LinkedHashMap.forEach(LinkedHashMap.java:721)
          at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:475)
          at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:344)
          at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:40)
          at org.hibernate.event.service.internal.EventListenerGroupImpl.fireEventOnEachListener(EventListenerGroupImpl.java:107)
          at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1407)
          ... 58 more

       

      This happens when the Outbox event is deleted., so it's created and updated correctly but deleted operation throws this exception.

       

      Then just to try I decide to update to Debezium 1.9.4 and Quarkus 2.10 and just when the app is starting it throws this expcetion

      2022-06-30 17:48:13,760 ERROR [io.deb.emb.EmbeddedEngine] (executor-thread-0) Error while trying to run connector class 'io.debezium.connector.mysql.MySqlConnector': org.apache.kafka.connect.errors.ConnectException: An exception occurred in the change event producer. This connector will be stopped.
          at io.debezium.pipeline.ErrorHandler.setProducerThrowable(ErrorHandler.java:50)
          at io.debezium.pipeline.ChangeEventSourceCoordinator.lambda$start$0(ChangeEventSourceCoordinator.java:116)
          at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
          at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
          at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
          at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
          at java.base/java.lang.Thread.run(Thread.java:833)
      Caused by: java.lang.NoSuchMethodError: 'io.debezium.schema.SchemaChangeEvent io.debezium.schema.SchemaChangeEvent.of(io.debezium.schema.SchemaChangeEvent$SchemaChangeEventType, io.debezium.pipeline.spi.Partition, io.debezium.pipeline.spi.OffsetContext, java.lang.String, java.lang.String, java.lang.String, io.debezium.relational.Table, boolean)'
          at io.debezium.connector.mysql.MySqlDatabaseSchema.emitChangeEvent(MySqlDatabaseSchema.java:306)
          at io.debezium.connector.mysql.MySqlDatabaseSchema.lambda$parseDdl$5(MySqlDatabaseSchema.java:279)
          at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)
          at io.debezium.connector.mysql.MySqlDatabaseSchema.lambda$parseDdl$6(MySqlDatabaseSchema.java:258)
          at io.debezium.relational.ddl.DdlChanges.getEventsByDatabase(DdlChanges.java:144)
          at io.debezium.connector.mysql.MySqlDatabaseSchema.parseDdl(MySqlDatabaseSchema.java:248)
          at io.debezium.connector.mysql.MySqlDatabaseSchema.parseSnapshotDdl(MySqlDatabaseSchema.java:204)
          at io.debezium.connector.mysql.MySqlSnapshotChangeEventSource.addSchemaEvent(MySqlSnapshotChangeEventSource.java:302)
          at io.debezium.connector.mysql.MySqlSnapshotChangeEventSource.readTableStructure(MySqlSnapshotChangeEventSource.java:334)
          at io.debezium.connector.mysql.MySqlSnapshotChangeEventSource.readTableStructure(MySqlSnapshotChangeEventSource.java:46)
          at io.debezium.relational.RelationalSnapshotChangeEventSource.doExecute(RelationalSnapshotChangeEventSource.java:114)
          at io.debezium.pipeline.source.AbstractSnapshotChangeEventSource.execute(AbstractSnapshotChangeEventSource.java:76)
          at io.debezium.pipeline.ChangeEventSourceCoordinator.doSnapshot(ChangeEventSourceCoordinator.java:155)
          at io.debezium.pipeline.ChangeEventSourceCoordinator.executeChangeEventSources(ChangeEventSourceCoordinator.java:137)
          at io.debezium.pipeline.ChangeEventSourceCoordinator.lambda$start$0(ChangeEventSourceCoordinator.java:109)
          ... 5 more

       

      So there are two errors in one issue, I know but this is how I found them to give you the context.

       

       The code is at https://github.com/lordofthejars/movie-plays-kafka/tree/main/movie-plays-producer-debezium

       

      You can start using Quarkus dev mode and Docker started.

       

      For the first exception just post a new game:

       

      curl -X 'POST' \
        'http://localhost:8080/game' \
        -H 'accept: application/json' \
        -H 'Content-Type: application/json' \
        -d '

      {   "name": "string2" }

      '

       

       

       

      Thank you very much.

       

      Alex.

       

       

      Bug report

      For bug reports, provide this information, please:

      What Debezium connector do you use and what version?

      <Your answer>

      What is the connector configuration?

      <Your answer>

      What is the captured database version and mode of depoyment?

      (E.g. on-premises, with a specific cloud provider, etc.)

      <Your answer>

      What behaviour do you expect?

      <Your answer>

      What behaviour do you see?

      <Your answer>

      Do you see the same behaviour using the latest relesead Debezium version?

      (Ideally, also verify with latest Alpha/Beta/CR version)

      <Your answer>

      Do you have the connector logs, ideally from start till finish?

      (You might be asked later to provide DEBUG/TRACE level log)

      <Your answer>

      How to reproduce the issue using our tutorial deployment?

      <Your answer>

      Feature request or enhancement

      For feature requests or enhancements, provide this information, please:

      Which use case/requirement will be addressed by the proposed feature?

      <Your answer>

      Implementation ideas (optional)

      <Your answer>

            ccranfor@redhat.com Chris Cranford
            asotobue Alex Soto (Inactive)
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

              Created:
              Updated: