microservices-patterns / ftgo-application

Example code for the book Microservice patterns
Other
3.41k stars 1.32k forks source link

Attempt to revise a cancelled order breaks the system - and all subsequently created orders are broken #70

Open asn25 opened 4 years ago

asn25 commented 4 years ago

Hi,

if I try to revise a cancelled order, it breaks application and all newly created order orders will be corrupted (in APPROVAL_PENDING state).

Quick steps to reproduce (all services are up): 1) run EndToEndTest (to quickly get a cancelled order) 2) run a revise instruction in console: curl -X POST "http://${DOCKER_HOST_IP}:8082/orders/1/revise" -H "Content-Type: application/json" -d "{\"revisedLineItemQuantities\": {\"1\": 14}}"

In Order Service log there will be an exception (provided below). After that any attemp to run EndToEndTest will fail. Also any attempt to create order will make order in APPROVED_PENDING state (not APPROVED). (F.e. run EndToEndTest with only createOrder() in test method and see that it creates order in APPROVED_PENDING state).

The solution to enable making normal orders is only to restart all the system (docker-compose down & up).

It seems, this issue is connected with ReviseOrder does not work correctly #38

=====

ftgo-order-service1 | 2019-12-30T20:10:35.360318564Z 2019-12-30 20:10:35.359 DEBUG [ftgo-order-service,1d507059884fc51a,1d507059884fc51a,true] 1 --- [nio-8080-exec-7] org.hibernate.SQL : select order0.id as id1_30, order0_.consumer_id as consumer2_30, order0_.ci ty as city3_30, order0_.delivery_state as delivery4_30, order0_.street1 as street5_30, order0_.street2 as street6_30, order0_.zip as zip7_30, order0_.delivery_time as delivery8_30, order0_.order_minimum as order_mi9_30, order0_.payment_token as payment10_30, order0_.restaurant_id as restaur11_30, order0_.state as state12_30, order0_.version as version13_30 from orders order0 where order0.id=? ftgo-order-service_1 | 2019-12-30T20:10:35.367576205Z 2019-12-30 20:10:35.364 INFO [ftgo-order-service,1d507059884fc51a,1d507059884fc51a,true] 1 --- [nio-8080-exec-7] i.e.t.s.o.SagaInstanceRepositoryJdbc : Saving net.chrisrichardson.ftgo.orderservice.sagas.reviseorder.ReviseOrderSaga 0 000016f586e83e4-0242ac1b000d0000 ftgo-order-service_1 | 2019-12-30T20:10:35.367632999Z 2019-12-30 20:10:35.367 INFO [ftgo-order-service,1d507059884fc51a,1d507059884fc51a,true] 1 --- [nio-8080-exec-7] i.e.t.s.o.SagaInstanceRepositoryJdbc : Updating net.chrisrichardson.ftgo.orderservice.sagas.reviseorder.ReviseOrderSaga 0000016f586e83e4-0242ac1b000d0000 ftgo-order-service1 | 2019-12-30T20:10:35.378096424Z 2019-12-30 20:10:35.375 DEBUG [ftgo-order-service,1d507059884fc51a,1d507059884fc51a,true] 1 --- [nio-8080-exec-7] org.hibernate.SQL : select lineitems0.order_id as order_id1_00, lineitems0_.menu_itemid as menu ite2_00, lineitems0_.name as name3_00, lineitems0_.price as price4_00, lineitems0_.quantity as quantity5_00 from order_lineitems lineitems0 where lineitems0_.order_id=? ftgo-order-service_1 | 2019-12-30T20:10:35.394036555Z 2019-12-30 20:10:35.393 DEBUG [ftgo-order-service,,,] 1 --- [er-orderService] i.e.m.k.b.c.EventuateKafkaConsumer : Got orderService 1 records ftgo-order-service_1 | 2019-12-30T20:10:35.394068052Z 2019-12-30 20:10:35.393 DEBUG [ftgo-order-service,,,] 1 --- [er-orderService] i.e.m.k.b.c.EventuateKafkaConsumer : processing record orderService 3 {"payload":"{\"orderId\":1,\"revision\":{\"revisedLineItemQuantities\":{\"1\":14}}} ","headers":{"command_saga_id":"0000016f586e83e4-0242ac1b000d0000","DATE":"Mon, 30 Dec 2019 20:10:35 GMT","command_type":"net.chrisrichardson.ftgo.orderservice.sagaparticipants.commands.BeginReviseOrderCommand","X-B3-SpanId":"8bee9ff4d866d17f","command_reply_to":"net.chrisrichardson.ftgo.orderservic e.sagas.reviseorder.ReviseOrderSaga-reply","DESTINATION":"orderService","command_saga_type":"net.chrisrichardson.ftgo.orderservice.sagas.reviseorder.ReviseOrderSaga","X-B3-ParentSpanId":"1d507059884fc51a","X-B3-Sampled":"1","X-B3-TraceId":"1d507059884fc51a","commanddestination":"orderService","ID" :"0000016f586e83e5-0242ac1b000d0000"}} ftgo-order-service_1 | 2019-12-30T20:10:35.395375641Z 2019-12-30 20:10:35.393 DEBUG [ftgo-order-service,,,] 1 --- [er-orderService] i.e.m.k.b.c.EventuateKafkaConsumer : EventuateKafkaAggregateSubscriptions subscriber = orderService, offset = 3, key = 0000016f586e83e5-0242ac1b000d0000, value = {"payload":"{\"orderId\":1,\"revision\":{\"revisedLineItemQuantities\":{\"1\":14}}}","headers":{"command_saga_id":"0000016f586e83e4-0242ac1b000d0000","DATE":"Mon, 30 Dec 2019 20:10:35 GMT","command_type":"net.chrisrichardson.ftgo.orderservice.sagaparticipants.commands.BeginReviseOrderComman d","X-B3-SpanId":"8bee9ff4d866d17f","command_reply_to":"net.chrisrichardson.ftgo.orderservice.sagas.reviseorder.ReviseOrderSaga-reply","DESTINATION":"orderService","command_saga_type":"net.chrisrichardson.ftgo.orderservice.sagas.reviseorder.ReviseOrderSaga","X-B3-ParentSpanId":"1d507059884fc51a","X- B3-Sampled":"1","X-B3-TraceId":"1d507059884fc51a","commanddestination":"orderService","ID":"0000016f586e83e5-0242ac1b000d0000"}} ftgo-order-service_1 | 2019-12-30T20:10:35.396870354Z 2019-12-30 20:10:35.395 DEBUG [ftgo-order-service,,,] 1 --- [er-orderService] i.e.m.k.b.c.EventuateKafkaConsumer : Processed orderService 1 records ftgo-order-service_1 | 2019-12-30T20:10:35.396892657Z 2019-12-30 20:10:35.396 DEBUG [ftgo-order-service,,,] 1 --- [er-orderService] i.e.m.k.b.c.EventuateKafkaConsumer : To commit orderService io.eventuate.messaging.kafka.basic.consumer.OffsetTracker@3fa27bf1[state={orderService-1=io.e ventuate.messaging.kafka.basic.consumer.TopicPartitionOffsets@4fa9dccb[unprocessed=[3],processed=[]], orderService-0=io.eventuate.messaging.kafka.basic.consumer.TopicPartitionOffsets@60ec48c8[unprocessed=[],processed=[]]}] ftgo-order-service_1 | 2019-12-30T20:10:35.410718176Z 2019-12-30 20:10:35.410 TRACE [ftgo-order-service,1d507059884fc51a,07c4e05527db0f95,true] 1 --- [pool-4-thread-1] i.e.t.c.c.DecoratedMessageHandlerFactory : Invoking handler orderService 0000016f586e83e5-0242ac1b000d0000 ftgo-order-service_1 | 2019-12-30T20:10:35.411568467Z 2019-12-30 20:10:35.410 TRACE [ftgo-order-service,1d507059884fc51a,07c4e05527db0f95,true] 1 --- [pool-4-thread-1] i.e.t.s.p.SagaCommandDispatcher : Received message orderService io.eventuate.tram.messaging.common.MessageImpl@684 31cef[payload={"orderId":1,"revision":{"revisedLineItemQuantities":{"1":14}}},headers={command_saga_id=0000016f586e83e4-0242ac1b000d0000, DATE=Mon, 30 Dec 2019 20:10:35 GMT, command_type=net.chrisrichardson.ftgo.orderservice.sagaparticipants.commands.BeginReviseOrderCommand, command_reply_to=net.chr isrichardson.ftgo.orderservice.sagas.reviseorder.ReviseOrderSaga-reply, DESTINATION=orderService, command_saga_type=net.chrisrichardson.ftgo.orderservice.sagas.reviseorder.ReviseOrderSaga, commanddestination=orderService, ID=0000016f586e83e5-0242ac1b000d0000, X-B3-TraceId=1d507059884fc51a, X-B3-Sp anId=07c4e05527db0f95, X-B3-ParentSpanId=8bee9ff4d866d17f, X-B3-Sampled=1}] ftgo-order-service1 | 2019-12-30T20:10:35.412520264Z 2019-12-30 20:10:35.412 DEBUG [ftgo-order-service,1d507059884fc51a,07c4e05527db0f95,true] 1 --- [pool-4-thread-1] org.hibernate.SQL : select order0.id as id1_30, order0_.consumer_id as consumer2_30, order0_.ci ty as city3_30, order0_.delivery_state as delivery4_30, order0_.street1 as street5_30, order0_.street2 as street6_30, order0_.zip as zip7_30, order0_.delivery_time as delivery8_30, order0_.order_minimum as order_mi9_30, order0_.payment_token as payment10_30, order0_.restaurant_id as restaur11_30, order0_.state as state12_30, order0_.version as version13_30 from orders order0 where order0.id=? ftgo-order-service_1 | 2019-12-30T20:10:35.418422357Z 2019-12-30 20:10:35.418 TRACE [ftgo-order-service,1d507059884fc51a,07c4e05527db0f95,true] 1 --- [pool-4-thread-1] i.e.t.s.p.SagaCommandDispatcher : Generated replies orderService io.eventuate.tram.messaging.common.MessageImpl@68 431cef[payload={"orderId":1,"revision":{"revisedLineItemQuantities":{"1":14}}},headers={command_saga_id=0000016f586e83e4-0242ac1b000d0000, DATE=Mon, 30 Dec 2019 20:10:35 GMT, command_type=net.chrisrichardson.ftgo.orderservice.sagaparticipants.commands.BeginReviseOrderCommand, command_reply_to=net.ch risrichardson.ftgo.orderservice.sagas.reviseorder.ReviseOrderSaga-reply, DESTINATION=orderService, command_saga_type=net.chrisrichardson.ftgo.orderservice.sagas.reviseorder.ReviseOrderSaga, commanddestination=orderService, ID=0000016f586e83e5-0242ac1b000d0000, X-B3-TraceId=1d507059884fc51a, X-B3-S panId=07c4e05527db0f95, X-B3-ParentSpanId=8bee9ff4d866d17f, X-B3-Sampled=1}] [io.eventuate.tram.messaging.common.MessageImpl@5add8f98[payload={},headers={reply_outcome-type=FAILURE, reply_type=io.eventuate.tram.commands.common.Failure}]] ftgo-order-service_1 | 2019-12-30T20:10:35.421817509Z 2019-12-30 20:10:35.421 TRACE [ftgo-order-service,1d507059884fc51a,07c4e05527db0f95,true] 1 --- [pool-4-thread-1] i.e.t.c.c.DecoratedMessageHandlerFactory : handled message orderService 0000016f586e83e5-0242ac1b000d0000 ftgo-order-service_1 | 2019-12-30T20:10:35.435043854Z 2019-12-30 20:10:35.433 ERROR [ftgo-order-service,,,] 1 --- [pool-4-thread-1] i.e.m.k.b.c.KafkaMessageProcessor : Got exception: ftgo-order-service_1 | 2019-12-30T20:10:35.435153843Z ftgo-order-service_1 | 2019-12-30T20:10:35.435171594Z org.springframework.orm.jpa.JpaSystemException: Transaction was marked for rollback only; cannot commit; nested exception is org.hibernate.TransactionException: Transaction was marked for rollback only; cannot commit ftgo-order-service_1 | 2019-12-30T20:10:35.435184957Z at org.springframework.orm.jpa.vendor.HibernateJpaDialect.convertHibernateAccessException(HibernateJpaDialect.java:314) ~[spring-orm-5.0.7.RELEASE.jar!/:5.0.7.RELEASE] ftgo-order-service_1 | 2019-12-30T20:10:35.435197241Z at org.springframework.orm.jpa.vendor.HibernateJpaDialect.translateExceptionIfPossible(HibernateJpaDialect.java:225) ~[spring-orm-5.0.7.RELEASE.jar!/:5.0.7.RELEASE] ftgo-order-service_1 | 2019-12-30T20:10:35.435210351Z at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:540) ~[spring-orm-5.0.7.RELEASE.jar!/:5.0.7.RELEASE] ftgo-order-service_1 | 2019-12-30T20:10:35.435225533Z at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:746) ~[spring-tx-5.0.7.RELEASE.jar!/:5.0.7.RELEASE] ftgo-order-service_1 | 2019-12-30T20:10:35.435238864Z at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:714) ~[spring-tx-5.0.7.RELEASE.jar!/:5.0.7.RELEASE] ftgo-order-service_1 | 2019-12-30T20:10:35.435253156Z at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:152) ~[spring-tx-5.0.7.RELEASE.jar!/:5.0.7.RELEASE] ftgo-order-service_1 | 2019-12-30T20:10:35.435267883Z at io.eventuate.tram.consumer.jdbc.SqlTableBasedDuplicateMessageDetector.doWithMessage(SqlTableBasedDuplicateMessageDetector.java:50) ~[eventuate-tram-consumer-jdbc-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T20:10:35.435282472Z at io.eventuate.tram.consumer.common.DuplicateDetectingMessageHandlerDecorator.accept(DuplicateDetectingMessageHandlerDecorator.java:15) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T20:10:35.435296703Z at io.eventuate.tram.consumer.common.DuplicateDetectingMessageHandlerDecorator.accept(DuplicateDetectingMessageHandlerDecorator.java:5) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T20:10:35.435314086Z at io.eventuate.tram.consumer.common.MessageHandlerDecoratorChainBuilder.lambda$buildChain$0(MessageHandlerDecoratorChainBuilder.java:38) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T20:10:35.435329593Z at io.eventuate.tram.consumer.common.PrePostReceiveMessageHandlerDecorator.accept(PrePostReceiveMessageHandlerDecorator.java:25) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T20:10:35.435367914Z at io.eventuate.tram.consumer.common.PrePostReceiveMessageHandlerDecorator.accept(PrePostReceiveMessageHandlerDecorator.java:11) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T20:10:35.435387508Z at io.eventuate.tram.consumer.common.MessageHandlerDecoratorChainBuilder.lambda$buildChain$0(MessageHandlerDecoratorChainBuilder.java:38) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T20:10:35.435402273Z at io.eventuate.tram.consumer.common.MessageConsumerImpl.lambda$subscribe$0(MessageConsumerImpl.java:34) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T20:10:35.435414509Z at io.eventuate.tram.consumer.kafka.EventuateTramKafkaMessageConsumer.lambda$subscribe$0(EventuateTramKafkaMessageConsumer.java:24) ~[eventuate-tram-consumer-kafka-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T20:10:35.435426707Z at io.eventuate.messaging.kafka.consumer.MessageConsumerKafkaImpl.handle(MessageConsumerKafkaImpl.java:60) [eventuate-messaging-kafka-consumer-0.3.0.RELEASE.jar!/:na] ftgo-order-service_1 | 2019-12-30T20:10:35.435467274Z at io.eventuate.messaging.kafka.consumer.MessageConsumerKafkaImpl.lambda$null$0(MessageConsumerKafkaImpl.java:40) [eventuate-messaging-kafka-consumer-0.3.0.RELEASE.jar!/:na] ftgo-order-service_1 | 2019-12-30T20:10:35.435482547Z at io.eventuate.messaging.kafka.consumer.SwimlaneDispatcher.processQueuedMessage(SwimlaneDispatcher.java:72) ~[eventuate-messaging-kafka-consumer-0.3.0.RELEASE.jar!/:na] ftgo-order-service_1 | 2019-12-30T20:10:35.435497631Z at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[na:1.8.0_171] ftgo-order-service_1 | 2019-12-30T20:10:35.435512314Z at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[na:1.8.0_171] ftgo-order-service_1 | 2019-12-30T20:10:35.435526638Z at java.lang.Thread.run(Thread.java:748) ~[na:1.8.0_171] ftgo-order-service_1 | 2019-12-30T20:10:35.435540366Z Caused by: org.hibernate.TransactionException: Transaction was marked for rollback only; cannot commit ftgo-order-service_1 | 2019-12-30T20:10:35.435556062Z at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.commit(JdbcResourceLocalTransactionCoordinatorImpl.java:228) ~[hibernate-core-5.2.17.Final.jar!/:5.2.17 .Final] ftgo-order-service_1 | 2019-12-30T20:10:35.435571274Z at org.hibernate.engine.transaction.internal.TransactionImpl.commit(TransactionImpl.java:68) ~[hibernate-core-5.2.17.Final.jar!/:5.2.17.Final] ftgo-order-service_1 | 2019-12-30T20:10:35.435585686Z at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:536) ~[spring-orm-5.0.7.RELEASE.jar!/:5.0.7.RELEASE] ftgo-order-service_1 | 2019-12-30T20:10:35.435600300Z ... 18 common frames omitted ftgo-order-service_1 | 2019-12-30T20:10:35.435614467Z ftgo-order-service_1 | 2019-12-30T20:10:35.440903706Z 2019-12-30 20:10:35.439 ERROR [ftgo-order-service,,,] 1 --- [pool-4-thread-1] i.e.m.kafka.consumer.SwimlaneDispatcher : Exception handling message - terminating ftgo-order-service_1 | 2019-12-30T20:10:35.441020394Z ftgo-order-service_1 | 2019-12-30T20:10:35.441035598Z org.springframework.orm.jpa.JpaSystemException: Transaction was marked for rollback only; cannot commit; nested exception is org.hibernate.TransactionException: Transaction was marked for rollback only; cannot commit ftgo-order-service_1 | 2019-12-30T20:10:35.441061474Z at org.springframework.orm.jpa.vendor.HibernateJpaDialect.convertHibernateAccessException(HibernateJpaDialect.java:314) ~[spring-orm-5.0.7.RELEASE.jar!/:5.0.7.RELEASE] ftgo-order-service_1 | 2019-12-30T20:10:35.441071936Z at org.springframework.orm.jpa.vendor.HibernateJpaDialect.translateExceptionIfPossible(HibernateJpaDialect.java:225) ~[spring-orm-5.0.7.RELEASE.jar!/:5.0.7.RELEASE] ftgo-order-service_1 | 2019-12-30T20:10:35.441081191Z at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:540) ~[spring-orm-5.0.7.RELEASE.jar!/:5.0.7.RELEASE] ftgo-order-service_1 | 2019-12-30T20:10:35.441090397Z at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:746) ~[spring-tx-5.0.7.RELEASE.jar!/:5.0.7.RELEASE] ftgo-order-service_1 | 2019-12-30T20:10:35.441099635Z at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:714) ~[spring-tx-5.0.7.RELEASE.jar!/:5.0.7.RELEASE] ftgo-order-service_1 | 2019-12-30T20:10:35.441108837Z at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:152) ~[spring-tx-5.0.7.RELEASE.jar!/:5.0.7.RELEASE] ftgo-order-service_1 | 2019-12-30T20:10:35.441117995Z at io.eventuate.tram.consumer.jdbc.SqlTableBasedDuplicateMessageDetector.doWithMessage(SqlTableBasedDuplicateMessageDetector.java:50) ~[eventuate-tram-consumer-jdbc-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T20:10:35.441127322Z at io.eventuate.tram.consumer.common.DuplicateDetectingMessageHandlerDecorator.accept(DuplicateDetectingMessageHandlerDecorator.java:15) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T20:10:35.441136524Z at io.eventuate.tram.consumer.common.DuplicateDetectingMessageHandlerDecorator.accept(DuplicateDetectingMessageHandlerDecorator.java:5) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T20:10:35.441147748Z at io.eventuate.tram.consumer.common.MessageHandlerDecoratorChainBuilder.lambda$buildChain$0(MessageHandlerDecoratorChainBuilder.java:38) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T20:10:35.441157612Z at io.eventuate.tram.consumer.common.PrePostReceiveMessageHandlerDecorator.accept(PrePostReceiveMessageHandlerDecorator.java:25) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T20:10:35.441166812Z at io.eventuate.tram.consumer.common.PrePostReceiveMessageHandlerDecorator.accept(PrePostReceiveMessageHandlerDecorator.java:11) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T20:10:35.441175961Z at io.eventuate.tram.consumer.common.MessageHandlerDecoratorChainBuilder.lambda$buildChain$0(MessageHandlerDecoratorChainBuilder.java:38) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T20:10:35.441185246Z at io.eventuate.tram.consumer.common.MessageConsumerImpl.lambda$subscribe$0(MessageConsumerImpl.java:34) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T20:10:35.441194447Z at io.eventuate.tram.consumer.kafka.EventuateTramKafkaMessageConsumer.lambda$subscribe$0(EventuateTramKafkaMessageConsumer.java:24) ~[eventuate-tram-consumer-kafka-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T20:10:35.441203670Z at io.eventuate.messaging.kafka.consumer.MessageConsumerKafkaImpl.handle(MessageConsumerKafkaImpl.java:60) ~[eventuate-messaging-kafka-consumer-0.3.0.RELEASE.jar!/:na] ftgo-order-service_1 | 2019-12-30T20:10:35.441212839Z at io.eventuate.messaging.kafka.consumer.MessageConsumerKafkaImpl.lambda$null$0(MessageConsumerKafkaImpl.java:40) ~[eventuate-messaging-kafka-consumer-0.3.0.RELEASE.jar!/:na] ftgo-order-service_1 | 2019-12-30T20:10:35.441228045Z at io.eventuate.messaging.kafka.consumer.SwimlaneDispatcher.processQueuedMessage(SwimlaneDispatcher.java:72) ~[eventuate-messaging-kafka-consumer-0.3.0.RELEASE.jar!/:na] ftgo-order-service_1 | 2019-12-30T20:10:35.441238278Z at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[na:1.8.0_171] ftgo-order-service_1 | 2019-12-30T20:10:35.441247184Z at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[na:1.8.0_171] ftgo-order-service_1 | 2019-12-30T20:10:35.441256046Z at java.lang.Thread.run(Thread.java:748) ~[na:1.8.0_171] ftgo-order-service_1 | 2019-12-30T20:10:35.441264807Z Caused by: org.hibernate.TransactionException: Transaction was marked for rollback only; cannot commit ftgo-order-service_1 | 2019-12-30T20:10:35.441274727Z at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.commit(JdbcResourceLocalTransactionCoordinatorImpl.java:228) ~[hibernate-core-5.2.17.Final.jar!/:5.2.17 .Final] ftgo-order-service_1 | 2019-12-30T20:10:35.441284661Z at org.hibernate.engine.transaction.internal.TransactionImpl.commit(TransactionImpl.java:68) ~[hibernate-core-5.2.17.Final.jar!/:5.2.17.Final] ftgo-order-service_1 | 2019-12-30T20:10:35.441293865Z at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:536) ~[spring-orm-5.0.7.RELEASE.jar!/:5.0.7.RELEASE] ftgo-order-service_1 | 2019-12-30T20:10:35.441302889Z ... 18 common frames omitted ftgo-order-service_1 | 2019-12-30T20:10:35.441311492Z

asn25 commented 4 years ago

Addition: If revise an APPROVED order and use non-existing menuItemId, revise process fails with exceptions (below) and subsequent revise attempts with correct menuItemId will not work.

Steps to reproduce: 1) run EndToEndTest with only createOrder() block in test-method. 2) run in console: curl -X POST "http://${DOCKER_HOST_IP}:8082/orders/1/revise" -H "Content-Type: application/json" -d "{\"revisedLineItemQuantities\": {\"aa\": 14}}" 3) Subsequent runs of revise with correct menuItemId will not work (data in order_line_items table is not changed): curl -X POST "http://${DOCKER_HOST_IP}:8082/orders/1/revise" -H "Content-Type: application/json" -d "{\"revisedLineItemQuantities\": {\"1\": 14}}"

