d3ledger / notary

Backend code for a D3 notary
Apache License 2.0
15 stars 5 forks source link

ETH rollback does not work #440

Open bakhtin opened 5 years ago

bakhtin commented 5 years ago

Withdrawal service does not rollback a transaction in case of insufficient funds on withdrawal account and fails with an error

How to reproduce:

  1. Make a deposit to an Ethereum account
  2. Make sure you don't have enough funds on withdrawal ETH address
  3. Withdraw some funds Log file:
    
    [20.03.2019 13:46:12,289] eth-withdrawal [INFO ] [eth-withdrawal:rmq-consumer:th-0:id-12] New Iroha block from RMQ arrived. Height 955
    [20.03.2019 13:46:12,289] eth-withdrawal [INFO ] [eth-withdrawal:rmq-consumer:th-0:id-12] New Iroha block from RMQ arrived. Height 955
    [20.03.2019 13:46:12,290] eth-withdrawal [INFO ] [eth-withdrawal:rmq-consumer:th-0:id-12] Iroha chain handler for block 955
    [20.03.2019 13:46:12,291] eth-withdrawal [INFO ] [eth-withdrawal:rmq-consumer:th-0:id-12] transfer iroha event (from: wwww@d3, to notary@notary, amount: 0.00005, asset: ether#ethereum
    [20.03.2019 13:46:12,299] eth-withdrawal [INFO ] [eth-withdrawal:rmq-consumer:th-0:id-12] Iroha transfer event to notary@notary, expected notary@notary
    [20.03.2019 13:46:12,299] eth-withdrawal [INFO ] [eth-withdrawal:rmq-consumer:th-0:id-12] Withdrawal event
    [20.03.2019 13:46:12,487] eth-withdrawal [INFO ] [eth-withdrawal:rmq-consumer:th-0:id-12] Query http://d3-notary-1:20000 for proof
    [20.03.2019 13:46:12,719] eth-withdrawal [INFO ] [eth-withdrawal:rmq-consumer:th-0:id-12] Query http://d3-notary-2:20000 for proof
    [20.03.2019 13:46:12,852] eth-withdrawal [INFO ] [eth-withdrawal:rmq-consumer:th-0:id-12] Query http://d3-notary-3:20000 for proof
    [20.03.2019 13:46:12,981] eth-withdrawal [INFO ] [eth-withdrawal:rmq-consumer:th-0:id-12] Consumed eth event EthRefund(proof=RollbackApproval(tokenContractAddress=0x0000000000000000000000000000000000000000, amount=50000000000000, account=0x0C9FBc1d4cb27b520e94769188b8D49cC19cCeE5, irohaHash=C4F717610833DB567DDCAB5B0A32269C28518E74719B64C97AFB5D298F19A242, r=[[B@58ab8f9a, [B@6fa3871f, [B@3646c9e7], s=[[B@4903d38a, [B@4dd0526f, [B@3eb8bfb5], v=[28, 28, 27], relay=0x81184c31accb4a780efb05ad906b8e09289b4a98))
    [20.03.2019 13:46:12,981] eth-withdrawal [INFO ] [eth-withdrawal:rmq-consumer:th-0:id-12] Got proof:
    account 0x0C9FBc1d4cb27b520e94769188b8D49cC19cCeE5
    amount 50000000000000
    token 0x0000000000000000000000000000000000000000
    iroha hash C4F717610833DB567DDCAB5B0A32269C28518E74719B64C97AFB5D298F19A242
    relay 0x81184c31accb4a780efb05ad906b8e09289b4a98

Mar 20, 2019 1:46:13 PM okhttp3.internal.platform.Platform log INFO: ALPN callback dropped: HTTP/2 is disabled. Is alpn-boot on the boot class path? [20.03.2019 13:46:13,240] eth-withdrawal [ERROR] [eth-withdrawal:rmq-consumer:th-0:id-12] Web3j exception encountered java.lang.RuntimeException: Error processing transaction request: Insufficient funds. The account you tried to send transaction from does not have enough funds. Required 19999990000000000 and got: 8976080000000000. at org.web3j.tx.TransactionManager.processResponse(TransactionManager.java:67) at org.web3j.tx.TransactionManager.executeTransaction(TransactionManager.java:51) at org.web3j.tx.ManagedTransaction.send(ManagedTransaction.java:87) at org.web3j.tx.Contract.executeTransaction(Contract.java:291) at org.web3j.tx.Contract.executeTransaction(Contract.java:275) at org.web3j.tx.Contract.executeTransaction(Contract.java:269) at org.web3j.tx.Contract.lambda$executeRemoteCallTransaction$3(Contract.java:321) at org.web3j.protocol.core.RemoteCall.send(RemoteCall.java:30) at com.d3.eth.withdrawal.consumer.EthConsumer.withdraw(EthConsumer.kt:81) at com.d3.eth.withdrawal.consumer.EthConsumer.consume(EthConsumer.kt:38) at com.d3.eth.withdrawal.withdrawalservice.WithdrawalServiceInitialization$initEthConsumer$2$1$1.invoke(WithdrawalServiceInitialization.kt:80) at com.d3.eth.withdrawal.withdrawalservice.WithdrawalServiceInitialization$initEthConsumer$2$1$1.invoke(WithdrawalServiceInitialization.kt:26) at com.github.kittinunf.result.ResultKt.map(Result.kt:24) at com.d3.eth.withdrawal.withdrawalservice.WithdrawalServiceInitialization$initEthConsumer$2$1.accept(WithdrawalServiceInitialization.kt:78) at com.d3.eth.withdrawal.withdrawalservice.WithdrawalServiceInitialization$initEthConsumer$2$1.accept(WithdrawalServiceInitialization.kt:26) at io.reactivex.internal.observers.LambdaObserver.onNext(LambdaObserver.java:63) at io.reactivex.internal.operators.observable.ObservableSubscribeOn$SubscribeOnObserver.onNext(ObservableSubscribeOn.java:58) at io.reactivex.internal.operators.observable.ObservableMap$MapObserver.onNext(ObservableMap.java:62) at io.reactivex.internal.operators.observable.ObservableFlattenIterable$FlattenIterableObserver.onNext(ObservableFlattenIterable.java:111) at io.reactivex.internal.operators.observable.ObservableMap$MapObserver.onNext(ObservableMap.java:62) at io.reactivex.subjects.PublishSubject$PublishDisposable.onNext(PublishSubject.java:308) at io.reactivex.subjects.PublishSubject.onNext(PublishSubject.java:228) at com.d3.commons.sidechain.iroha.ReliableIrohaChainListener$getBlockObservable$1$deliverCallback$1.invoke(ReliableIrohaChainListener.kt:82) at com.d3.commons.sidechain.iroha.ReliableIrohaChainListener$getBlockObservable$1$deliverCallback$1.invoke(ReliableIrohaChainListener.kt:25) at com.d3.commons.sidechain.iroha.ReliableIrohaChainListenerKt$sam$com_rabbitmq_client_DeliverCallback$0.handle(ReliableIrohaChainListener.kt) at com.rabbitmq.client.impl.recovery.AutorecoveringChannel$2.handleDelivery(AutorecoveringChannel.java:577) at com.rabbitmq.client.impl.ConsumerDispatcher$5.run(ConsumerDispatcher.java:149) at com.rabbitmq.client.impl.ConsumerWorkService$WorkPoolRunnable.run(ConsumerWorkService.java:104) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) [20.03.2019 13:46:13,242] eth-withdrawal [INFO ] [eth-withdrawal:rmq-consumer:th-0:id-12] Withdrawal rollback initiated: C4F717610833DB567DDCAB5B0A32269C28518E74719B64C97AFB5D298F19A242 [20.03.2019 13:46:21,343] eth-withdrawal [ERROR] [eth-withdrawal:rmq-consumer:th-0:id-12] Error during rollback transfer transaction java.lang.Exception: Tx fc438cfd85c3a60d0e2f4a351356031269e8be5f4a117d420718773a1a47d6be failed. TransferAsset at com.d3.commons.sidechain.iroha.consumer.IrohaConsumerImpl$createTxStatusObserver$5.accept(IrohaConsumerImpl.kt:139) at com.d3.commons.sidechain.iroha.consumer.IrohaConsumerImpl$createTxStatusObserver$5.accept(IrohaConsumerImpl.kt:41) at jp.co.soramitsu.iroha.java.detail.InlineTransactionStatusObserver.onTransactionFailed(InlineTransactionStatusObserver.java:60) at jp.co.soramitsu.iroha.java.detail.router.Router.processType(Router.java:46) at jp.co.soramitsu.iroha.java.detail.router.Router.process(Router.java:67) at jp.co.soramitsu.iroha.java.TransactionStatusObserver.onNext(TransactionStatusObserver.java:64) at jp.co.soramitsu.iroha.java.TransactionStatusObserver.onNext(TransactionStatusObserver.java:38) at io.reactivex.internal.util.NotificationLite.acceptFull(NotificationLite.java:298) at io.reactivex.internal.operators.observable.ObservableBlockingSubscribe.subscribe(ObservableBlockingSubscribe.java:65) at io.reactivex.Observable.blockingSubscribe(Observable.java:5504) at com.d3.commons.sidechain.iroha.consumer.IrohaConsumerImpl$send$1.invoke(IrohaConsumerImpl.kt:68) at com.d3.commons.sidechain.iroha.consumer.IrohaConsumerImpl$send$1.invoke(IrohaConsumerImpl.kt:41) at com.github.kittinunf.result.Result$Companion.of(Result.kt:112) at com.d3.commons.sidechain.iroha.consumer.IrohaConsumerImpl.send(IrohaConsumerImpl.kt:65) at com.d3.commons.sidechain.iroha.consumer.IrohaConsumerImpl.send(IrohaConsumerImpl.kt:56) at com.d3.commons.sidechain.iroha.util.ModelUtil.transferAssetIroha(ModelUtil.kt:242) at com.d3.commons.sidechain.iroha.util.ModelUtil.transferAssetIroha$default(ModelUtil.kt:235) at com.d3.eth.withdrawal.withdrawalservice.WithdrawalServiceImpl$returnIrohaAssets$2.invoke(WithdrawalServiceImpl.kt:214) at com.d3.eth.withdrawal.withdrawalservice.WithdrawalServiceImpl$returnIrohaAssets$2.invoke(WithdrawalServiceImpl.kt:54) at com.github.kittinunf.result.ResultKt.map(Result.kt:24) at com.d3.eth.withdrawal.withdrawalservice.WithdrawalServiceImpl.returnIrohaAssets(WithdrawalServiceImpl.kt:210) at com.d3.eth.withdrawal.withdrawalservice.WithdrawalServiceInitialization$initEthConsumer$2$1$1.invoke(WithdrawalServiceInitialization.kt:83) at com.d3.eth.withdrawal.withdrawalservice.WithdrawalServiceInitialization$initEthConsumer$2$1$1.invoke(WithdrawalServiceInitialization.kt:26) at com.github.kittinunf.result.ResultKt.map(Result.kt:24) at com.d3.eth.withdrawal.withdrawalservice.WithdrawalServiceInitialization$initEthConsumer$2$1.accept(WithdrawalServiceInitialization.kt:78) at com.d3.eth.withdrawal.withdrawalservice.WithdrawalServiceInitialization$initEthConsumer$2$1.accept(WithdrawalServiceInitialization.kt:26) at io.reactivex.internal.observers.LambdaObserver.onNext(LambdaObserver.java:63) at io.reactivex.internal.operators.observable.ObservableSubscribeOn$SubscribeOnObserver.onNext(ObservableSubscribeOn.java:58) at io.reactivex.internal.operators.observable.ObservableMap$MapObserver.onNext(ObservableMap.java:62) at io.reactivex.internal.operators.observable.ObservableFlattenIterable$FlattenIterableObserver.onNext(ObservableFlattenIterable.java:111) at io.reactivex.internal.operators.observable.ObservableMap$MapObserver.onNext(ObservableMap.java:62) at io.reactivex.subjects.PublishSubject$PublishDisposable.onNext(PublishSubject.java:308) at io.reactivex.subjects.PublishSubject.onNext(PublishSubject.java:228) at com.d3.commons.sidechain.iroha.ReliableIrohaChainListener$getBlockObservable$1$deliverCallback$1.invoke(ReliableIrohaChainListener.kt:82) at com.d3.commons.sidechain.iroha.ReliableIrohaChainListener$getBlockObservable$1$deliverCallback$1.invoke(ReliableIrohaChainListener.kt:25) at com.d3.commons.sidechain.iroha.ReliableIrohaChainListenerKt$sam$com_rabbitmq_client_DeliverCallback$0.handle(ReliableIrohaChainListener.kt) at com.rabbitmq.client.impl.recovery.AutorecoveringChannel$2.handleDelivery(AutorecoveringChannel.java:577) at com.rabbitmq.client.impl.ConsumerDispatcher$5.run(ConsumerDispatcher.java:149) at com.rabbitmq.client.impl.ConsumerWorkService$WorkPoolRunnable.run(ConsumerWorkService.java:104) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) [20.03.2019 13:46:21,353] eth-withdrawal [INFO ] [eth-withdrawal:rmq-consumer:th-0:id-12] New Iroha block from RMQ arrived. Height 956 [20.03.2019 13:46:21,353] eth-withdrawal [INFO ] [eth-withdrawal:rmq-consumer:th-0:id-12] New Iroha block from RMQ arrived. Height 956 [20.03.2019 13:46:21,353] eth-withdrawal [INFO ] [eth-withdrawal:rmq-consumer:th-0:id-12] Iroha chain handler for block 956



The log files shows an attempt to withdraw 0.00005 ETH followed by an error message saying it cannot rollback.

**Environment**
- 3 Iroha nodes (Docker image, version rc4-hotfix1)
- 3 deposit nodes (Docker image, `develop` branch snapshot as of March 20)
- 1 withdrawal node (Docker image, `develop` branch snapshot as of March 20)
Alexey-N-Chernyshov commented 5 years ago

https://soramitsu.atlassian.net/browse/D3-926