Electric-Coin-Company / zcash-android-wallet-sdk

Native Android SDK for Zcash
MIT License
5 stars 9 forks source link

Sync restart once error is there (sdk-v2.0.0-rc.1 - rc.3) #1249

Closed Mandeepbhalothia closed 1 year ago

Mandeepbhalothia commented 1 year ago

Describe the issue

On sync error sync start from initial blockHeight

Can you reliably reproduce the issue?

If so, please list the steps to reproduce below:

Tried to sync the wallet that was not synced for a while then after some syncing, error came at a specific height. After the error closed the app and reopened the app, wallet start syncing from initial blockHeight. I am attaching a screenshot of error, unfortunately I don't have logs.

Actual behavior + errors

signal-2023-09-18-165815

Mandeepbhalothia commented 1 year ago

Hi @HonzaR, I see https://github.com/zcash/zcash-android-wallet-sdk/pull/1247. Is this PR something related to the above bug? If you need any more info on this I have an account where this happens. I tried two times and it is reproduced both time.

nuttycom commented 1 year ago

Log content reported by @Mandeepbhalothia prior to the observed restart:

AnchoredDraggableState.invokeSuspend(): Blocks in range BlockHeight(value=1729372)..BlockHeight(value=1729471) failed to download with: kotlinx.coroutines.flow.internal.AbortFlowException: Flow was aborted, no more elements needed
2023-09-20 12:45:34.410 27631-27631 Twig                    com.nighthawkapps.wallet.android     W                              main                           CompactBlockProcessor.downloadBatchOfBlocks$zcash_android_sdk_2_0_0_rc_1_release(): Retrying (1/5) in 500s...
kotlinx.coroutines.flow.internal.AbortFlowException: Flow was aborted, no more elements needed
HonzaR commented 1 year ago

Log reported by @Mandeepbhalothia from RC.2 testing:

CompactBlockProcessor.emit(): Download stage done with result: SyncStageResult(batch=BlockBatch(order=1, range=BlockHeight(value=2234278)..BlockHeight(value=2234289), blocks=null), stageResult=DownloadSuccess with 12 blocks)
2023-09-21 08:44:46.493 30963-30963 Twig                    com.nighthawkapps.wallet.android     E                              main                           CompactBlockProcessor.scanBatchOfBlocks$zcash_android_sdk_2_0_0_rc_2_release(): Failed while scanning batch BlockBatch(order=1, range=BlockHeight(value=2234278)..BlockHeight(value=2234289), blocks=12) with java.lang.RuntimeException: Rust error while scanning blocks (limit 12): Scan(PrevHashMismatch { at_height: BlockHeight(2234278) })
2023-09-21 08:44:46.501 30963-30963 Twig                    com.nighthawkapps.wallet.android     D                              main                           CompactBlockProcessor.emit(): Scan stage done with result: SyncStageResult(batch=BlockBatch(order=1, range=BlockHeight(value=2234278)..BlockHeight(value=2234289), blocks=12), stageResult=ScanFailed(failedAtHeight=BlockHeight(value=2234278), exception=cash.z.ecc.android.sdk.exception.CompactBlockProcessorException$FailedScanException: Error while scanning blocks. This most likely means a problem with locally persisted data. See logs for details.))
2023-09-21 08:44:46.502 30963-30963 Twig                    com.nighthawkapps.wallet.android     D                              main                           CompactBlockProcessor.invokeSuspend(): Deletion stage done with result: SyncStageResult(batch=BlockBatch(order=1, range=BlockHeight(value=2234278)..BlockHeight(value=2234289), blocks=12), stageResult=ScanFailed(failedAtHeight=BlockHeight(value=2234278), exception=cash.z.ecc.android.sdk.exception.CompactBlockProcessorException$FailedScanException: Error while scanning blocks. This most likely means a problem with locally persisted data. See logs for details.))
2023-09-21 08:44:47.591 30963-30963 Twig                    com.nighthawkapps.wallet.android     V                              main                           CompactBlockProcessor.getScanProgress$zcash_android_sdk_2_0_0_rc_2_release(): Successfully called getScanProgress with result: ScanProgress(253405/72585389) -> 0.0034911295
2023-09-21 08:44:47.591 30963-30963 Twig                    com.nighthawkapps.wallet.android     I                              main                           CompactBlockProcessor.emit(): Progress from rust: 0.0034911295
2023-09-21 08:44:47.592 30963-30963 Twig                    com.nighthawkapps.wallet.android     D                              main                           CompactBlockProcessor.checkSaplingBalance$zcash_android_sdk_2_0_0_rc_2_release(): Checking Sapling balance
2023-09-21 08:44:48.666 30963-30963 Twig                    com.nighthawkapps.wallet.android     I                              main                           CompactBlockProcessor.getBalanceInfo(): Found total balance: Zatoshi(value=684007899)
2023-09-21 08:44:49.737 30963-30963 Twig                    com.nighthawkapps.wallet.android     I                              main                           CompactBlockProcessor.getBalanceInfo(): Found available balance: Zatoshi(value=0)
2023-09-21 08:44:49.737 30963-30963 Twig                    com.nighthawkapps.wallet.android     D                              main                           CompactBlockProcessor.checkTransparentBalance$zcash_android_sdk_2_0_0_rc_2_release(): Checking Transparent balance
2023-09-21 08:44:49.756 30963-30963 Twig                    com.nighthawkapps.wallet.android     D                              main                           CompactBlockProcessor.start(): processNewBlocks MUTEX: releasing lock
2023-09-21 08:44:49.757 30963-30963 Twig                    com.nighthawkapps.wallet.android     E                              main                           CompactBlockProcessor.start(): Failed while processing blocks at height: BlockHeight(value=2234278) with: cash.z.ecc.android.sdk.exception.CompactBlockProcessorException$FailedScanException: Error while scanning blocks. This most likely means a problem with locally persisted data. See logs for details.
2023-09-21 08:44:49.760 30963-10292 ConnectivityManager     com.nighthawkapps.wallet.android     D  StackLog: [android.net.ConnectivityManager.unregisterNetworkCallback(ConnectivityManager.java:4972)] [io.grpc.android.AndroidChannelBuilder$AndroidChannel$1.run(AndroidChannelBuilder.java:222)] [io.grpc.android.AndroidChannelBuilder$AndroidChannel.unregisterNetworkListener(AndroidChannelBuilder.java:245)] [io.grpc.android.AndroidChannelBuilder$AndroidChannel.shutdown(AndroidChannelBuilder.java:253)] [co.electriccoin.lightwallet.client.internal.LightWalletClientImpl.shutdown(LightWalletClientImpl.kt:238)] [cash.z.ecc.android.sdk.internal.block.CompactBlockDownloader$stop$2.invokeSuspend(CompactBlockDownloader.kt:132)] [kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)] [kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:108)] [kotlinx.coroutines.internal.LimitedDispatcher$Worker.run(LimitedDispatcher.kt:115)] [kotlinx.coroutines.scheduling.TaskImpl.run(Tasks.kt:103)] [kotlinx.coroutines.scheduling.CoroutineScheduler.runSafely(CoroutineScheduler.kt:584)] [kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.executeTask(CoroutineScheduler.kt:793)] [kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.runWorker(CoroutineScheduler.kt:697)] [kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.run(CoroutineScheduler.kt:684)]
2023-09-21 08:44:49.767 30963-30963 Twig                    com.nighthawkapps.wallet.android     E                              main                           CompactBlockProcessor.fail(): Common error while running the block synchronization. This is typically caused by a failed underlying synchronization operation. See failure description: ERROR: unable to resolve the error at height BlockHeight(value=2234278) after 5 correction attempts! OR the root cause: cash.z.ecc.android.sdk.exception.CompactBlockProcessorException$FailedScanException: Error while scanning blocks. This most likely means a problem with locally persisted data. See logs for details.
2023-09-21 08:44:49.769 30963-30963 Twig                    com.nighthawkapps.wallet.android     D                              main                           SdkSynchronizer.onProcessorError(): ERROR while processing data: cash.z.ecc.android.sdk.exception.CompactBlockProcessorException$FailedSynchronizationException: Common error while running the block synchronization. This is typically caused by a failed underlying synchronization operation. See failure description: ERROR: unable to resolve the error at height BlockHeight(value=2234278) after 5 correction attempts! OR the root cause: cash.z.ecc.android.sdk.exception.CompactBlockProcessorException$FailedScanException: Error while scanning blocks. This most likely means a problem with locally persisted data. See logs for details.
2023-09-21 08:44:49.770 30963-30963 nighthawk-(d)           com.nighthawkapps.wallet.android     E  com.nighthawkapps.wallet.android main                           WalletViewModel.invoke(): WALLET - Error Processor: cash.z.ecc.android.sdk.exception.CompactBlockProcessorException$FailedSynchronizationException: Common error while running the block synchronization. This is typically caused by a failed underlying synchronization operation. See failure description: ERROR: unable to resolve the error at height BlockHeight(value=2234278) after 5 correction attempts! OR the root cause: cash.z.ecc.android.sdk.exception.CompactBlockProcessorException$FailedScanException: Error while scanning blocks. This most likely means a problem with locally persisted data. See logs for details.
2023-09-21 08:44:49.773 30963-30963 Twig                    com.nighthawkapps.wallet.android     D                              main                           SdkSynchronizer.onProcessorError(): processor error handler signaled that we should abort!
2023-09-21 08:44:49.777 30963-30963 Twig                    com.nighthawkapps.wallet.android     E                              main                           SdkSynchronizer.onCriticalError(): Critical error occurred
                                                                                                    cash.z.ecc.android.sdk.exception.CompactBlockProcessorException$FailedSynchronizationException: Common error while running the block synchronization. This is typically caused by a failed underlying synchronization operation. See failure description: ERROR: unable to resolve the error at height BlockHeight(value=2234278) after 5 correction attempts! OR the root cause: cash.z.ecc.android.sdk.exception.CompactBlockProcessorException$FailedScanException: Error while scanning blocks. This most likely means a problem with locally persisted data. See logs for details.
                                                                                                        at cash.z.ecc.android.sdk.block.processor.CompactBlockProcessor.checkErrorAndFail(CompactBlockProcessor.kt:374)
                                                                                                        at cash.z.ecc.android.sdk.block.processor.CompactBlockProcessor.start(CompactBlockProcessor.kt:336)
                                                                                                        at cash.z.ecc.android.sdk.block.processor.CompactBlockProcessor$start$1.invokeSuspend(Unknown Source:14)
                                                                                                        at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
                                                                                                        at kotlinx.coroutines.internal.ScopeCoroutine.afterResume(Scopes.kt:32)
                                                                                                        at kotlinx.coroutines.AbstractCoroutine.resumeWith(AbstractCoroutine.kt:102)
                                                                                                        at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:46)
                                                                                                        at kotlinx.coroutines.flow.internal.SafeCollector.invokeSuspend(SafeCollector.kt:48)
                                                                                                        at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
                                                                                                        at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:108)
                                                                                                        at android.os.Handler.handleCallback(Handler.java:938)
                                                                                                        at android.os.Handler.dispatchMessage(Handler.java:99)
                                                                                                        at android.os.Looper.loopOnce(Looper.java:226)
                                                                                                        at android.os.Looper.loop(Looper.java:313)
                                                                                                        at android.app.ActivityThread.main(ActivityThread.java:8663)
                                                                                                        at java.lang.reflect.Method.invoke(Native Method)
                                                                                                        at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:571)
                                                                                                        at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1135)
