failed due to io.grpc.StatusRuntimeException: INTERNAL: Internal error #6

When debugging downloading blocks, this error is output numerous times in logcat. I did not see this in initial testing and may be related to Android SDK bumping for QR scanning. The blocks eventually all download, but it appears to slow the process down noticeably compared to previous syncs. Will test with reverting back to Android SDK 31.

2022-12-05 20:57:52.957 4030-4389/hush.android W/System.err: @TWIG 12/05/22 08:57:52.956000000[BaseContinuationImpl:33](#downloading)    failed due to io.grpc.StatusRuntimeException: INTERNAL: Internal error
2022-12-05 20:57:54.058 4030-4389/hush.android W/System.err: @TWIG 12/05/22 08:57:54.057000000[BaseContinuationImpl:33](#downloading)    failed due to io.grpc.StatusRuntimeException: INTERNAL: Internal error
2022-12-05 20:57:56.177 4030-4389/hush.android W/System.err: @TWIG 12/05/22 08:57:56.176000000[BaseContinuationImpl:33](#downloading)    downloaded BlockHeight(value=1173061)..BlockHeight(value=1173070) (batch 57 of 372) [BlockHeight(value=1173061)..BlockHeight(value=1173070)] | 111ms
2022-12-05 20:57:56.179 4030-4389/hush.android W/System.err: @TWIG 12/05/22 08:57:56.178000000[BaseContinuationImpl:33](#downloading)    downloaded 10 blocks!
2022-12-05 20:57:56.245 4030-4389/hush.android W/System.err: @TWIG 12/05/22 08:57:56.243000000[BaseContinuationImpl:33](#downloading)    failed due to io.grpc.StatusRuntimeException: INTERNAL: Internal error
2022-12-05 20:57:56.824 4030-4389/hush.android W/System.err: @TWIG 12/05/22 08:57:56.823000000[BaseContinuationImpl:33](#downloading)    failed due to io.grpc.StatusRuntimeException: INTERNAL: Internal error

No difference reverting Android SDK versions. The only other change was enabling secure connections. Likely related to that and would expect some slowness, but not the error. This seems like internals of gRPC and probably not an easy fix unless fixed in a newer version. I see mentions of our lightwalletd using 1.27.0, but looked no further. Releases here: https://github.com/grpc/grpc/releases

Not sure if this is also used:
https://github.com/grpc-ecosystem/go-grpc-middleware

@fekt we could try to upgrade our grpc dependency if we want. According to https://git.hush.is/hush/lightwalletd/src/branch/master/go.mod#L15 we are using v1.50.1 which was released Oct 27 2022 . There have been 2 releases since then. Our older lightwalletd code used 1.24 . I think the 1.27.0 you mention is the current minimum version required by the current version of protobuf format.

@duke I doubt it will solve the error I am seeing if it's already using a more recent version. I thought it may have been using a really old version but didn't dig into it much.

@fekt is this still relevant to the latest code?

@duke Yes, I am still seeing this in logcat and seems to slow syncing down. Still not sure on the cause. It will download blocks, error, download more blocks, error, etc.

Could be something else with newer lightwalletd. I get these errors server-side:

2023/03/25 18:33:49 [error] 225532#225532: *1 upstream sent frame for closed stream 1 while reading upstream, client: 1.1.1.1, server: lite2.hushpool.is, request: "POST /cash.z.wallet.sdk.rpc.CompactTxStreamer/GetBlockRange HTTP/2.0", upstream: "grpc://127.0.0.1:9067", host: "lite2.hushpool.is:443"
2023/03/25 18:33:50 [error] 225532#225532: *1 upstream sent frame for closed stream 1 while reading upstream, client: 1.1.1.1, server: lite2.hushpool.is, request: "POST /cash.z.wallet.sdk.rpc.CompactTxStreamer/GetBlockRange HTTP/2.0", upstream: "grpc://127.0.0.1:9067", host: "lite2.hushpool.is:443"
2023/03/25 18:33:51 [error] 225532#225532: *1 connect() failed (111: Connection refused) while connecting to upstream, client: 1.1.1.1, server: lite2.hushpool.is, request: "POST /cash.z.wallet.sdk.rpc.CompactTxStreamer/GetBlockRange HTTP/2.0", upstream: "grpc://[::1]:9067", host: "lite2.hushpool.is:443"
2023/03/25 18:33:54 [error] 225532#225532: *1 upstream sent frame for closed stream 1 while reading response header from upstream, client: 1.1.1.1, server: lite2.hushpool.is, request: "POST /cash.z.wallet.sdk.rpc.CompactTxStreamer/GetBlockRange HTTP/2.0", upstream: "grpc://127.0.0.1:9067", host: "lite2.hushpool.is:443"

With SDL, I notice similar errors that seem to cause Error: grpc-status: Internal, grpc-message: Unexpected compression flag: 60 randomly even though the server is up.

2023/03/25 18:55:27 [error] 225532#225532: *1024 connect() failed (111: Connection refused) while connecting to upstream, client: 1.1.1.1, server: lite2.hushpool.is, request: "POST /cash.z.wallet.sdk.rpc.CompactTxStreamer/GetLatestBlock HTTP/2.0", upstream: "grpc://[::1]:9067", host: "lite2.hushpool.is:443"
2023/03/25 18:55:28 [error] 225533#225533: *1031 connect() failed (111: Connection refused) while connecting to upstream, client: 1.1.1.1, server: lite2.hushpool.is, request: "POST /cash.z.wallet.sdk.rpc.CompactTxStreamer/GetAddressTxids HTTP/2.0", upstream: "grpc://[::1]:9067", host: "lite2.hushpool.is:443"

Could be something else with newer lightwalletd. I get these errors server-side: ``` 2023/03/25 18:33:49 [error] 225532#225532: *1 upstream sent frame for closed stream 1 while reading upstream, client: 1.1.1.1, server: lite2.hushpool.is, request: "POST /cash.z.wallet.sdk.rpc.CompactTxStreamer/GetBlockRange HTTP/2.0", upstream: "grpc://127.0.0.1:9067", host: "lite2.hushpool.is:443" 2023/03/25 18:33:50 [error] 225532#225532: *1 upstream sent frame for closed stream 1 while reading upstream, client: 1.1.1.1, server: lite2.hushpool.is, request: "POST /cash.z.wallet.sdk.rpc.CompactTxStreamer/GetBlockRange HTTP/2.0", upstream: "grpc://127.0.0.1:9067", host: "lite2.hushpool.is:443" 2023/03/25 18:33:51 [error] 225532#225532: *1 connect() failed (111: Connection refused) while connecting to upstream, client: 1.1.1.1, server: lite2.hushpool.is, request: "POST /cash.z.wallet.sdk.rpc.CompactTxStreamer/GetBlockRange HTTP/2.0", upstream: "grpc://[::1]:9067", host: "lite2.hushpool.is:443" 2023/03/25 18:33:54 [error] 225532#225532: *1 upstream sent frame for closed stream 1 while reading response header from upstream, client: 1.1.1.1, server: lite2.hushpool.is, request: "POST /cash.z.wallet.sdk.rpc.CompactTxStreamer/GetBlockRange HTTP/2.0", upstream: "grpc://127.0.0.1:9067", host: "lite2.hushpool.is:443" ``` With SDL, I notice similar errors that seem to cause `Error: grpc-status: Internal, grpc-message: Unexpected compression flag: 60` randomly even though the server is up. ``` 2023/03/25 18:55:27 [error] 225532#225532: *1024 connect() failed (111: Connection refused) while connecting to upstream, client: 1.1.1.1, server: lite2.hushpool.is, request: "POST /cash.z.wallet.sdk.rpc.CompactTxStreamer/GetLatestBlock HTTP/2.0", upstream: "grpc://[::1]:9067", host: "lite2.hushpool.is:443" 2023/03/25 18:55:28 [error] 225533#225533: *1031 connect() failed (111: Connection refused) while connecting to upstream, client: 1.1.1.1, server: lite2.hushpool.is, request: "POST /cash.z.wallet.sdk.rpc.CompactTxStreamer/GetAddressTxids HTTP/2.0", upstream: "grpc://[::1]:9067", host: "lite2.hushpool.is:443" ```

Could be related to this nginx bug: https://trac.nginx.org/nginx/ticket/2229

My servers all seem to be running 1.18.0 and I didn't notice this originally until enabling SSL. Going to try upgrading to latest version.

@fekt very interesting, that bug does seem very related

@fekt if I am reading their bug tracker correctly, it was fixed in the nginx 1.20.2 release

Yeah, they said it's fixed. I upgraded nginx to 1.23.3 on both of my light servers. Maybe placebo effect, but it seems a little better. I still see this internal error when downloading blocks in SDA but not as frequent. Originally I was seeing it 3-5 times every time it tried to download a single batch of 10 blocks. Now about once every 10 batches. I was about to say I wasn't seeing the grpc error in SDL, but then one popped up.

See connection refused errors like this in logs:

2023/03/25 21:18:01 [error] 227809#227809: *3925 connect() failed (111: Connection refused) while connecting to upstream, client: 1.1.1.1, server: lite2.hushpool.is, request: "POST /cash.z.wallet.sdk.rpc.CompactTxStreamer/GetBlockRange HTTP/2.0", upstream: "grpc://[::1]:9067", host: "lite2.hushpool.is:443"

In SDA, I get a connection refused mostly for GetBlockRange and GetLatestBlock. In SDL, it seems to mostly happen for GetLatestBlock. Ocassionally see connections refused for GetLightdInfo and GetAddressTxids that I think are from SDA.

Not sure if these errors were happening before we started using a newer version of lightwalletd but maybe there are slight differences in RPC calls causing funk.

@fekt it may be that nginx fixed the bug for the original bug poster but we still trigger a different flavor of it. It may be worth posting this as a bug to nginx if you can stomach using Trac

I am not sure if these errors happened in our old lightwalletd code but we were basically forced to update our grpc go dependencies to make things work and I don't think there is any good way to reverse that course. It's possible this bug is related to grpc go code that is a dependency

I am testing some tweaks to the SDK with DragonX version that changes the download and scan batch sizes to be smaller. I just cut them in half from 10 to 5 and 150 to 75. These values are set in this file for reference: https://git.hush.is/hush/hush-android-wallet-sdk/src/branch/main/sdk-lib/src/main/java/cash/z/ecc/android/sdk/ext/ZcashSdk.kt#L40

I am no longer seeing the originally reported error with this change and it seems to sync normally/faster. Possibly a memory issue when trying to scan and download too many blocks at once.

I also changed this to download the sapling params from https://git.hush.is/hush/hush3/raw/branch/master/ instead of Zcash's site as it seems to be blocked in China. Do we host the sapling params in a better location that should be used instead?

@fekt that is the best (and only) place Hush stores the param files, seems fine to use that

OK. It would be nice to include the params and not download them but the app size would probably be too large.

I'll do some more testing with a longer scan/download to see if this error still crops up in the logs with the batch size reduction. Probably test some slightly higher values and see what Zcash is currently using too. I want to say I only saw the original error once we updated lightwalletd but who knows.

Zcash changed how all of this works now. They no longer have DOWNLOAD_BATCH_SIZE or SCAN_BATCH_SIZE. At one point it changed to using a new single value of SYNC_BATCH_SIZE = 10, but that's gone now too and a lot of shit is refactored. Same with downloading the params.

I should maybe test merging code from a newer SDK version at some point but I have no idea if it'll be compatible with lightwalletd or librustzcash we are using.

@fekt ok, thanks for looking into this.

OK. It would be nice to include the params and not download them but the app size would probably be too large.

I'll do some more testing with a longer scan/download to see if this error still crops up in the logs with the batch size reduction. Probably test some slightly higher values and see what Zcash is currently using too. I want to say I only saw the original error once we updated lightwalletd but who knows.

In thinking more about this, it would improve decentralization and reliability to have the params hosted in another location, in case Gitea is down/etc. Perhaps at hush.land or dragonx.is as static files. I also remembered that the params can also be found at https://github.com/hushmirror/hush3 (which hasn't been updated in a real long time) but I am not sure that I like the dependence on that surveillance platform. Perhaps it's better than nothing if all other download locations are down or blocked. I will let y'all decide on that.

@onryo @dan_s is this something you would be interested in? Hosting the 2 files will take about 50MB of disk space and potentially large amounts of bandwidth, so you want to make sure you aren't paying for bandwidth.

Also, it seems like a good idea to also have these files downloadable via Tor and i2p.

OK. It would be nice to include the params and not download them but the app size would probably be too large.

I'll do some more testing with a longer scan/download to see if this error still crops up in the logs with the batch size reduction. Probably test some slightly higher values and see what Zcash is currently using too. I want to say I only saw the original error once we updated lightwalletd but who knows.

In thinking more about this, it would improve decentralization and reliability to have the params hosted in another location, in case Gitea is down/etc. Perhaps at hush.land or dragonx.is as static files. I also remembered that the params can also be found at https://github.com/hushmirror/hush3 (which hasn't been updated in a real long time) but I am not sure that I like the dependence on that surveillance platform. Perhaps it's better than nothing if all other download locations are down or blocked. I will let y'all decide on that.

@onryo @dan_s is this something you would be interested in? Hosting the 2 files will take about 50MB of disk space and potentially large amounts of bandwidth, so you want to make sure you aren't paying for bandwidth.

Also, it seems like a good idea to also have these files downloadable via Tor and i2p.

We can host params somewhere on storage.hush.land.

Zcash's URL was using Cloudfront for a CDN/redundancy to serve their params based on the comments. The code could probably be modified to use a random server list to decentralize things and spread bandwidth, but I haven't really looked at it to even know at what point it tries to download the params. I'll need to check.

It checks for params and downloads them when trying to send your first tx. They are stored in app cache. If cache is cleared, they have to be downloaded again. I modified it to use a list of URLs instead and pick a random one. It seems to work and used a different server for each file when I tested multiple times so I'd just need any other URLs to add. I am using the following currently:

val CLOUD_PARAM_DIR_URL = listOf("https://git.hush.is/hush/hush3/raw/branch/master/",
        "https://github.com/hushmirror/hush3/raw/dev/")

Testing some other values for scan and download batch size, I think the error originally reported might only happen on specific lite servers. For DRGX, it seems to only happen on lite.dragonx.is. I tested changing DOWNLOAD_BATCH_SIZE to a higher number like 50 and don't get these errors when using my own server but haven't tested enough to confirm. I need to test smaller values with lite.dragonx.is again as well. Setting this to a higher value may be ideal provided the selected lite server isn't repeatedly erroring while blocks are being downloaded. We probably need to ensure all servers are configured with same versions of lightwalletd, nginx, etc.

SCAN_BATCH_SIZE is probably good to have a value around or under 75 as it seems to only be able to process ~70 blocks/second regardless of a higher value, but is likely dependent on device. I'm using a really old/shitty phone for testing. Setting higher values will cause the "Scanning..." progress bar to appear to hang and update in larger increments at a slower pace. Smaller values allow the progress bar to update in smaller increments regularly.

There are some other values like POLL_INTERVAL and BLOCK_INTERVAL_MILLIS that I changed for DRGX block time and will change for HUSH as well if I forgot to update them originally.

@fekt thanks for making progress on this.

@onryo sounds like you can put the 2 param files anywhere you want on storage.hush.land and then the directory they are in can be added to CLOUD_PARAM_DIR_URL

@fekt would it be possible to make the code try each CLOUD_PARAM_DIR_URL in order, and try the next one if one is down/blocked ? That way, if any URL works, a user can successfully use the wallet. The current logic means if any one random URL is down, things will fail for the user and it will be hard to determine which URL a users wallet tried when it fails. If so, the best ordering would be hush.land, git.hush.is and then gitflub last.

That or better error handling to retry automatically should be possible. It seems to always check for existence of params when sending and will try to download them if they don't exist. There is a specific error when they don't exist that can likely be checked for.

When sending fails for not having params, there is a retry button to send the tx again. Retrying to send seems to retry downloading the params as well, but I'd need to check the code and test with a bad URL where the params can't be downloaded.