search

status-im / status-desktop

Status Desktop client made in Nim & QML
https://status.app
Mozilla Public License 2.0
291 stars 78 forks source link

Login to the app takes forever in master #16086

Closed anastasiyaig closed 2 months ago

anastasiyaig commented 2 months ago

Bug Report

Description

image

Steps to reproduce

Found with autotests. new accounts could not be created because clicking Start using status button hangs the app for more than 15 seconds

https://ci.status.im/job/status-desktop/job/systems/job/linux/job/x86_64/job/tests-e2e-new/496/allure/#suites/db36b027265858e30e3f42c2f7edffa8/52a4187c811bcc96/

Expected behavior

Login is smooth

Actual behavior

Cant basically create new account with autotests

Additional Information

NOTE 1: it was not the case for build on 10-Aug-2024 https://ci.status.im/job/status-desktop/job/nightly/466/ which was the commit 9acf723ddcec770956d173d8f01a5da38c95e7d8 NOTE 2: it is not the case for release branch of 2.30.x , tests are smooth there https://ci.infra.status.im/job/status-desktop/job/release/job/release%252F2.30.x/48/

anastasiyaig commented 2 months ago

@antdanchenko ^^

alexjba commented 2 months ago

Logs while the app is freezing:

 2024-08-13 10:48:49.089+03:00 NewBE_callPrivateRPC                       topics="rpc" tid=12011950 file=core.nim:27 rpc_method=ens_getName