HonzaR commented 1 year ago

@Mandeepbhalothia, as for the first shorter log. It could be the planned block synchronization which is necessary by design of the newly implemented spend-before-sync mechanism. The log should continue with Planned restarting of block synchronization.... Could that be the case? See a similar around the block synchronization restart in my test:

...
CompactBlockProcessor.invokeSuspend(): All sync stages done for the batch 38/2905: BlockBatch(order=38, range=BlockHeight(value=1938701)..BlockHeight(value=1938800), blocks=100) with result state: AllSuccess
CompactBlockProcessor.emit(): Progress from rust: 0.016542448
CompactBlockProcessor.getBalanceInfo$suspendImpl(): Found total balance: Zatoshi(value=0)
CompactBlockProcessor.getBalanceInfo$suspendImpl(): Found available balance: Zatoshi(value=0)
CompactBlockDownloader.invokeSuspend(): Blocks in range BlockHeight(value=1938901)..BlockHeight(value=1939000) failed to download with: kotlinx.coroutines.flow.internal.AbortFlowException: Flow was aborted, no more elements needed
CompactBlockProcessor.downloadBatchOfBlocks$zcash_android_sdk_2_0_0_rc_2_release(): Retrying (1/5) in 500s...
CompactBlockProcessor.start$suspendImpl(): Planned restarting of block synchronization...
CompactBlockProcessor.putSaplingSubtreeRoots$zcash_android_sdk_2_0_0_rc_2_release(): Sapling subtree roots put successfully with startIndex: 0 and roots: 1114
CompactBlockProcessor.processNewBlocksInSbSOrder(): Beginning to process new blocks with Spend-before-Sync approach with lower bound: BlockHeight(value=1934900))...
CompactBlockProcessor.updateChainTip$zcash_android_sdk_2_0_0_rc_2_release(): Chain tip updated successfully with height: BlockHeight(value=2234529)
CompactBlockProcessor.suggestScanRanges$zcash_android_sdk_2_0_0_rc_2_release(): Successfully got newly suggested ranges: [ScanRange(range=BlockHeight(value=2234519)..BlockHeight(value=2234529), priority=ChainTip), ScanRange(range=BlockHeight(value=1938901)..BlockHeight(value=2225472), priority=Historic)]
CompactBlockProcessor.runSbSSyncingPreparation$suspendImpl(): Check for verification of ranges resulted with: cash.z.ecc.android.sdk.block.processor.model.VerifySuggestedScanRange$NoRangeToVerify@e824fc6
CompactBlockProcessor.processNewBlocksInSbSOrder(): Preparation phase done with result: Success(suggestedRangesResult=Success(ranges=[ScanRange(range=BlockHeight(value=2234519)..BlockHeight(value=2234529), priority=ChainTip), ScanRange(range=BlockHeight(value=1938901)..BlockHeight(value=2225472), priority=Historic)]), verifyRangeResult=cash.z.ecc.android.sdk.block.processor.model.VerifySuggestedScanRange$NoRangeToVerify@e824fc6)
CompactBlockProcessor.invokeSuspend(): Syncing blocks in range BlockHeight(value=2234519)..BlockHeight(value=2234529)
CompactBlockProcessor.emit(): Progress from rust: 0.016558735
...

Note that I use level:info filter in the logcat to filter out unimportant logs.

HonzaR commented 1 year ago