====

ftgo-order-service_1 | 2019-12-30T19:49:31.194014151Z 2019-12-30 19:49:31.188 DEBUG [ftgo-order-service,,,] 1 --- [er-orderService] i.e.m.k.b.c.EventuateKafkaConsumer : processing record orderService 5 {"payload":"{\"orderId\":3,\"revision\":{\"revisedLineItemQuantities\":{\"aa\":14}} }","headers":{"command_saga_id":"0000016f585b399b-0242ac19000d0000","DATE":"Mon, 30 Dec 2019 19:49:31 GMT","command_type":"net.chrisrichardson.ftgo.orderservice.sagaparticipants.commands.BeginReviseOrderCommand","X-B3-SpanId":"c86bc2276b9e6741","command_reply_to":"net.chrisrichardson.ftgo.orderservi ce.sagas.reviseorder.ReviseOrderSaga-reply","DESTINATION":"orderService","command_saga_type":"net.chrisrichardson.ftgo.orderservice.sagas.reviseorder.ReviseOrderSaga","X-B3-ParentSpanId":"8c4a37f81ea884e4","X-B3-Sampled":"1","X-B3-TraceId":"8c4a37f81ea884e4","commanddestination":"orderService","ID ":"0000016f585b39a0-0242ac19000d0000"}} ftgo-order-service_1 | 2019-12-30T19:49:31.195277606Z 2019-12-30 19:49:31.193 DEBUG [ftgo-order-service,,,] 1 --- [er-orderService] i.e.m.k.b.c.EventuateKafkaConsumer : EventuateKafkaAggregateSubscriptions subscriber = orderService, offset = 5, key = 0000016f585b39a0-0242ac19000d0000, value = {"payload":"{\"orderId\":3,\"revision\":{\"revisedLineItemQuantities\":{\"aa\":14}}}","headers":{"command_saga_id":"0000016f585b399b-0242ac19000d0000","DATE":"Mon, 30 Dec 2019 19:49:31 GMT","command_type":"net.chrisrichardson.ftgo.orderservice.sagaparticipants.commands.BeginReviseOrderComma nd","X-B3-SpanId":"c86bc2276b9e6741","command_reply_to":"net.chrisrichardson.ftgo.orderservice.sagas.reviseorder.ReviseOrderSaga-reply","DESTINATION":"orderService","command_saga_type":"net.chrisrichardson.ftgo.orderservice.sagas.reviseorder.ReviseOrderSaga","X-B3-ParentSpanId":"8c4a37f81ea884e4","X -B3-Sampled":"1","X-B3-TraceId":"8c4a37f81ea884e4","commanddestination":"orderService","ID":"0000016f585b39a0-0242ac19000d0000"}} ftgo-order-service_1 | 2019-12-30T19:49:31.195713675Z 2019-12-30 19:49:31.195 DEBUG [ftgo-order-service,,,] 1 --- [er-orderService] i.e.m.k.b.c.EventuateKafkaConsumer : Processed orderService 1 records ftgo-order-service_1 | 2019-12-30T19:49:31.196228084Z 2019-12-30 19:49:31.195 DEBUG [ftgo-order-service,,,] 1 --- [er-orderService] i.e.m.k.b.c.EventuateKafkaConsumer : To commit orderService io.eventuate.messaging.kafka.basic.consumer.OffsetTracker@57c58419[state={orderService-1=io.e ventuate.messaging.kafka.basic.consumer.TopicPartitionOffsets@4dc44f1c[unprocessed=[],processed=[]], orderService-0=io.eventuate.messaging.kafka.basic.consumer.TopicPartitionOffsets@44dc77df[unprocessed=[5],processed=[]]}] ftgo-order-service_1 | 2019-12-30T19:49:31.202716664Z 2019-12-30 19:49:31.202 TRACE [ftgo-order-service,8c4a37f81ea884e4,242a90ac19ad0d20,true] 1 --- [pool-4-thread-3] i.e.t.c.c.DecoratedMessageHandlerFactory : Invoking handler orderService 0000016f585b39a0-0242ac19000d0000 ftgo-order-service_1 | 2019-12-30T19:49:31.203052131Z 2019-12-30 19:49:31.202 TRACE [ftgo-order-service,8c4a37f81ea884e4,242a90ac19ad0d20,true] 1 --- [pool-4-thread-3] i.e.t.s.p.SagaCommandDispatcher : Received message orderService io.eventuate.tram.messaging.common.MessageImpl@19a 49573[payload={"orderId":3,"revision":{"revisedLineItemQuantities":{"aa":14}}},headers={command_saga_id=0000016f585b399b-0242ac19000d0000, DATE=Mon, 30 Dec 2019 19:49:31 GMT, command_type=net.chrisrichardson.ftgo.orderservice.sagaparticipants.commands.BeginReviseOrderCommand, command_reply_to=net.ch risrichardson.ftgo.orderservice.sagas.reviseorder.ReviseOrderSaga-reply, DESTINATION=orderService, command_saga_type=net.chrisrichardson.ftgo.orderservice.sagas.reviseorder.ReviseOrderSaga, command__destination=orderService, ID=0000016f585b39a0-0242ac19000d0000, X-B3-TraceId=8c4a37f81ea884e4, X-B3-S panId=242a90ac19ad0d20, X-B3-ParentSpanId=c86bc2276b9e6741, X-B3-Sampled=1}] ftgo-order-service1 | 2019-12-30T19:49:31.207693629Z 2019-12-30 19:49:31.207 DEBUG [ftgo-order-service,8c4a37f81ea884e4,242a90ac19ad0d20,true] 1 --- [pool-4-thread-3] org.hibernate.SQL : select order0.id as id1_30, order0_.consumer_id as consumer2_30, order0_.ci ty as city3_30, order0_.delivery_state as delivery4_30, order0_.street1 as street5_30, order0_.street2 as street6_30, order0_.zip as zip7_30, order0_.delivery_time as delivery8_30, order0_.order_minimum as order_mi9_30, order0_.payment_token as payment10_30, order0_.restaurant_id as restaur11_30, order0_.state as state12_30, order0_.version as version13_30 from orders order0 where order0.id=? ftgo-order-service1 | 2019-12-30T19:49:31.217250824Z 2019-12-30 19:49:31.215 DEBUG [ftgo-order-service,8c4a37f81ea884e4,242a90ac19ad0d20,true] 1 --- [pool-4-thread-3] org.hibernate.SQL : select lineitems0.order_id as order_id1_00, lineitems0_.menu_itemid as menu ite2_00, lineitems0_.name as name3_00, lineitems0_.price as price4_00, lineitems0_.quantity as quantity5_00 from order_lineitems lineitems0 where lineitems0_.order_id=? ftgo-order-service_1 | 2019-12-30T19:49:31.234239523Z 2019-12-30 19:49:31.228 TRACE [ftgo-order-service,8c4a37f81ea884e4,242a90ac19ad0d20,true] 1 --- [pool-4-thread-3] i.e.t.s.p.SagaCommandDispatcher : Generated error orderService io.eventuate.tram.messaging.common.MessageImpl@19a4 9573[payload={"orderId":3,"revision":{"revisedLineItemQuantities":{"aa":14}}},headers={command_saga_id=0000016f585b399b-0242ac19000d0000, DATE=Mon, 30 Dec 2019 19:49:31 GMT, command_type=net.chrisrichardson.ftgo.orderservice.sagaparticipants.commands.BeginReviseOrderCommand, command_reply_to=net.chr isrichardson.ftgo.orderservice.sagas.reviseorder.ReviseOrderSaga-reply, DESTINATION=orderService, command_saga_type=net.chrisrichardson.ftgo.orderservice.sagas.reviseorder.ReviseOrderSaga, command__destination=orderService, ID=0000016f585b39a0-0242ac19000d0000, X-B3-TraceId=8c4a37f81ea884e4, X-B3-Sp anId=242a90ac19ad0d20, X-B3-ParentSpanId=c86bc2276b9e6741, X-B3-Sampled=1}] java.util.NoSuchElementException ftgo-order-service_1 | 2019-12-30T19:49:31.245422855Z java.util.NoSuchElementException: No value present ftgo-order-service_1 | 2019-12-30T19:49:31.246064438Z at java.util.Optional.get(Optional.java:135) ftgo-order-service_1 | 2019-12-30T19:49:31.246316392Z at net.chrisrichardson.ftgo.orderservice.domain.OrderLineItems.findOrderLineItem(OrderLineItems.java:24) ftgo-order-service_1 | 2019-12-30T19:49:31.246350017Z at net.chrisrichardson.ftgo.orderservice.domain.OrderLineItems.lambda$changeToOrderTotal$1(OrderLineItems.java:30) ftgo-order-service_1 | 2019-12-30T19:49:31.247371929Z at java.util.LinkedHashMap.forEach(LinkedHashMap.java:684) ftgo-order-service_1 | 2019-12-30T19:49:31.247394274Z at net.chrisrichardson.ftgo.orderservice.domain.OrderLineItems.changeToOrderTotal(OrderLineItems.java:29) ftgo-order-service_1 | 2019-12-30T19:49:31.247405246Z at net.chrisrichardson.ftgo.orderservice.domain.OrderLineItems.lineItemQuantityChange(OrderLineItems.java:46) ftgo-order-service_1 | 2019-12-30T19:49:31.247414363Z at net.chrisrichardson.ftgo.orderservice.domain.Order.revise(Order.java:132) ftgo-order-service_1 | 2019-12-30T19:49:31.247423247Z at net.chrisrichardson.ftgo.orderservice.domain.OrderService.lambda$beginReviseOrder$11(OrderService.java:159) ftgo-order-service_1 | 2019-12-30T19:49:31.247432257Z at java.util.Optional.map(Optional.java:215) ftgo-order-service_1 | 2019-12-30T19:49:31.247440966Z at net.chrisrichardson.ftgo.orderservice.domain.OrderService.beginReviseOrder(OrderService.java:157) ftgo-order-service_1 | 2019-12-30T19:49:31.247449959Z at net.chrisrichardson.ftgo.orderservice.domain.OrderService$$FastClassBySpringCGLIB$$f0abbe15.invoke() ftgo-order-service_1 | 2019-12-30T19:49:31.247459294Z at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204) ftgo-order-service_1 | 2019-12-30T19:49:31.248022955Z at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:746) ftgo-order-service_1 | 2019-12-30T19:49:31.248058881Z at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) ftgo-order-service_1 | 2019-12-30T19:49:31.248138100Z at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:294) ftgo-order-service_1 | 2019-12-30T19:49:31.251339649Z at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:98) ftgo-order-service_1 | 2019-12-30T19:49:31.252400572Z at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185) ftgo-order-service_1 | 2019-12-30T19:49:31.254188727Z at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:688) ftgo-order-service_1 | 2019-12-30T19:49:31.256606352Z at net.chrisrichardson.ftgo.orderservice.domain.OrderService$$EnhancerBySpringCGLIB$$6ad681b2.beginReviseOrder() ftgo-order-service_1 | 2019-12-30T19:49:31.257086437Z at net.chrisrichardson.ftgo.orderservice.service.OrderCommandHandlers.beginReviseOrder(OrderCommandHandlers.java:89) ftgo-order-service_1 | 2019-12-30T19:49:31.257108842Z at io.eventuate.tram.sagas.participant.SagaCommandHandlersBuilder.lambda$onMessage$1(SagaCommandHandlersBuilder.java:50) ftgo-order-service_1 | 2019-12-30T19:49:31.257196586Z at io.eventuate.tram.sagas.participant.SagaCommandHandler.lambda$new$0(SagaCommandHandler.java:25) ftgo-order-service_1 | 2019-12-30T19:49:31.257262477Z at io.eventuate.tram.commands.consumer.CommandHandler.lambda$new$0(CommandHandler.java:27) ftgo-order-service_1 | 2019-12-30T19:49:31.257905861Z at io.eventuate.tram.commands.consumer.CommandHandler.invokeMethod(CommandHandler.java:62) ftgo-order-service_1 | 2019-12-30T19:49:31.258797797Z at io.eventuate.tram.commands.consumer.CommandDispatcher.invoke(CommandDispatcher.java:92) ftgo-order-service_1 | 2019-12-30T19:49:31.259633705Z at io.eventuate.tram.sagas.participant.SagaCommandDispatcher.invoke(SagaCommandDispatcher.java:80) ftgo-order-service_1 | 2019-12-30T19:49:31.260086004Z at io.eventuate.tram.commands.consumer.CommandDispatcher.messageHandler(CommandDispatcher.java:76) ftgo-order-service_1 | 2019-12-30T19:49:31.260892566Z at io.eventuate.tram.sagas.participant.SagaCommandDispatcher.messageHandler(SagaCommandDispatcher.java:44) ftgo-order-service_1 | 2019-12-30T19:49:31.260952395Z at io.eventuate.tram.consumer.common.DecoratedMessageHandlerFactory.lambda$decorate$0(DecoratedMessageHandlerFactory.java:33) ftgo-order-service_1 | 2019-12-30T19:49:31.261477488Z at io.eventuate.tram.consumer.common.PrePostHandlerMessageHandlerDecorator.accept(PrePostHandlerMessageHandlerDecorator.java:26) ftgo-order-service_1 | 2019-12-30T19:49:31.261753646Z at io.eventuate.tram.consumer.common.PrePostHandlerMessageHandlerDecorator.accept(PrePostHandlerMessageHandlerDecorator.java:11) ftgo-order-service_1 | 2019-12-30T19:49:31.261797080Z at io.eventuate.tram.consumer.common.MessageHandlerDecoratorChainBuilder.lambda$buildChain$0(MessageHandlerDecoratorChainBuilder.java:38) ftgo-order-service_1 | 2019-12-30T19:49:31.261955714Z at io.eventuate.tram.consumer.common.DuplicateDetectingMessageHandlerDecorator.lambda$accept$0(DuplicateDetectingMessageHandlerDecorator.java:15) ftgo-order-service_1 | 2019-12-30T19:49:31.263247895Z at io.eventuate.tram.consumer.jdbc.SqlTableBasedDuplicateMessageDetector.lambda$doWithMessage$0(SqlTableBasedDuplicateMessageDetector.java:53) ftgo-order-service_1 | 2019-12-30T19:49:31.263334975Z at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:140) ftgo-order-service_1 | 2019-12-30T19:49:31.263376783Z at io.eventuate.tram.consumer.jdbc.SqlTableBasedDuplicateMessageDetector.doWithMessage(SqlTableBasedDuplicateMessageDetector.java:50) ftgo-order-service_1 | 2019-12-30T19:49:31.275239710Z at io.eventuate.tram.consumer.common.DuplicateDetectingMessageHandlerDecorator.accept(DuplicateDetectingMessageHandlerDecorator.java:15) ftgo-order-service_1 | 2019-12-30T19:49:31.276067823Z at io.eventuate.tram.consumer.common.DuplicateDetectingMessageHandlerDecorator.accept(DuplicateDetectingMessageHandlerDecorator.java:5) ftgo-order-service_1 | 2019-12-30T19:49:31.276156560Z at io.eventuate.tram.consumer.common.MessageHandlerDecoratorChainBuilder.lambda$buildChain$0(MessageHandlerDecoratorChainBuilder.java:38) ftgo-order-service_1 | 2019-12-30T19:49:31.276188804Z at io.eventuate.tram.consumer.common.PrePostReceiveMessageHandlerDecorator.accept(PrePostReceiveMessageHandlerDecorator.java:25) ftgo-order-service_1 | 2019-12-30T19:49:31.277102958Z at io.eventuate.tram.consumer.common.PrePostReceiveMessageHandlerDecorator.accept(PrePostReceiveMessageHandlerDecorator.java:11) ftgo-order-service_1 | 2019-12-30T19:49:31.277240978Z at io.eventuate.tram.consumer.common.MessageHandlerDecoratorChainBuilder.lambda$buildChain$0(MessageHandlerDecoratorChainBuilder.java:38) ftgo-order-service_1 | 2019-12-30T19:49:31.277259327Z at io.eventuate.tram.consumer.common.MessageConsumerImpl.lambda$subscribe$0(MessageConsumerImpl.java:34) ftgo-order-service_1 | 2019-12-30T19:49:31.277865923Z at io.eventuate.tram.consumer.kafka.EventuateTramKafkaMessageConsumer.lambda$subscribe$0(EventuateTramKafkaMessageConsumer.java:24) ftgo-order-service_1 | 2019-12-30T19:49:31.278608885Z at io.eventuate.messaging.kafka.consumer.MessageConsumerKafkaImpl.handle(MessageConsumerKafkaImpl.java:60) ftgo-order-service_1 | 2019-12-30T19:49:31.278741262Z at io.eventuate.messaging.kafka.consumer.MessageConsumerKafkaImpl.lambda$null$0(MessageConsumerKafkaImpl.java:40) ftgo-order-service_1 | 2019-12-30T19:49:31.279404399Z at io.eventuate.messaging.kafka.consumer.SwimlaneDispatcher.processQueuedMessage(SwimlaneDispatcher.java:72) ftgo-order-service_1 | 2019-12-30T19:49:31.280023141Z at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ftgo-order-service_1 | 2019-12-30T19:49:31.280095980Z at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ftgo-order-service_1 | 2019-12-30T19:49:31.280606016Z at java.lang.Thread.run(Thread.java:748) ftgo-order-service_1 | 2019-12-30T19:49:31.281384605Z 2019-12-30 19:49:31.280 TRACE [ftgo-order-service,8c4a37f81ea884e4,242a90ac19ad0d20,true] 1 --- [pool-4-thread-3] i.e.t.c.c.DecoratedMessageHandlerFactory : Got exception orderService 0000016f585b39a0-0242ac19000d0000 ftgo-order-service_1 | 2019-12-30T19:49:31.294367668Z 2019-12-30 19:49:31.293 TRACE [ftgo-order-service,8c4a37f81ea884e4,242a90ac19ad0d20,true] 1 --- [pool-4-thread-3] i.e.t.c.c.DecoratedMessageHandlerFactory : Got exception ftgo-order-service_1 | 2019-12-30T19:49:31.294410302Z ftgo-order-service_1 | 2019-12-30T19:49:31.294421152Z java.lang.UnsupportedOperationException: implement me ftgo-order-service_1 | 2019-12-30T19:49:31.294430265Z at io.eventuate.tram.commands.consumer.CommandHandlers.findExceptionHandler(CommandHandlers.java:28) ~[eventuate-tram-commands-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.294439499Z at io.eventuate.tram.commands.consumer.CommandDispatcher.handleException(CommandDispatcher.java:140) ~[eventuate-tram-commands-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.294448516Z at io.eventuate.tram.commands.consumer.CommandDispatcher.messageHandler(CommandDispatcher.java:80) ~[eventuate-tram-commands-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.294457539Z at io.eventuate.tram.sagas.participant.SagaCommandDispatcher.messageHandler(SagaCommandDispatcher.java:44) ~[eventuate-tram-sagas-participant-0.12.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.294466619Z at io.eventuate.tram.consumer.common.DecoratedMessageHandlerFactory.lambda$decorate$0(DecoratedMessageHandlerFactory.java:33) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.294488562Z at io.eventuate.tram.consumer.common.PrePostHandlerMessageHandlerDecorator.accept(PrePostHandlerMessageHandlerDecorator.java:26) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.294498894Z at io.eventuate.tram.consumer.common.PrePostHandlerMessageHandlerDecorator.accept(PrePostHandlerMessageHandlerDecorator.java:11) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.294508106Z at io.eventuate.tram.consumer.common.MessageHandlerDecoratorChainBuilder.lambda$buildChain$0(MessageHandlerDecoratorChainBuilder.java:38) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.294517308Z at io.eventuate.tram.consumer.common.DuplicateDetectingMessageHandlerDecorator.lambda$accept$0(DuplicateDetectingMessageHandlerDecorator.java:15) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.294526501Z at io.eventuate.tram.consumer.jdbc.SqlTableBasedDuplicateMessageDetector.lambda$doWithMessage$0(SqlTableBasedDuplicateMessageDetector.java:53) ~[eventuate-tram-consumer-jdbc-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.294536964Z at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:140) ~[spring-tx-5.0.7.RELEASE.jar!/:5.0.7.RELEASE] ftgo-order-service_1 | 2019-12-30T19:49:31.294546529Z at io.eventuate.tram.consumer.jdbc.SqlTableBasedDuplicateMessageDetector.doWithMessage(SqlTableBasedDuplicateMessageDetector.java:50) ~[eventuate-tram-consumer-jdbc-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.294555747Z at io.eventuate.tram.consumer.common.DuplicateDetectingMessageHandlerDecorator.accept(DuplicateDetectingMessageHandlerDecorator.java:15) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.294564907Z at io.eventuate.tram.consumer.common.DuplicateDetectingMessageHandlerDecorator.accept(DuplicateDetectingMessageHandlerDecorator.java:5) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.294573974Z at io.eventuate.tram.consumer.common.MessageHandlerDecoratorChainBuilder.lambda$buildChain$0(MessageHandlerDecoratorChainBuilder.java:38) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.294583063Z at io.eventuate.tram.consumer.common.PrePostReceiveMessageHandlerDecorator.accept(PrePostReceiveMessageHandlerDecorator.java:25) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.294592206Z at io.eventuate.tram.consumer.common.PrePostReceiveMessageHandlerDecorator.accept(PrePostReceiveMessageHandlerDecorator.java:11) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.294601260Z at io.eventuate.tram.consumer.common.MessageHandlerDecoratorChainBuilder.lambda$buildChain$0(MessageHandlerDecoratorChainBuilder.java:38) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.294610437Z at io.eventuate.tram.consumer.common.MessageConsumerImpl.lambda$subscribe$0(MessageConsumerImpl.java:34) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.294635720Z at io.eventuate.tram.consumer.kafka.EventuateTramKafkaMessageConsumer.lambda$subscribe$0(EventuateTramKafkaMessageConsumer.java:24) ~[eventuate-tram-consumer-kafka-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.294647590Z at io.eventuate.messaging.kafka.consumer.MessageConsumerKafkaImpl.handle(MessageConsumerKafkaImpl.java:60) ~[eventuate-messaging-kafka-consumer-0.3.0.RELEASE.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.294664846Z at io.eventuate.messaging.kafka.consumer.MessageConsumerKafkaImpl.lambda$null$0(MessageConsumerKafkaImpl.java:40) ~[eventuate-messaging-kafka-consumer-0.3.0.RELEASE.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.294675356Z at io.eventuate.messaging.kafka.consumer.SwimlaneDispatcher.processQueuedMessage(SwimlaneDispatcher.java:72) ~[eventuate-messaging-kafka-consumer-0.3.0.RELEASE.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.294684707Z at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[na:1.8.0_171] ftgo-order-service_1 | 2019-12-30T19:49:31.294693581Z at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[na:1.8.0_171] ftgo-order-service_1 | 2019-12-30T19:49:31.294702344Z at java.lang.Thread.run(Thread.java:748) ~[na:1.8.0_171] ftgo-order-service_1 | 2019-12-30T19:49:31.294710963Z Caused by: java.util.NoSuchElementException: No value present ftgo-order-service_1 | 2019-12-30T19:49:31.294719541Z at java.util.Optional.get(Optional.java:135) ~[na:1.8.0_171] ftgo-order-service_1 | 2019-12-30T19:49:31.294728122Z at net.chrisrichardson.ftgo.orderservice.domain.OrderLineItems.findOrderLineItem(OrderLineItems.java:24) ~[classes!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.294737170Z at net.chrisrichardson.ftgo.orderservice.domain.OrderLineItems.lambda$changeToOrderTotal$1(OrderLineItems.java:30) ~[classes!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.294746232Z at java.util.LinkedHashMap.forEach(LinkedHashMap.java:684) ~[na:1.8.0_171] ftgo-order-service_1 | 2019-12-30T19:49:31.294754975Z at net.chrisrichardson.ftgo.orderservice.domain.OrderLineItems.changeToOrderTotal(OrderLineItems.java:29) ~[classes!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.294763791Z at net.chrisrichardson.ftgo.orderservice.domain.OrderLineItems.lineItemQuantityChange(OrderLineItems.java:46) ~[classes!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.294772536Z at net.chrisrichardson.ftgo.orderservice.domain.Order.revise(Order.java:132) ~[classes!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.294781210Z at net.chrisrichardson.ftgo.orderservice.domain.OrderService.lambda$beginReviseOrder$11(OrderService.java:159) ~[classes!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.294790130Z at java.util.Optional.map(Optional.java:215) ~[na:1.8.0_171] ftgo-order-service_1 | 2019-12-30T19:49:31.294798870Z at net.chrisrichardson.ftgo.orderservice.domain.OrderService.beginReviseOrder(OrderService.java:157) ~[classes!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.294807788Z at net.chrisrichardson.ftgo.orderservice.domain.OrderService$$FastClassBySpringCGLIB$$f0abbe15.invoke() ~[classes!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.294816897Z at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204) ~[spring-core-5.0.7.RELEASE.jar!/:5.0.7.RELEASE] ftgo-order-service_1 | 2019-12-30T19:49:31.294825890Z at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:746) ~[spring-aop-5.0.7.RELEASE.jar!/:5.0.7.RELEASE] ftgo-order-service_1 | 2019-12-30T19:49:31.294836085Z at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) ~[spring-aop-5.0.7.RELEASE.jar!/:5.0.7.RELEASE] ftgo-order-service_1 | 2019-12-30T19:49:31.294845833Z at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:294) ~[spring-tx-5.0.7.RELEASE.jar!/:5.0.7.RELEASE] ftgo-order-service_1 | 2019-12-30T19:49:31.294861586Z at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:98) ~[spring-tx-5.0.7.RELEASE.jar!/:5.0.7.RELEASE] ftgo-order-service_1 | 2019-12-30T19:49:31.294871267Z at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185) ~[spring-aop-5.0.7.RELEASE.jar!/:5.0.7.RELEASE] ftgo-order-service_1 | 2019-12-30T19:49:31.294880231Z at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:688) ~[spring-aop-5.0.7.RELEASE.jar!/:5.0.7.RELEASE] ftgo-order-service_1 | 2019-12-30T19:49:31.294889342Z at net.chrisrichardson.ftgo.orderservice.domain.OrderService$$EnhancerBySpringCGLIB$$6ad681b2.beginReviseOrder() ~[classes!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.294898439Z at net.chrisrichardson.ftgo.orderservice.service.OrderCommandHandlers.beginReviseOrder(OrderCommandHandlers.java:89) ~[classes!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.294907351Z at io.eventuate.tram.sagas.participant.SagaCommandHandlersBuilder.lambda$onMessage$1(SagaCommandHandlersBuilder.java:50) ~[eventuate-tram-sagas-participant-0.12.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.294916445Z at io.eventuate.tram.sagas.participant.SagaCommandHandler.lambda$new$0(SagaCommandHandler.java:25) ~[eventuate-tram-sagas-participant-0.12.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.294925440Z at io.eventuate.tram.commands.consumer.CommandHandler.lambda$new$0(CommandHandler.java:27) ~[eventuate-tram-commands-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.294934329Z at io.eventuate.tram.commands.consumer.CommandHandler.invokeMethod(CommandHandler.java:62) ~[eventuate-tram-commands-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.294943274Z at io.eventuate.tram.commands.consumer.CommandDispatcher.invoke(CommandDispatcher.java:92) ~[eventuate-tram-commands-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.294952130Z at io.eventuate.tram.sagas.participant.SagaCommandDispatcher.invoke(SagaCommandDispatcher.java:80) ~[eventuate-tram-sagas-participant-0.12.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.294962084Z at io.eventuate.tram.commands.consumer.CommandDispatcher.messageHandler(CommandDispatcher.java:76) ~[eventuate-tram-commands-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.294971466Z ... 23 common frames omitted ftgo-order-service_1 | 2019-12-30T19:49:31.294980175Z ftgo-order-service_1 | 2019-12-30T19:49:31.304744780Z 2019-12-30 19:49:31.303 ERROR [ftgo-order-service,,,] 1 --- [pool-4-thread-3] i.e.m.k.b.c.KafkaMessageProcessor : Got exception: ftgo-order-service_1 | 2019-12-30T19:49:31.304804991Z ftgo-order-service_1 | 2019-12-30T19:49:31.304817277Z java.lang.UnsupportedOperationException: implement me ftgo-order-service_1 | 2019-12-30T19:49:31.304826453Z at io.eventuate.tram.commands.consumer.CommandHandlers.findExceptionHandler(CommandHandlers.java:28) ~[eventuate-tram-commands-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.304835996Z at io.eventuate.tram.commands.consumer.CommandDispatcher.handleException(CommandDispatcher.java:140) ~[eventuate-tram-commands-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.304845086Z at io.eventuate.tram.commands.consumer.CommandDispatcher.messageHandler(CommandDispatcher.java:80) ~[eventuate-tram-commands-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.304865933Z at io.eventuate.tram.sagas.participant.SagaCommandDispatcher.messageHandler(SagaCommandDispatcher.java:44) ~[eventuate-tram-sagas-participant-0.12.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.304875987Z at io.eventuate.tram.consumer.common.DecoratedMessageHandlerFactory.lambda$decorate$0(DecoratedMessageHandlerFactory.java:33) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.304885301Z at io.eventuate.tram.consumer.common.PrePostHandlerMessageHandlerDecorator.accept(PrePostHandlerMessageHandlerDecorator.java:26) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.304936735Z at io.eventuate.tram.consumer.common.PrePostHandlerMessageHandlerDecorator.accept(PrePostHandlerMessageHandlerDecorator.java:11) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.304951114Z at io.eventuate.tram.consumer.common.MessageHandlerDecoratorChainBuilder.lambda$buildChain$0(MessageHandlerDecoratorChainBuilder.java:38) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.304960990Z at io.eventuate.tram.consumer.common.DuplicateDetectingMessageHandlerDecorator.lambda$accept$0(DuplicateDetectingMessageHandlerDecorator.java:15) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.304970284Z at io.eventuate.tram.consumer.jdbc.SqlTableBasedDuplicateMessageDetector.lambda$doWithMessage$0(SqlTableBasedDuplicateMessageDetector.java:53) ~[eventuate-tram-consumer-jdbc-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.304981034Z at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:140) ~[spring-tx-5.0.7.RELEASE.jar!/:5.0.7.RELEASE] ftgo-order-service_1 | 2019-12-30T19:49:31.304990482Z at io.eventuate.tram.consumer.jdbc.SqlTableBasedDuplicateMessageDetector.doWithMessage(SqlTableBasedDuplicateMessageDetector.java:50) ~[eventuate-tram-consumer-jdbc-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.304999641Z at io.eventuate.tram.consumer.common.DuplicateDetectingMessageHandlerDecorator.accept(DuplicateDetectingMessageHandlerDecorator.java:15) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.305008727Z at io.eventuate.tram.consumer.common.DuplicateDetectingMessageHandlerDecorator.accept(DuplicateDetectingMessageHandlerDecorator.java:5) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.305017901Z at io.eventuate.tram.consumer.common.MessageHandlerDecoratorChainBuilder.lambda$buildChain$0(MessageHandlerDecoratorChainBuilder.java:38) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.305027066Z at io.eventuate.tram.consumer.common.PrePostReceiveMessageHandlerDecorator.accept(PrePostReceiveMessageHandlerDecorator.java:25) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.305036114Z at io.eventuate.tram.consumer.common.PrePostReceiveMessageHandlerDecorator.accept(PrePostReceiveMessageHandlerDecorator.java:11) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.305046392Z at io.eventuate.tram.consumer.common.MessageHandlerDecoratorChainBuilder.lambda$buildChain$0(MessageHandlerDecoratorChainBuilder.java:38) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.305055480Z at io.eventuate.tram.consumer.common.MessageConsumerImpl.lambda$subscribe$0(MessageConsumerImpl.java:34) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.305071317Z at io.eventuate.tram.consumer.kafka.EventuateTramKafkaMessageConsumer.lambda$subscribe$0(EventuateTramKafkaMessageConsumer.java:24) ~[eventuate-tram-consumer-kafka-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.305081175Z at io.eventuate.messaging.kafka.consumer.MessageConsumerKafkaImpl.handle(MessageConsumerKafkaImpl.java:60) [eventuate-messaging-kafka-consumer-0.3.0.RELEASE.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.305091129Z at io.eventuate.messaging.kafka.consumer.MessageConsumerKafkaImpl.lambda$null$0(MessageConsumerKafkaImpl.java:40) [eventuate-messaging-kafka-consumer-0.3.0.RELEASE.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.305100375Z at io.eventuate.messaging.kafka.consumer.SwimlaneDispatcher.processQueuedMessage(SwimlaneDispatcher.java:72) ~[eventuate-messaging-kafka-consumer-0.3.0.RELEASE.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.305109445Z at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[na:1.8.0_171] ftgo-order-service_1 | 2019-12-30T19:49:31.305118176Z at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[na:1.8.0_171] ftgo-order-service_1 | 2019-12-30T19:49:31.305188242Z at java.lang.Thread.run(Thread.java:748) ~[na:1.8.0_171] ftgo-order-service_1 | 2019-12-30T19:49:31.305202415Z Caused by: java.util.NoSuchElementException: No value present ftgo-order-service_1 | 2019-12-30T19:49:31.305211530Z at java.util.Optional.get(Optional.java:135) ~[na:1.8.0_171] ftgo-order-service_1 | 2019-12-30T19:49:31.305220255Z at net.chrisrichardson.ftgo.orderservice.domain.OrderLineItems.findOrderLineItem(OrderLineItems.java:24) ~[classes!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.305254829Z at net.chrisrichardson.ftgo.orderservice.domain.OrderLineItems.lambda$changeToOrderTotal$1(OrderLineItems.java:30) ~[classes!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.305268232Z at java.util.LinkedHashMap.forEach(LinkedHashMap.java:684) ~[na:1.8.0_171] ftgo-order-service_1 | 2019-12-30T19:49:31.305277401Z at net.chrisrichardson.ftgo.orderservice.domain.OrderLineItems.changeToOrderTotal(OrderLineItems.java:29) ~[classes!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.305286328Z at net.chrisrichardson.ftgo.orderservice.domain.OrderLineItems.lineItemQuantityChange(OrderLineItems.java:46) ~[classes!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.305295277Z at net.chrisrichardson.ftgo.orderservice.domain.Order.revise(Order.java:132) ~[classes!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.305303993Z at net.chrisrichardson.ftgo.orderservice.domain.OrderService.lambda$beginReviseOrder$11(OrderService.java:159) ~[classes!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.305312841Z at java.util.Optional.map(Optional.java:215) ~[na:1.8.0_171] ftgo-order-service_1 | 2019-12-30T19:49:31.305321485Z at net.chrisrichardson.ftgo.orderservice.domain.OrderService.beginReviseOrder(OrderService.java:157) ~[classes!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.305330391Z at net.chrisrichardson.ftgo.orderservice.domain.OrderService$$FastClassBySpringCGLIB$$f0abbe15.invoke() ~[classes!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.305339464Z at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204) ~[spring-core-5.0.7.RELEASE.jar!/:5.0.7.RELEASE] ftgo-order-service_1 | 2019-12-30T19:49:31.305348500Z at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:746) ~[spring-aop-5.0.7.RELEASE.jar!/:5.0.7.RELEASE] ftgo-order-service_1 | 2019-12-30T19:49:31.305366082Z at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) ~[spring-aop-5.0.7.RELEASE.jar!/:5.0.7.RELEASE] ftgo-order-service_1 | 2019-12-30T19:49:31.305376413Z at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:294) ~[spring-tx-5.0.7.RELEASE.jar!/:5.0.7.RELEASE] ftgo-order-service_1 | 2019-12-30T19:49:31.305385482Z at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:98) ~[spring-tx-5.0.7.RELEASE.jar!/:5.0.7.RELEASE] ftgo-order-service_1 | 2019-12-30T19:49:31.305395375Z at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185) ~[spring-aop-5.0.7.RELEASE.jar!/:5.0.7.RELEASE] ftgo-order-service_1 | 2019-12-30T19:49:31.305404255Z at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:688) ~[spring-aop-5.0.7.RELEASE.jar!/:5.0.7.RELEASE] ftgo-order-service_1 | 2019-12-30T19:49:31.305413489Z at net.chrisrichardson.ftgo.orderservice.domain.OrderService$$EnhancerBySpringCGLIB$$6ad681b2.beginReviseOrder() ~[classes!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.305422543Z at net.chrisrichardson.ftgo.orderservice.service.OrderCommandHandlers.beginReviseOrder(OrderCommandHandlers.java:89) ~[classes!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.305431432Z at io.eventuate.tram.sagas.participant.SagaCommandHandlersBuilder.lambda$onMessage$1(SagaCommandHandlersBuilder.java:50) ~[eventuate-tram-sagas-participant-0.12.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.305440504Z at io.eventuate.tram.sagas.participant.SagaCommandHandler.lambda$new$0(SagaCommandHandler.java:25) ~[eventuate-tram-sagas-participant-0.12.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.305451341Z at io.eventuate.tram.commands.consumer.CommandHandler.lambda$new$0(CommandHandler.java:27) ~[eventuate-tram-commands-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.305460242Z at io.eventuate.tram.commands.consumer.CommandHandler.invokeMethod(CommandHandler.java:62) ~[eventuate-tram-commands-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.305469118Z at io.eventuate.tram.commands.consumer.CommandDispatcher.invoke(CommandDispatcher.java:92) ~[eventuate-tram-commands-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.305478001Z at io.eventuate.tram.sagas.participant.SagaCommandDispatcher.invoke(SagaCommandDispatcher.java:80) ~[eventuate-tram-sagas-participant-0.12.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.305487842Z at io.eventuate.tram.commands.consumer.CommandDispatcher.messageHandler(CommandDispatcher.java:76) ~[eventuate-tram-commands-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.305496984Z ... 23 common frames omitted ftgo-order-service_1 | 2019-12-30T19:49:31.305505518Z ftgo-order-service_1 | 2019-12-30T19:49:31.306700014Z 2019-12-30 19:49:31.306 ERROR [ftgo-order-service,,,] 1 --- [pool-4-thread-3] i.e.m.kafka.consumer.SwimlaneDispatcher : Exception handling message - terminating ftgo-order-service_1 | 2019-12-30T19:49:31.306722874Z ftgo-order-service_1 | 2019-12-30T19:49:31.306733624Z java.lang.UnsupportedOperationException: implement me ftgo-order-service_1 | 2019-12-30T19:49:31.306742847Z at io.eventuate.tram.commands.consumer.CommandHandlers.findExceptionHandler(CommandHandlers.java:28) ~[eventuate-tram-commands-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.306752169Z at io.eventuate.tram.commands.consumer.CommandDispatcher.handleException(CommandDispatcher.java:140) ~[eventuate-tram-commands-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.306769641Z at io.eventuate.tram.commands.consumer.CommandDispatcher.messageHandler(CommandDispatcher.java:80) ~[eventuate-tram-commands-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.306782495Z at io.eventuate.tram.sagas.participant.SagaCommandDispatcher.messageHandler(SagaCommandDispatcher.java:44) ~[eventuate-tram-sagas-participant-0.12.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.306791732Z at io.eventuate.tram.consumer.common.DecoratedMessageHandlerFactory.lambda$decorate$0(DecoratedMessageHandlerFactory.java:33) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.306800982Z at io.eventuate.tram.consumer.common.PrePostHandlerMessageHandlerDecorator.accept(PrePostHandlerMessageHandlerDecorator.java:26) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.306810206Z at io.eventuate.tram.consumer.common.PrePostHandlerMessageHandlerDecorator.accept(PrePostHandlerMessageHandlerDecorator.java:11) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.306819660Z at io.eventuate.tram.consumer.common.MessageHandlerDecoratorChainBuilder.lambda$buildChain$0(MessageHandlerDecoratorChainBuilder.java:38) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.306828997Z at io.eventuate.tram.consumer.common.DuplicateDetectingMessageHandlerDecorator.lambda$accept$0(DuplicateDetectingMessageHandlerDecorator.java:15) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.306838204Z at io.eventuate.tram.consumer.jdbc.SqlTableBasedDuplicateMessageDetector.lambda$doWithMessage$0(SqlTableBasedDuplicateMessageDetector.java:53) ~[eventuate-tram-consumer-jdbc-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.306848721Z at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:140) ~[spring-tx-5.0.7.RELEASE.jar!/:5.0.7.RELEASE] ftgo-order-service_1 | 2019-12-30T19:49:31.306858257Z at io.eventuate.tram.consumer.jdbc.SqlTableBasedDuplicateMessageDetector.doWithMessage(SqlTableBasedDuplicateMessageDetector.java:50) ~[eventuate-tram-consumer-jdbc-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.306867478Z at io.eventuate.tram.consumer.common.DuplicateDetectingMessageHandlerDecorator.accept(DuplicateDetectingMessageHandlerDecorator.java:15) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.306876618Z at io.eventuate.tram.consumer.common.DuplicateDetectingMessageHandlerDecorator.accept(DuplicateDetectingMessageHandlerDecorator.java:5) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.306885703Z at io.eventuate.tram.consumer.common.MessageHandlerDecoratorChainBuilder.lambda$buildChain$0(MessageHandlerDecoratorChainBuilder.java:38) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.306894798Z at io.eventuate.tram.consumer.common.PrePostReceiveMessageHandlerDecorator.accept(PrePostReceiveMessageHandlerDecorator.java:25) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.306903891Z at io.eventuate.tram.consumer.common.PrePostReceiveMessageHandlerDecorator.accept(PrePostReceiveMessageHandlerDecorator.java:11) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.306913005Z at io.eventuate.tram.consumer.common.MessageHandlerDecoratorChainBuilder.lambda$buildChain$0(MessageHandlerDecoratorChainBuilder.java:38) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.306927896Z at io.eventuate.tram.consumer.common.MessageConsumerImpl.lambda$subscribe$0(MessageConsumerImpl.java:34) ~[eventuate-tram-consumer-common-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.306937901Z at io.eventuate.tram.consumer.kafka.EventuateTramKafkaMessageConsumer.lambda$subscribe$0(EventuateTramKafkaMessageConsumer.java:24) ~[eventuate-tram-consumer-kafka-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.306947024Z at io.eventuate.messaging.kafka.consumer.MessageConsumerKafkaImpl.handle(MessageConsumerKafkaImpl.java:60) ~[eventuate-messaging-kafka-consumer-0.3.0.RELEASE.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.306956870Z at io.eventuate.messaging.kafka.consumer.MessageConsumerKafkaImpl.lambda$null$0(MessageConsumerKafkaImpl.java:40) ~[eventuate-messaging-kafka-consumer-0.3.0.RELEASE.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.306966434Z at io.eventuate.messaging.kafka.consumer.SwimlaneDispatcher.processQueuedMessage(SwimlaneDispatcher.java:72) ~[eventuate-messaging-kafka-consumer-0.3.0.RELEASE.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.306975484Z at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[na:1.8.0_171] ftgo-order-service_1 | 2019-12-30T19:49:31.306984288Z at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[na:1.8.0_171] ftgo-order-service_1 | 2019-12-30T19:49:31.306993066Z at java.lang.Thread.run(Thread.java:748) ~[na:1.8.0_171] ftgo-order-service_1 | 2019-12-30T19:49:31.307001716Z Caused by: java.util.NoSuchElementException: No value present ftgo-order-service_1 | 2019-12-30T19:49:31.307010328Z at java.util.Optional.get(Optional.java:135) ~[na:1.8.0_171] ftgo-order-service_1 | 2019-12-30T19:49:31.307018987Z at net.chrisrichardson.ftgo.orderservice.domain.OrderLineItems.findOrderLineItem(OrderLineItems.java:24) ~[classes!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.307027893Z at net.chrisrichardson.ftgo.orderservice.domain.OrderLineItems.lambda$changeToOrderTotal$1(OrderLineItems.java:30) ~[classes!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.307036777Z at java.util.LinkedHashMap.forEach(LinkedHashMap.java:684) ~[na:1.8.0_171] ftgo-order-service_1 | 2019-12-30T19:49:31.307045494Z at net.chrisrichardson.ftgo.orderservice.domain.OrderLineItems.changeToOrderTotal(OrderLineItems.java:29) ~[classes!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.307054465Z at net.chrisrichardson.ftgo.orderservice.domain.OrderLineItems.lineItemQuantityChange(OrderLineItems.java:46) ~[classes!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.307063335Z at net.chrisrichardson.ftgo.orderservice.domain.Order.revise(Order.java:132) ~[classes!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.307072073Z at net.chrisrichardson.ftgo.orderservice.domain.OrderService.lambda$beginReviseOrder$11(OrderService.java:159) ~[classes!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.307080932Z at java.util.Optional.map(Optional.java:215) ~[na:1.8.0_171] ftgo-order-service_1 | 2019-12-30T19:49:31.307089528Z at net.chrisrichardson.ftgo.orderservice.domain.OrderService.beginReviseOrder(OrderService.java:157) ~[classes!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.307098382Z at net.chrisrichardson.ftgo.orderservice.domain.OrderService$$FastClassBySpringCGLIB$$f0abbe15.invoke() ~[classes!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.307107472Z at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204) ~[spring-core-5.0.7.RELEASE.jar!/:5.0.7.RELEASE] ftgo-order-service_1 | 2019-12-30T19:49:31.307137156Z at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:746) ~[spring-aop-5.0.7.RELEASE.jar!/:5.0.7.RELEASE] ftgo-order-service_1 | 2019-12-30T19:49:31.307151298Z at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) ~[spring-aop-5.0.7.RELEASE.jar!/:5.0.7.RELEASE] ftgo-order-service_1 | 2019-12-30T19:49:31.307161069Z at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:294) ~[spring-tx-5.0.7.RELEASE.jar!/:5.0.7.RELEASE] ftgo-order-service_1 | 2019-12-30T19:49:31.307171632Z at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:98) ~[spring-tx-5.0.7.RELEASE.jar!/:5.0.7.RELEASE] ftgo-order-service_1 | 2019-12-30T19:49:31.307180772Z at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185) ~[spring-aop-5.0.7.RELEASE.jar!/:5.0.7.RELEASE] ftgo-order-service_1 | 2019-12-30T19:49:31.307189882Z at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:688) ~[spring-aop-5.0.7.RELEASE.jar!/:5.0.7.RELEASE] ftgo-order-service_1 | 2019-12-30T19:49:31.307198981Z at net.chrisrichardson.ftgo.orderservice.domain.OrderService$$EnhancerBySpringCGLIB$$6ad681b2.beginReviseOrder() ~[classes!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.307208163Z at net.chrisrichardson.ftgo.orderservice.service.OrderCommandHandlers.beginReviseOrder(OrderCommandHandlers.java:89) ~[classes!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.307217097Z at io.eventuate.tram.sagas.participant.SagaCommandHandlersBuilder.lambda$onMessage$1(SagaCommandHandlersBuilder.java:50) ~[eventuate-tram-sagas-participant-0.12.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.307226255Z at io.eventuate.tram.sagas.participant.SagaCommandHandler.lambda$new$0(SagaCommandHandler.java:25) ~[eventuate-tram-sagas-participant-0.12.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.307235394Z at io.eventuate.tram.commands.consumer.CommandHandler.lambda$new$0(CommandHandler.java:27) ~[eventuate-tram-commands-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.307244415Z at io.eventuate.tram.commands.consumer.CommandHandler.invokeMethod(CommandHandler.java:62) ~[eventuate-tram-commands-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.307253278Z at io.eventuate.tram.commands.consumer.CommandDispatcher.invoke(CommandDispatcher.java:92) ~[eventuate-tram-commands-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.307262233Z at io.eventuate.tram.sagas.participant.SagaCommandDispatcher.invoke(SagaCommandDispatcher.java:80) ~[eventuate-tram-sagas-participant-0.12.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.307272117Z at io.eventuate.tram.commands.consumer.CommandDispatcher.messageHandler(CommandDispatcher.java:76) ~[eventuate-tram-commands-0.22.0.RC5.jar!/:na] ftgo-order-service_1 | 2019-12-30T19:49:31.307281334Z ... 23 common frames omitted ftgo-order-service_1 | 2019-12-30T19:49:31.307290182Z