zecwalletlitelib gets stuck on block height.

[dannasessha]

Versions of all involved: zwll - [zancas feature] - (https://github.com/zancas/zecwalletlitelib/tree/lrzc_upgrade_2): c213ce lwd - [zcash master] - (https://github.com/zcash/lightwalletd): ba1b93 zcd - [zcash master] - (https://github.com/zcash/zcash): aad3da

My pattern: Had zcashd running on testnet, synched. Had lightwalletd running (with --no-tls-very-insecure flag), was generating messages such as {"app":"lightwalletd","level":"info","msg":"Refreshing mempool","time":"...."} Ran cargo run in zecwalletlightlib directory with patch

-pub const DEFAULT_SERVER: &str = "https://lwdv3.zecwallet.co";
+pub const DEFAULT_SERVER: &str = "http://127.0.0.1:9067";

in /lib/src/lightclient/lightclient_config.rs Got a cli interface, was able to run help and interact. I generated new z address. Then received tx with memo, decoding memo. I tried to send and noticed it would not allow me. I could see TAZ in "unverified_zbalance" field with balance. The block number on cli line stuck at an earlier number (before) recognized transaction.

message seen when attempting to send:

Error with response: Status { code: Unknown, message: "Cache is empty. Server is probably not yet ready", metadata: MetadataMap { headers: {"content-type": "application/grpc"} }, source: None 

Same message after trying sync.

I quit, restarted the cli application, and the block has still not updated. running rescan just generates the same Error.

Trying to see TAZ with balance again failed! That is, I could not see any TAZ or a memo.

[dannasessha]

stopping zecwalletlitelib, then rebooting zcashd, and then lightwalletd - lightwalletd started outputting messages such as: {"app":"lightwalletd","level":"info","msg":"Adding block to cache 292629 00225d128cd68a99790f9c32636e881f58911417d1fd372d5fd909ccfdba3a26","time":"2022-05-30T06:46:21Z"}

[dannasessha]

running zecwalletlitelib as cli interface, I am still stuck at the stale block height:

Lightclient connecting to http://127.0.0.1:9067/
Server's latest block(354312) is behind ours(1896036)
Ready!
(test) Block:1896036 (type 'help') >>

This seems strange because I was able to 1> generate a new z address and 2> receive provisional TAZ and see an encrypted memo.

[dannasessha]

Using top I notice zc-wait-to-stop and lightwalletd occupy the top two slots, with combined CPU usage at about 120% .

[dannasessha]

Eventually, lightwalletd did sync to the block height that zcashd registered, and the messages became just like: {"app":"lightwalletd","level":"info","msg":"Waiting for block: 1896221","time":"..."}

At that point, I did cargo run again with zecwalletlightlib, and the cli display showed Ready! (test) Block:1896220 .. !

Using balance I was able to see the TAZ. Thus, I think this must be some kind of issue having to do with lightwalletd's sync.

Attempting to use send to another z test address seemed to work! Part of the output was Transaction created and showed a txid.

[dannasessha]

Blocks in the cli prompt are now updating, almost keeping pace with zcashd.

[AloeareV]

"Cache is empty. Server is probably not yet ready" is likely the smoking gun here.

According to lightwalletd docs, "lightwalletd caches all blocks from Sapling activation up to the most recent block, which takes about an hour the first time you run lightwalletd. During this syncing, lightwalletd is fully available, but block fetches are slower until the download completes."

This sounds like lightwalletd was having trouble with something. It should start outputting messages like {"app":"lightwalletd","level":"info","msg":"Adding block to cache 292629 00225d128cd68a99790f9c32636e881f58911417d1fd372d5fd909ccfdba3a26","time":"2022-05-30T06:46:21Z"} right away, or nearly. If it wasn't doing that until you restarted, then the problem was likely with lightwalletd or its connection to zcashd.

[dannasessha]

@AloeareV Thank you for the reply. I am going to try to chase down this bug, seems like it may be a lightwalletd issue. If that's the case I plan to open some tickets over there.

[dannasessha]

This is almost certainly some kind of "buggy" behavior due to the sync status.

When I opened this client today having pointed lightwalletd to an empty cache (but zcashd still synced) I got this message: Server's latest block(316583) is behind ours(1897022). I feel like this, coupled with the code: Unknown, message: "Cache is empty. Server is probably not yet ready" I mentioned above, this client is at least letting us know somewhat of what's going on, and we can still generate addresses to receive TAZ, and see that they have received TAZ. We just couldn't spend yet because lightwalletd hadn't filled the cache yet.

The issue where I could see a new transaction but not spend before the cache is full could be tested further or made more clear, but overall we might just add proper documentation for "setting up the stack."