ERR 2024-08-13 10:49:01.426+03:00 rpc response error                         topics="rpc" tid=12011950 file=core.nim:36 err="\nstatus-go error [methodName:ens_getName, code:-32000, message:not a resolver ]\n"
ERR 2024-08-13 10:49:01.428+03:00 error doing rpc request                    topics="rpc" tid=12011950 file=core.nim:39 methodName=ens_getName exception="\nstatus-go error [methodName:ens_getName, code:-32000, message:not a resolver ]\n"
ERR 2024-08-13 10:49:01.428+03:00 error:                                     topics="wallet-account-service" tid=12011950 file=utils.nim:75 errDesription="\nstatus-go error [methodName:ens_getName, code:-32000, message:not a resolver ]\n"
DBG 2024-08-13 10:49:01.428+03:00 NewBE_callPrivateRPC                       topics="rpc" tid=12011950 file=core.nim:27 rpc_method=ens_getName
2024-08-13T10:49:03+0300 NIL [github.com/anacrolix/torrent.(*Client).NewAnacrolixDhtServer.func2:406]: dht server on 0.0.0.0:60089 (node id 1e0a075929b883cf3216f3dcc0d84af679808b14) completed bootstrap ({NumAddrsTried:47 NumResponses:24})
2024-08-13T10:49:05+0300 NIL [github.com/anacrolix/torrent.(*Client).NewAnacrolixDhtServer.func2:406]: dht server on [::]:60089 (node id c5dc157b02cf17ec5e3f63ecdffc884f59ae94a5) completed bootstrap ({NumAddrsTried:45 NumResponses:20})
ERR 2024-08-13 10:49:08.895+03:00 rpc response error                         topics="rpc" tid=12011950 file=core.nim:36 err="\nstatus-go error [methodName:ens_getName, code:-32000, message:not a resolver ]\n"
ERR 2024-08-13 10:49:08.895+03:00 error doing rpc request                    topics="rpc" tid=12011950 file=core.nim:39 methodName=ens_getName exception="\nstatus-go error [methodName:ens_getName, code:-32000, message:not a resolver ]\n"
ERR 2024-08-13 10:49:08.895+03:00 error:                                     topics="wallet-account-service" tid=12011950 file=utils.nim:75 errDesription="\nstatus-go error [methodName:ens_getName, code:-32000, message:not a resolver ]\n"
DBG 2024-08-13 10:49:08.895+03:00 NewBE_callPrivateRPC                       topics="rpc" tid=12011950 file=core.nim:27 rpc_method=ens_getName
ERR 2024-08-13 10:49:14.154+03:00 rpc response error                         topics="rpc" tid=12011950 file=core.nim:36 err="\nstatus-go error [methodName:ens_getName, code:-32000, message:not a resolver ]\n"
ERR 2024-08-13 10:49:14.154+03:00 error doing rpc request                    topics="rpc" tid=12011950 file=core.nim:39 methodName=ens_getName exception="\nstatus-go error [methodName:ens_getName, code:-32000, message:not a resolver ]\n"
ERR 2024-08-13 10:49:14.154+03:00 error:                                     topics="wallet-account-service" tid=12011950 file=utils.nim:75 errDesription="\nstatus-go error [methodName:ens_getName, code:-32000, message:not a resolver ]\n"
DBG 2024-08-13 10:49:14.154+03:00 NewBE_callPrivateRPC                       topics="rpc" tid=12011950 file=core.nim:27 rpc_method=accounts_getKeypairs
DBG 2024-08-13 10:49:14.157+03:00 NewBE_callPrivateRPC                       topics="rpc" tid=12011950 file=core.nim:27 rpc_method=ens_getName
ERR 2024-08-13 10:49:20.880+03:00 rpc response error                         topics="rpc" tid=12011950 file=core.nim:36 err="\nstatus-go error [methodName:ens_getName, code:-32000, message:not a resolver ]\n"
ERR 2024-08-13 10:49:20.880+03:00 error doing rpc request                    topics="rpc" tid=12011950 file=core.nim:39 methodName=ens_getName exception="\nstatus-go error [methodName:ens_getName, code:-32000, message:not a resolver ]\n"
ERR 2024-08-13 10:49:20.880+03:00 error:                                     topics="wallet-account-service" tid=12011950 file=utils.nim:75 errDesription="\nstatus-go error [methodName:ens_getName, code:-32000, message:not a resolver ]\n"
DBG 2024-08-13 10:49:20.880+03:00 NewBE_callPrivateRPC                       topics="rpc" tid=12011950 file=core.nim:27 rpc_method=ens_getName
ERR 2024-08-13 10:49:28.557+03:00 rpc response error                         topics="rpc" tid=12011950 file=core.nim:36 err="\nstatus-go error [methodName:ens_getName, code:-32000, message:not a resolver ]\n"
ERR 2024-08-13 10:49:28.557+03:00 error doing rpc request                    topics="rpc" tid=12011950 file=core.nim:39 methodName=ens_getName exception="\nstatus-go error [methodName:ens_getName, code:-32000, message:not a resolver ]\n"
ERR 2024-08-13 10:49:28.557+03:00 error:                                     topics="wallet-account-service" tid=12011950 file=utils.nim:75 errDesription="\nstatus-go error [methodName:ens_getName, code:-32000, message:not a resolver ]\n"
DBG 2024-08-13 10:49:28.557+03:00 NewBE_callPrivateRPC                       topics="rpc" tid=12011950 file=core.nim:27 rpc_method=ens_getName
ERR 2024-08-13 10:49:45.997+03:00 rpc response error                         topics="rpc" tid=12011950 file=core.nim:36 err="\nstatus-go error [methodName:ens_getName, code:-32000, message:not a resolver ]\n"
ERR 2024-08-13 10:49:45.997+03:00 error doing rpc request                    topics="rpc" tid=12011950 file=core.nim:39 methodName=ens_getName exception="\nstatus-go error [methodName:ens_getName, code:-32000, message:not a resolver ]\n"
ERR 2024-08-13 10:49:45.997+03:00 error:                                     topics="wallet-account-service" tid=12011950 file=utils.nim:75 errDesription="\nstatus-go error [methodName:ens_getName, code:-32000, message:not a resolver ]\n"
DBG 2024-08-13 10:49:45.997+03:00 NewBE_callPrivateRPC                       topics="rpc" tid=12011950 file=core.nim:27 rpc_method=ens_getName
anastasiyaig commented 2 months ago