@Mandeepbhalothia Please, could you assist by answering these few questions?

  1. I assume that the error occurs on Mainnet only. Have you been able to reproduce it for a testnet wallet as well?
  2. Is that happening only for the older wallet you use? Or, again, is any other Mainnet wallet impacted for you?
  3. If you switch back to the latest pre spend-before-sync SDK release (v1.21.0-beta01), are you able to reproduce it?
  4. Could you please try to sync the same old impacted wallet in the Zashi wallet? You will need to pull branch 944-adopt-sdk-with-sbs, which targets SDK 2.0.0-rc.2, and build it on your machine.
Mandeepbhalothia commented 1 year ago

Hi @HonzaR

  1. No, I am not able to reproduce on testnet as I don't have old wallet on testnet.
  2. I see this is on my wallet only, I think @nighthawk24 tried on other wallet that got synced but not sure what was the last synced for those wallets.
  3. I can try this but I haven't tried.
  4. Sure I can try the mentioned branch, Thanks.
HonzaR commented 1 year ago

Okay, I await your results for the 3 and 4 steps. In the meantime, I'm running synchronization of my older mainnet wallet with your Nighthawk wallet app, and everything is fine so far.

HonzaR commented 1 year ago

It'll also be great to have @nuttycom, @str4d, or @daira eyes on the log you've provided. I see a potential bug cause coming from the FFI layer at the end of the second line RuntimeException: Rust error while scanning blocks (limit 12): Scan(PrevHashMismatch { at_height: BlockHeight(2234278) })

HonzaR commented 1 year ago

@Mandeepbhalothia, can you see any pattern in the error occurrence? E.g., always the same failed height, or after some action you do on the device? Any information could be helpful.

Mandeepbhalothia commented 1 year ago

Yes, on rc2 height is same and same error. It try 5 times but fail again on same hight. But on rc1 it was for different height

HonzaR commented 1 year ago

@Mandeepbhalothia, could you please do one more thing? Keep your device and Nighthawk wallet app with the old wallet as is, as it's useful to be able to reproduce the error repeatedly, but also try to sync your old wallet within another device with the same setup Nighthawk wallet + Zcash SDK 2.0.0_rc.2 from scratch to avoid the the PrevHashMismatch error you're getting.

Mandeepbhalothia commented 1 year ago

Checked on rc3 version and issue persists. Below are the logs

and before these logs it tries as below:

CompactBlockDownloader.invokeSuspend(): All blocks in range BlockHeight(value=2234273)..BlockHeight(value=2234372) downloaded successfully
2023-09-21 21:43:17.544 18814-18814 Twig com.nighthawkapps.wallet.android V  main  CompactBlockProcessor.downloadBatchOfBlocks$zcash_android_sdk_2_0_0_rc_3_release(): Successfully downloaded batch: BlockBatch(order=89, range=BlockHeight(value=2234273)..BlockHeight(value=2234372), blocks=null) of [cash.z.ecc.android.sdk.internal.model.JniBlockMeta@db030ad, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@5a79fe2, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@5e21f73, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@cce9e30, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@14c2aa9, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@a23d82e, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@eb53fcf, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@5b76d5c, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@393c865, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@19493a, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@bf009eb, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@efc0348, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@bfd85e1, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@6c2bf06, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@bc359c7, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@e720bf4, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@8eb9f1d, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@43bc592, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@491cb63, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@f9df360, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@2a81019, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@2cca8de, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@64bbabf, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@fdee58c, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@22094d5, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@6f674ea, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@58b43db, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@15ace78, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@762a951, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@a3ef5b6, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@c7042b7, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@aa5a24, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@bd7898d, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@6bcb742, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@d3c5353, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@944f490, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@c403189, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@f63058e, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@2aed1af, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@4acc9bc, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@6715d45, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@10dec9a, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@a20d9cb, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@5ac5a8, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@6cf88c1, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@84e3866, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@36147a7, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@66a9454, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@18aeffd, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@7f574f2, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@250b743, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@506a1c0, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@39b8ef9, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@c61ee3e, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@e3d849f, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@9419ec, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@77d21b5, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@78ab04a, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@affcbbb, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@c9ee8d8, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@9ab2431, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@1cb8716, cash.z.ecc.android.sdk.internal.model.JniBlockMeta@7d56897, cash.z.ecc.
2023-09-21 21:43:17.545 18814-18814 Twig com.nighthawkapps.wallet.android D  main  CompactBlockProcessor.emit(): Syncing process starts for batch: BlockBatch(order=90, range=BlockHeight(value=2234373)..BlockHeight(value=2234472), blocks=null)
2023-09-21 21:43:17.546 18814-18814 Twig com.nighthawkapps.wallet.android V  main  CompactBlockProcessor.downloadBatchOfBlocks$zcash_android_sdk_2_0_0_rc_3_release(): Starting to download batch BlockBatch(order=90, range=BlockHeight(value=2234373)..BlockHeight(value=2234472), blocks=null)
2023-09-21 21:43:17.551 18814-18814 Twig com.nighthawkapps.wallet.android D  main  CompactBlockProcessor.emit(): Download stage done with result: SyncStageResult(batch=BlockBatch(order=89, range=BlockHeight(value=2234273)..BlockHeight(value=2234372), blocks=null), stageResult=DownloadSuccess with 100 blocks)
2023-09-21 21:43:18.156 18814-18814 Twig com.nighthawkapps.wallet.android E  main  CompactBlockProcessor.scanBatchOfBlocks$zcash_android_sdk_2_0_0_rc_3_release(): Failed while scanning batch BlockBatch(order=89, range=BlockHeight(value=2234273)..BlockHeight(value=2234372), blocks=100) with java.lang.RuntimeException: Rust error while scanning blocks (limit 100): The underlying datasource produced the following error: An error occurred accessing or updating note commitment tree data: Inserted root conflicts with existing root at address Address { level: Level(3), index: 9128357 }.
2023-09-21 21:43:18.158 18814-18814 Twig com.nighthawkapps.wallet.android D  main  CompactBlockProcessor.emit(): Scan stage done with result: SyncStageResult(batch=BlockBatch(order=89, range=BlockHeight(value=2234273)..BlockHeight(value=2234372), blocks=100), stageResult=ScanFailed(failedAtHeight=BlockHeight(value=2234273), exception=cash.z.ecc.android.sdk.exception.CompactBlockProcessorException$FailedScanException: Error while scanning blocks. This most likely means a problem with locally persisted data. See logs for details.))
2023-09-21 21:43:18.158 18814-18814 Twig com.nighthawkapps.wallet.android D  main  CompactBlockProcessor.invokeSuspend(): Deletion stage done with result: SyncStageResult(batch=BlockBatch(order=89, range=BlockHeight(value=2234273)..BlockHeight(value=2234372), blocks=100), stageResult=ScanFailed(failedAtHeight=BlockHeight(value=2234273), exception=cash.z.ecc.android.sdk.exception.CompactBlockProcessorException$FailedScanException: Error while scanning blocks. This most likely means a problem with locally persisted data. See logs for details.))
2023-09-21 21:43:18.804 18814-18814 Twig com.nighthawkapps.wallet.android V  main  CompactBlockProcessor.getScanProgress$zcash_android_sdk_2_0_0_rc_3_release(): Successfully called getScanProgress with result: ScanProgress(155263/72585389) -> 0.002139039
2023-09-21 21:43:18.804 18814-18814 Twig com.nighthawkapps.wallet.android I  main  CompactBlockProcessor.emit(): Progress from rust: 0.002139039
2023-09-21 21:43:18.804 18814-18814 Twig com.nighthawkapps.wallet.android D  main  CompactBlockProcessor.checkSaplingBalance$zcash_android_sdk_2_0_0_rc_3_release(): Checking Sapling balance
2023-09-21 21:43:19.456 18814-18814 Twig com.nighthawkapps.wallet.android I  main  CompactBlockProcessor.getBalanceInfo(): Found total balance: Zatoshi(value=7899)
2023-09-21 21:43:20.104 18814-18814 Twig com.nighthawkapps.wallet.android I  main  CompactBlockProcessor.getBalanceInfo(): Found available balance: Zatoshi(value=0)
2023-09-21 21:43:20.104 18814-18814 Twig com.nighthawkapps.wallet.android D  main  CompactBlockProcessor.checkTransparentBalance$zcash_android_sdk_2_0_0_rc_3_release(): Checking Transparent balance
2023-09-21 21:43:20.108 18814-18814 Twig com.nighthawkapps.wallet.android V  main  CompactBlockDownloader.invokeSuspend(): Downloading block at height: 2234373 succeeded.
2023-09-21 21:43:20.116 18814-18814 Twig com.nighthawkapps.wallet.android V  main  CompactBlockDownloader.invokeSuspend(): Downloading block at height: 2234374 succeeded.
2023-09-21 21:43:20.123 18814-18814 Twig com.nighthawkapps.wallet.android W  main  CompactBlockDownloader.invokeSuspend(): Blocks in range BlockHeight(value=2234373)..BlockHeight(value=2234472) failed to download with: kotlinx.coroutines.flow.internal.AbortFlowException: Flow was aborted, no more elements needed
2023-09-21 21:43:20.124 18814-18814 Twig com.nighthawkapps.wallet.android W  main  CompactBlockProcessor.downloadBatchOfBlocks$zcash_android_sdk_2_0_0_rc_3_release(): Retrying (1/5) in 500s...
    kotlinx.coroutines.flow.internal.AbortFlowException: Flow was aborted, no more elements needed
2023-09-21 21:43:20.126 18814-18814 Twig com.nighthawkapps.wallet.android D  main  CompactBlockProcessor.start(): processNewBlocks MUTEX: releasing lock
2023-09-21 21:43:20.126 18814-18814 Twig com.nighthawkapps.wallet.android E  main  CompactBlockProcessor.start(): Failed while processing blocks at height: BlockHeight(value=2234273) with: cash.z.ecc.android.sdk.exception.CompactBlockProcessorException$FailedScanException: Error while scanning blocks. This most likely means a problem with locally persisted data. See logs for details.
2023-09-21 21:43:20.128 18814-18814 Twig com.nighthawkapps.wallet.android I  main  CompactBlockProcessor.start(): Sleeping for 4.873sms (latest height: BlockHeight(value=2234903)).
2023-09-21 21:43:25.006 18814-18814 Twig com.nighthawkapps.wallet.android D  main  CompactBlockProcessor.start(): processNewBlocks MUTEX: acquiring lock...
2023-09-21 21:43:25.007 18814-18814 Twig com.nighthawkapps.wallet.android D  main  CompactBlockProcessor.start(): processNewBlocks MUTEX: ...lock acquired!
2023-09-21 21:43:30.284 18814-18814 Twig com.nighthawkapps.wallet.android I  main  CompactBlockProcessor.putSaplingSubtreeRoots$zcash_android_sdk_2_0_0_rc_3_release(): Sapling subtree roots put successfully with startIndex: 0 and roots: 1114
2023-09-21 21:43:30.284 18814-18814 Twig com.nighthawkapps.wallet.android I  main  CompactBlockProcessor.processNewBlocksInSbSOrder(): Beginning to process new blocks with Spend-before-Sync approach with lower bound: BlockHeight(value=1079900))...
2023-09-21 21:43:30.284 18814-18814 Twig com.nighthawkapps.wallet.android D  main  CompactBlockProcessor.fetchLatestBlockHeight$zcash_android_sdk_2_0_0_rc_3_release(): Fetching latest block height...
2023-09-21 21:43:30.762 18814-18814 Twig com.nighthawkapps.wallet.android D  main  CompactBlockProcessor.fetchLatestBlockHeight$zcash_android_sdk_2_0_0_rc_3_release(): Latest block height fetched successfully with value: 2234909
2023-09-21 21:43:30.825 18814-18814 Twig com.nighthawkapps.wallet.android I  main  CompactBlockProcessor.updateChainTip$zcash_android_sdk_2_0_0_rc_3_release(): Chain tip updated successfully with height: BlockHeight(value=2234909)
2023-09-21 21:43:30.829 18814-18814 Twig com.nighthawkapps.wallet.android I  main  CompactBlockProcessor.suggestScanRanges$zcash_android_sdk_2_0_0_rc_3_release(): Successfully got newly suggested ranges: [ScanRange(range=BlockHeight(value=2234273)..BlockHeight(value=2234282), priority=Verify), ScanRange(range=BlockHeight(value=2234283)..BlockHeight(value=2234909), priority=ChainTip), ScanRange(range=BlockHeight(value=1213706)..BlockHeight(value=1256932), priority=FoundNote), ScanRange(range=BlockHeight(value=1256933)..BlockHeight(value=2225472), priority=Historic)]
2023-09-21 21:43:30.829 18814-18814 Twig com.nighthawkapps.wallet.android D  main  CompactBlockProcessor.fetchLatestBlockHeight$zcash_android_sdk_2_0_0_rc_3_release(): Fetching latest block height...
2023-09-21 21:43:31.126 18814-18814 Twig com.nighthawkapps.wallet.android D  main  CompactBlockProcessor.fetchLatestBlockHeight$zcash_android_sdk_2_0_0_rc_3_release(): Latest block height fetched successfully with value: 2234909
2023-09-21 21:43:31.135 18814-18814 Twig com.nighthawkapps.wallet.android D  main  CompactBlockProcessor.shouldVerifySuggestedScanRanges$zcash_android_sdk_2_0_0_rc_3_release(): Check for Priority.Verify scan range result: [ScanRange(range=BlockHeight(value=2234273)..BlockHeight(value=2234282), priority=Verify), ScanRange(range=BlockHeight(value=2234283)..BlockHeight(value=2234909), priority=ChainTip), ScanRange(range=BlockHeight(value=1213706)..BlockHeight(value=1256932), priority=FoundNote), ScanRange(range=BlockHeight(value=1256933)..BlockHeight(value=2225472), priority=Historic)]
2023-09-21 21:43:31.135 18814-18814 Twig com.nighthawkapps.wallet.android I  main  CompactBlockProcessor.runSbSSyncingPreparation$zcash_android_sdk_2_0_0_rc_3_release(): Check for verification of ranges resulted with: ShouldVerify(scanRange=ScanRange(range=BlockHeight(value=2234273)..BlockHeight(value=2234282), priority=Verify))
2023-09-21 21:43:31.136 18814-18814 Twig com.nighthawkapps.wallet.android I  main  CompactBlockProcessor.processNewBlocksInSbSOrder(): Preparation phase done with result: Success(suggestedRangesResult=Success(ranges=[ScanRange(range=BlockHeight(value=2234273)..BlockHeight(value=2234282), priority=Verify), ScanRange(range=BlockHeight(value=2234283)..BlockHeight(value=2234909), priority=ChainTip), ScanRange(range=BlockHeight(value=1213706)..BlockHeight(value=1256932), priority=FoundNote), ScanRange(range=BlockHeight(value=1256933)..BlockHeight(value=2225472), priority=Historic)]), verifyRangeResult=ShouldVerify(scanRange=ScanRange(range=BlockHeight(value=2234273)..BlockHeight(value=2234282), priority=Verify)))
2023-09-21 21:43:31.136 18814-18814 Twig com.nighthawkapps.wallet.android I  main  CompactBlockProcessor.processNewBlocksInSbSOrder(): Starting verification of range: ShouldVerify(scanRange=ScanRange(range=BlockHeight(value=2234273)..BlockHeight(value=2234282), priority=Verify))
2023-09-21 21:43:31.137 18814-18814 Twig com.nighthawkapps.wallet.android I  main  CompactBlockProcessor.invokeSuspend(): Syncing blocks in range BlockHeight(value=2234273)..BlockHeight(value=2234282)
2023-09-21 21:43:31.137 18814-18814 Twig com.nighthawkapps.wallet.android D  main  CompactBlockProcessor.getBatchCount(): Found 10 missing blocks, syncing in 1 batches of 100...
2023-09-21 21:43:31.142 18814-18814 Twig com.nighthawkapps.wallet.android I  main  WalletView.WalletView(): walletSnapshot WalletSnapshot(status=SYNCING, processorInfo=ProcessorInfo(networkBlockHeight=BlockHeight(value=2234909), overallSyncRange=BlockHeight(value=1213706)..BlockHeight(value=2234909), firstUnenhancedHeight=null), orchardBalance=WalletBalance(total=Zatoshi(value=0), available=Zatoshi(value=0)), saplingBalance=WalletBalance(total=Zatoshi(value=7899), available=Zatoshi(value=0)), transparentBalance=WalletBalance(total=Zatoshi(value=0), available=Zatoshi(value=0)), progress=PercentDecimal(decimal=0.002139039), synchronizerError=co.electriccoin.zcash.ui.screen.home.viewmodel.SynchronizerError$Chain@9cb8c22) and is fiat currency preferred false
2023-09-21 21:43:31.192 18814-18814 Twig com.nighthawkapps.wallet.android D  main  CompactBlockProcessor.emit(): Syncing process starts for batch: BlockBatch(order=1, range=BlockHeight(value=2234273)..BlockHeight(value=2234282), blocks=null)
2023-09-21 21:43:31.193 18814-18814 Twig com.nighthawkapps.wallet.android V  main  CompactBlockProcessor.downloadBatchOfBlocks$zcash_android_sdk_2_0_0_rc_3_release(): Starting to download batch BlockBatch(order=1, range=BlockHeight(value=2234273)..BlockHeight(value=2234282), blocks=null)
2023-09-21 21:43:33.114 18814-18814 Twig com.nighthawkapps.wallet.android V  main  CompactBlockDownloader.invokeSuspend(): Downloading block at height: 2234273 succeeded.

SdkSynchronizer.onCriticalError(): Critical error occurred
cash.z.ecc.android.sdk.exception.CompactBlockProcessorException$FailedSynchronizationException: Common error while running the block synchronization. This is typically caused by a failed underlying synchronization operation. See failure description: ERROR: unable to resolve the error at height BlockHeight(value=2234273) after 5 correction attempts! OR the root cause: cash.z.ecc.android.sdk.exception.CompactBlockProcessorException$FailedScanException: Error while scanning blocks. This most likely means a problem with locally persisted data. See logs for details.
    at cash.z.ecc.android.sdk.block.processor.CompactBlockProcessor.checkErrorAndFail(CompactBlockProcessor.kt:377)
    at cash.z.ecc.android.sdk.block.processor.CompactBlockProcessor.start(CompactBlockProcessor.kt:339)
    at cash.z.ecc.android.sdk.block.processor.CompactBlockProcessor$start$1.invokeSuspend(Unknown Source:14)
    at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
    at kotlinx.coroutines.internal.ScopeCoroutine.afterResume(Scopes.kt:32)
    at kotlinx.coroutines.AbstractCoroutine.resumeWith(AbstractCoroutine.kt:102)
    at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:46)
    at kotlinx.coroutines.flow.internal.SafeCollector.invokeSuspend(SafeCollector.kt:48)
    at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
    at kotlinx.coroutines.flow.internal.SafeCollector.invokeSuspend(SafeCollector.kt:48)
    at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
    at kotlinx.coroutines.internal.ScopeCoroutine.afterResume(Scopes.kt:32)
    at kotlinx.coroutines.AbstractCoroutine.resumeWith(AbstractCoroutine.kt:102)
    at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:46)
    at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:108)
    at android.os.Handler.handleCallback(Handler.java:938)
    at android.os.Handler.dispatchMessage(Handler.java:99)
    at android.os.Looper.loopOnce(Looper.java:226)
    at android.os.Looper.loop(Looper.java:313)
    at android.app.ActivityThread.main(ActivityThread.java:8663)
    at java.lang.reflect.Method.invoke(Native Method)
    at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:571)
    at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1135)