@igor-sirotin can you pls check on that?

anastasiyaig commented 2 months ago

@jrainville i put it to 2.30 since @alexjba confirmed it is the same behavior in rc too, however my tests do not catch it in release yet..

caybro commented 2 months ago

Hotspot results: image

alexjba commented 2 months ago

I can confirm this is the trigger: https://github.com/status-im/status-desktop/blob/master/src/app_service/service/wallet_account/utils.nim#L69

Looks like we're calling it in a loop for each account and each call is blocking the main thread for a long time

alexjba commented 2 months ago

We're calling ens_getName for each wallet account on initialisation. Each call to https://github.com/status-im/status-go/blob/develop/services/ens/api.go#L151 would wait until the 5 sec timeout, blocking the main thread.

The perf issue was visible on all versions for a few hours. Afterwards it went back to normal! Maybe it's not a critical issue in the end, but definitely a vulnerability!

My suggestion is to move ens_getName to the threadpool. This would fix the symptom and remove the vulnerability, but probably not the root cause.

caybro commented 2 months ago

The perf issue was visible on all versions for a few hours. Afterwards it went back to normal! Maybe it's not a critical issue in the end, but definitely a vulnerability!

Still an issue here

alexjba commented 2 months ago

Maybe one idea would be to descope the ens checks for 2.30 and do a proper fix in 2.31. I'm not sure now of the full scope of the fix, but probably it involves analysing the root cause (not sure it's fixable if the network calls are indeed the issue) and moving the ens checks to the threadpool.

@saledjenic @alaibe Do you think it would be an option to descope the ens checks from 2.30 and do a proper fix in 2.31? It would mean to remove at least these 2 calls:

--- a/src/app_service/service/wallet_account/service_account.nim
+++ b/src/app_service/service/wallet_account/service_account.nim
@@ -139,12 +139,12 @@ proc init*(self: Service) =
     let chainId = self.networkService.getAppNetwork().chainId
     let woAccounts = getWatchOnlyAccountsFromDb()
     for acc in woAccounts:
-      acc.ens = getEnsName(acc.address, chainId)
+      acc.ens = ""
       self.storeWatchOnlyAccount(acc)
     let keypairs = getKeypairsFromDb()
     for kp in keypairs:
       for acc in kp.accounts:
-        acc.ens = getEnsName(acc.address, chainId)
+        acc.ens = ""
       self.storeKeypair(kp)

     let addresses = self.getWalletAddresses()
saledjenic commented 2 months ago

I am not sure why it's so slow, could be due to slow network calls cause each getEnsName call does a few contracts calls.

It's important to have it, cause we're checking there if an ens name is still valid or not and don't want to display expired ens names in the app. I don't see other solutions atm except making it async, which won't block the app start, something similar like we did for saved addresses, check checkForEnsNameAndUpdate proc.

jrainville commented 2 months ago

Indeed, making those calls async should be the main fix.

I guess the question here is if it's possible to just disable those calls in the release without breaking too much?

Otherwise, we need to add the async fix in the release, which shouldn't cause issues if done correctly, but we've had issues in the past where we didn't handle errors correctly and it caused crashes, so we need to be careful.

saledjenic commented 2 months ago

@jrainville yes, that's the thing, I am not sure from the top of my head how we handle accounts that have ens name registered in the Send Modal, that's why I would rather go with switching to async call.

I can handle that tomorrow, if that sounds good?

jrainville commented 2 months ago

@saledjenic I have a WIP branch here: https://github.com/status-im/status-desktop/pull/16099 It's on top of release/2.30

It makes the calls async. I tested and it works. However, I don't know if there is a model or something else to update. I tried looking and it doesn't seem like we ever show the ENS name anywhere.

IMO, if we actually do not use or show that ENS name somewhere, we're better off just removing those getName lines from the release. Then, if we really do want to keep them for later, in master we can use that branch I created.