2023-09-21 21:44:37.124 18814-18814 Twig                    com.nighthawkapps.wallet.android I  main  WalletView.WalletView(): walletSnapshot WalletSnapshot(status=STOPPED, processorInfo=ProcessorInfo(networkBlockHeight=BlockHeight(value=2234911), overallSyncRange=BlockHeight(value=1213706)..BlockHeight(value=2234911), firstUnenhancedHeight=null), orchardBalance=WalletBalance(total=Zatoshi(value=0), available=Zatoshi(value=0)), saplingBalance=WalletBalance(total=Zatoshi(value=7899), available=Zatoshi(value=0)), transparentBalance=WalletBalance(total=Zatoshi(value=0), available=Zatoshi(value=0)), progress=PercentDecimal(decimal=0.002139039), synchronizerError=co.electriccoin.zcash.ui.screen.home.viewmodel.SynchronizerError$Processor@317c2db) and is fiat currency preferred false
2023-09-21 21:47:00.758 18814-18814 ViewRootIm...rActivity] com.nighthawkapps.wallet.android I  ViewPostIme pointer 0
2023-09-21 21:47:00.915 18814-18814 ViewRootIm...rActivity] com.nighthawkapps.wallet.android I  MSG_WINDOW_FOCUS_CHANGED 0 1
2023-09-21 21:47:01.790 18814-18814 ViewRootIm...rActivity] com.nighthawkapps.wallet.android I  handleAppVisibility mAppVisible=true visible=false
2023-09-21 21:47:01.793 18814-18814 ViewRootIm...rActivity] com.nighthawkapps.wallet.android I  stopped(true) old=false
2023-09-21 21:47:01.815 18814-19097 OpenGLRenderer          com.nighthawkapps.wallet.android D  setSurface called with nullptr
2023-09-21 21:47:01.816 18814-19097 OpenGLRenderer          com.nighthawkapps.wallet.android D  setSurface() destroyed EGLSurface
2023-09-21 21:47:01.816 18814-19097 OpenGLRenderer          com.nighthawkapps.wallet.android D  destroyEglSurface
2023-09-21 21:47:01.817 18814-19097 BufferQueueProducer     com.nighthawkapps.wallet.android I  [ViewRootImpl@c3db914[LauncherActivity]#0(BLAST Consumer)0](id:497e00000000,api:1,p:18814,c:18814) disconnect: api 1
2023-09-21 21:47:01.820 18814-19097 BLASTBufferQueue        com.nighthawkapps.wallet.android I  [ViewRootImpl@c3db914[LauncherActivity]#0] destructor()
2023-09-21 21:47:01.820 18814-19097 BufferQueueConsumer     com.nighthawkapps.wallet.android I  [ViewRootImpl@c3db914[LauncherActivity]#0(BLAST Consumer)0](id:497e00000000,api:0,p:-1,c:18814) disconnect
2023-09-21 21:47:01.859 18814-18814 ViewRootIm...rActivity] com.nighthawkapps.wallet.android I  Relayout returned: old=(0,0,1080,2400) new=(0,0,1080,2400) req=(1080,2400)8 dur=36 res=0x5 s={false 0} ch=false fn=-1
2023-09-21 21:47:01.874  1520-8607  WindowManager           system_server                    E  win=Window{2475f26 u0 com.nighthawkapps.wallet.android/co.electricoin.zcash.LauncherActivity} destroySurfaces: appStopped=true win.mWindowRemovalAllowed=false win.mRemoveOnExit=false win.mViewVisibility=8 caller=com.android.server.wm.ActivityRecord.destroySurfaces:5873 com.android.server.wm.ActivityRecord.destroySurfaces:5854 com.android.server.wm.ActivityRecord.notifyAppStopped:5918 com.android.server.wm.ActivityRecord.activityStopped:6560 com.android.server.wm.ActivityClientController.activityStopped:254 android.app.IActivityClientController$Stub.onTransact:596 com.android.server.wm.ActivityClientController.onTransact:130 
2023-09-21 21:47:01.876 18814-18814 InputTransport          com.nighthawkapps.wallet.android D  Input channel destroyed: 'ClientS', fd=123
HonzaR commented 1 year ago

The important part of the log is this:

CompactBlockProcessor.scanBatchOfBlocks$zcash_android_sdk_2_0_0_rc_3_release(): Failed while scanning batch BlockBatch(order=89, range=BlockHeight(value=2234273)..BlockHeight(value=2234372), blocks=100) with java.lang.RuntimeException: Rust error while scanning blocks (limit 100): The underlying datasource produced the following error: An error occurred accessing or updating note commitment tree data: Inserted root conflicts with existing root at address Address { level: Level(3), index: 9128357 }.

We're on it. Thank you for reporting it.

nuttycom commented 1 year ago

@Mandeepbhalothia has reported that this later error occurred when upgrading from rc.2 to rc.3, after his wallet encountered several errors related to problems in the earlier RC, but after re-syncing has not reported this issue since. Closing as tentatively fixed; the error reported here ended up being three separate things, so please open a new issue if the last of these recurs.