RPC Calls are very slow to respond

ma7555 commented

2020-04-19 11:07:20 +02:00

(Migrated from github.com)

The wallet rpc calls are very slow to respond

This takes 12 seconds to get executed

 ./lbrycrd-cli -getinfo
{
  "version": 170302,
  "protocolversion": 70015,
  "walletversion": 169900,
  "balance": 0.00000000,
  "blocks": 750800,
  "timeoffset": 0,
  "connections": 8,
  "proxy": "",
  "difficulty": 455175102026.4689,
  "testnet": false,
  "keypoololdest": 1557683735,
  "keypoolsize": 1000,
  "paytxfee": 0.00000000,
  "relayfee": 0.00001000,
  "warnings": ""
}

The wallet is almost always using 100% of a CPU core.
Running v17.3.2

The wallet rpc calls are very slow to respond This takes 12 seconds to get executed ``` ./lbrycrd-cli -getinfo { "version": 170302, "protocolversion": 70015, "walletversion": 169900, "balance": 0.00000000, "blocks": 750800, "timeoffset": 0, "connections": 8, "proxy": "", "difficulty": 455175102026.4689, "testnet": false, "keypoololdest": 1557683735, "keypoolsize": 1000, "paytxfee": 0.00000000, "relayfee": 0.00001000, "warnings": "" } ``` The wallet is almost always using 100% of a CPU core. Running v17.3.2

BrannonKing commented

2020-04-19 18:33:30 +02:00

(Migrated from github.com)

v17.3.2 uses about 5GB of RAM after running a full sync. Restarting it will reduce the RAM usage (for a while). Do you have that much free RAM? You might be memory swapping.

The "-getinfo" call is slow. I don't know why other than it's built from several other calls. If you call getblockchaininfo or getwalletinfo or getnetworkinfo -- those individual calls should go faster.

v17.3.2 uses about 5GB of RAM after running a full sync. Restarting it will reduce the RAM usage (for a while). Do you have that much free RAM? You might be memory swapping. The "-getinfo" call is slow. I don't know why other than it's built from several other calls. If you call getblockchaininfo or getwalletinfo or getnetworkinfo -- those individual calls should go faster.

ma7555 commented

2020-04-25 04:09:17 +02:00

(Migrated from github.com)

All was extremely slow, this wallet had many txs and I had to delete the wallet and use a brand new one

BrannonKing commented

2020-04-26 05:18:17 +02:00

(Migrated from github.com)

Thanks for clarifying that it's the wallet RPC calls that are slow. Please test it in v0.17.4.5 and report times for the wallet there.

pinpins commented

2020-12-17 18:04:14 +01:00

(Migrated from github.com)

This is to confirm that daemon behaviour is extremely slow. Most of time RPC calls take more than 10 seconds to return results.

Sometimes it recovers, but only for short period of time, then it is slow again.

Loading wallet itself takes 40mins. Reindexing super slow too.

We will not able to support it soon on mining pools if corrective actions are not taken.

This is to confirm that daemon behaviour is extremely slow. Most of time RPC calls take more than 10 seconds to return results. Sometimes it recovers, but only for short period of time, then it is slow again. Loading wallet itself takes 40mins. Reindexing super slow too. We will not able to support it soon on mining pools if corrective actions are not taken.

BrannonKing commented

2020-12-18 15:15:58 +01:00

(Migrated from github.com)

@pinpins , are you managing many accounts in your wallet? Or does it just contain a large number of transactions? It's common for heavily-used lbrycrd wallet instances to require consolidation of transactions from time to time. Essentially, you send all the funds to a single address in a new wallet and discontinue use of the previous wallet. Would that meet your requirements or not? Perhaps some others could offer additional insight into their wallet management: tagging @tzarebczan , @nikooo777, @lyoshenka

bvbfan commented

2020-12-19 12:19:05 +01:00

(Migrated from github.com)

Consider use 17.4.6 i've test some rpc calls -getinfo is instant, other can be slower but less than 10 sec. Also note run daemon with higher db cache ./lbrycrdd -dbcache=8192

Consider use 17.4.6 i've test some rpc calls `-getinfo` is instant, other can be slower but less than 10 sec. Also note run daemon with higher db cache `./lbrycrdd -dbcache=8192`

pinpins commented

2020-12-24 22:04:30 +01:00

(Migrated from github.com)

@pinpins , are you managing many accounts in your wallet? Or does it just contain a large number of transactions? It's common for heavily-used lbrycrd wallet instances to require consolidation of transactions from time to time. Essentially, you send all the funds to a single address in a new wallet and discontinue use of the previous wallet. Would that meet your requirements or not? Perhaps some others could offer additional insight into their wallet management: tagging @tzarebczan , @nikooo777, @lyoshenka

Well, we host mining pool and mostly mining LBRY blocks, regardless of wallet size and history there. I do believe getblocktemplate should be instant regardless.

> @pinpins , are you managing many accounts in your wallet? Or does it just contain a large number of transactions? It's common for heavily-used lbrycrd wallet instances to require consolidation of transactions from time to time. Essentially, you send all the funds to a single address in a new wallet and discontinue use of the previous wallet. Would that meet your requirements or not? Perhaps some others could offer additional insight into their wallet management: tagging @tzarebczan , @nikooo777, @lyoshenka Well, we host mining pool and mostly mining LBRY blocks, regardless of wallet size and history there. I do believe getblocktemplate should be instant regardless.

pinpins commented

2020-12-24 22:06:27 +01:00

(Migrated from github.com)

Consider use 17.4.6 i've test some rpc calls -getinfo is instant, other can be slower but less than 10 sec. Also note run daemon with higher db cache ./lbrycrdd -dbcache=8192

Okay, so downgrading is essentially ok for mining pool?

Also starting up lbry daemon takes 40mins, mostly on loading block index status message

> Consider use 17.4.6 i've test some rpc calls `-getinfo` is instant, other can be slower but less than 10 sec. Also note run daemon with higher db cache `./lbrycrdd -dbcache=8192` Okay, so downgrading is essentially ok for mining pool? Also starting up lbry daemon takes 40mins, mostly on loading block index status message

nikooo777 commented

2020-12-24 23:12:11 +01:00

(Migrated from github.com)

@pinpins did you try running your current version of lbrycrdd with -dbcache=8192?
It does improve performances by a lot.
If that is not sufficient then downgrading should be fine.

@pinpins did you try running your current version of lbrycrdd with -dbcache=8192? It does improve performances by a lot. If that is not sufficient then downgrading should be fine.

pinpins commented

2020-12-25 10:05:50 +01:00

(Migrated from github.com)

@pinpins did you try running your current version of lbrycrdd with -dbcache=8192?
It does improve performances by a lot.
If that is not sufficient then downgrading should be fine.

I have tried for last 12h, definately loading was super fast but getblocktemplate {"rules":["segwit"]} takes 20 seconds still

> @pinpins did you try running your current version of lbrycrdd with -dbcache=8192? > It does improve performances by a lot. > If that is not sufficient then downgrading should be fine. I have tried for last 12h, definately loading was super fast but getblocktemplate {"rules":["segwit"]} takes 20 seconds still

BrannonKing commented

2020-12-26 21:47:04 +01:00

(Migrated from github.com)

@pinpins , which version are you running? Are you using an HDD or SSD or NVMe storage device? I just tested on v19 latest and was seeing about a tenth of a second per call to getblocktemplate (on NVMe).

@pinpins , which version are you running? Are you using an HDD or SSD or NVMe storage device? I just tested on v19 latest and was seeing about a tenth of a second per call to `getblocktemplate` (on NVMe).

pinpins commented

2020-12-27 17:22:12 +01:00

(Migrated from github.com)

Using NVMe storage. Well it works sometimes quickly, but most of the cases it takes more than 5-10 seconds.

Below sample for last 40 minutes


18:02:11: ERROR: recv1, 0, 2, No such file or directory, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 
18:02:11: LBRY Credits error getblocktemplate result1
18:02:46: delay rpc_call 192.168.0.130:25730 getblocktemplate in 13618 ms
18:03:07: ERROR: recv1, 0, 2, No such file or directory, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 
18:03:07: LBRY Credits error getblocktemplate result1
18:03:31: delay rpc_call 192.168.0.130:25730 getblocktemplate in 2411 ms
18:03:52: ERROR: recv1, 0, 2, No such file or directory, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"5"}, 
18:03:52: LBRY Credits error getblocktemplate result1
18:04:34: ERROR: recv1, 0, 2, No such file or directory, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 
18:04:34: LBRY Credits error getblocktemplate result1
18:05:17: ERROR: recv1, 0, 2, No such file or directory, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 
18:05:17: LBRY Credits error getblocktemplate result1
18:05:59: ERROR: recv1, 0, 2, No such file or directory, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 
18:05:59: LBRY Credits error getblocktemplate result1
18:06:42: ERROR: recv1, 0, 2, No such file or directory, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 
18:06:42: LBRY Credits error getblocktemplate result1
18:07:25: delay rpc_call 192.168.0.130:25730 getblocktemplate in 22122 ms
18:07:46: ERROR: recv1, 0, 2, No such file or directory, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 
18:07:46: LBRY Credits error getblocktemplate result1
18:08:30: delay rpc_call 192.168.0.130:25730 getblocktemplate in 22241 ms
18:08:51: ERROR: recv1, 0, 2, No such file or directory, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 
18:08:51: LBRY Credits error getblocktemplate result1
18:09:35: delay rpc_call 192.168.0.130:25730 getblocktemplate in 23326 ms
18:09:56: ERROR: recv1, 0, 2, No such file or directory, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 
18:09:56: LBRY Credits error getblocktemplate result1
18:10:40: delay rpc_call 192.168.0.130:25730 getblocktemplate in 23030 ms
18:10:52: ERROR: recv1, 0, 0, Success, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 
18:10:52: LBRY Credits error getblocktemplate result1
18:11:25: delay rpc_call 192.168.0.130:25730 getblocktemplate in 2039 ms
18:11:46: ERROR: recv1, 0, 2, No such file or directory, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 
18:11:46: LBRY Credits error getblocktemplate result1
18:12:30: ERROR: recv1, 0, 2, No such file or directory, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 
18:12:30: LBRY Credits error getblocktemplate result1
18:13:13: delay rpc_call 192.168.0.130:25730 getblocktemplate in 22352 ms
18:13:34: ERROR: recv1, 0, 2, No such file or directory, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 
18:13:34: LBRY Credits error getblocktemplate result1
18:14:19: delay rpc_call 192.168.0.130:25730 getblocktemplate in 23798 ms
18:14:32: ERROR: recv1, 0, 0, Success, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 
18:14:32: LBRY Credits error getblocktemplate result1
18:15:04: delay rpc_call 192.168.0.130:25730 getblocktemplate in 2103 ms
18:15:25: ERROR: recv1, 0, 2, No such file or directory, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 
18:15:25: LBRY Credits error getblocktemplate result1
18:16:08: ERROR: recv1, 0, 2, No such file or directory, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 
18:16:08: LBRY Credits error getblocktemplate result1
18:16:52: ERROR: recv1, 0, 2, No such file or directory, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 
18:16:52: LBRY Credits error getblocktemplate result1
18:17:33: delay rpc_call 192.168.0.130:25730 getblocktemplate in 19594 ms
18:17:54: ERROR: recv1, 0, 2, No such file or directory, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 
18:17:54: LBRY Credits error getblocktemplate result1
18:18:37: delay rpc_call 192.168.0.130:25730 getblocktemplate in 21507 ms
18:18:56: ERROR: recv1, 0, 0, Success, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 
18:18:56: LBRY Credits error getblocktemplate result1
18:19:41: ERROR: recv1, 0, 2, No such file or directory, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 
18:19:41: LBRY Credits error getblocktemplate result1
18:20:05: delay rpc_call 192.168.0.130:25730 getblocktemplate in 2578 ms
18:20:26: ERROR: recv1, 0, 2, No such file or directory, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 
18:20:26: LBRY Credits error getblocktemplate result1
18:20:50: delay rpc_call 192.168.0.130:25730 getblocktemplate in 2893 ms
18:21:11: ERROR: recv1, 0, 2, No such file or directory, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 
18:21:11: LBRY Credits error getblocktemplate result1

Using NVMe storage. Well it works sometimes quickly, but most of the cases it takes more than 5-10 seconds. Below sample for last 40 minutes ``` 18:02:11: ERROR: recv1, 0, 2, No such file or directory, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 18:02:11: LBRY Credits error getblocktemplate result1 18:02:46: delay rpc_call 192.168.0.130:25730 getblocktemplate in 13618 ms 18:03:07: ERROR: recv1, 0, 2, No such file or directory, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 18:03:07: LBRY Credits error getblocktemplate result1 18:03:31: delay rpc_call 192.168.0.130:25730 getblocktemplate in 2411 ms 18:03:52: ERROR: recv1, 0, 2, No such file or directory, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"5"}, 18:03:52: LBRY Credits error getblocktemplate result1 18:04:34: ERROR: recv1, 0, 2, No such file or directory, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 18:04:34: LBRY Credits error getblocktemplate result1 18:05:17: ERROR: recv1, 0, 2, No such file or directory, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 18:05:17: LBRY Credits error getblocktemplate result1 18:05:59: ERROR: recv1, 0, 2, No such file or directory, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 18:05:59: LBRY Credits error getblocktemplate result1 18:06:42: ERROR: recv1, 0, 2, No such file or directory, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 18:06:42: LBRY Credits error getblocktemplate result1 18:07:25: delay rpc_call 192.168.0.130:25730 getblocktemplate in 22122 ms 18:07:46: ERROR: recv1, 0, 2, No such file or directory, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 18:07:46: LBRY Credits error getblocktemplate result1 18:08:30: delay rpc_call 192.168.0.130:25730 getblocktemplate in 22241 ms 18:08:51: ERROR: recv1, 0, 2, No such file or directory, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 18:08:51: LBRY Credits error getblocktemplate result1 18:09:35: delay rpc_call 192.168.0.130:25730 getblocktemplate in 23326 ms 18:09:56: ERROR: recv1, 0, 2, No such file or directory, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 18:09:56: LBRY Credits error getblocktemplate result1 18:10:40: delay rpc_call 192.168.0.130:25730 getblocktemplate in 23030 ms 18:10:52: ERROR: recv1, 0, 0, Success, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 18:10:52: LBRY Credits error getblocktemplate result1 18:11:25: delay rpc_call 192.168.0.130:25730 getblocktemplate in 2039 ms 18:11:46: ERROR: recv1, 0, 2, No such file or directory, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 18:11:46: LBRY Credits error getblocktemplate result1 18:12:30: ERROR: recv1, 0, 2, No such file or directory, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 18:12:30: LBRY Credits error getblocktemplate result1 18:13:13: delay rpc_call 192.168.0.130:25730 getblocktemplate in 22352 ms 18:13:34: ERROR: recv1, 0, 2, No such file or directory, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 18:13:34: LBRY Credits error getblocktemplate result1 18:14:19: delay rpc_call 192.168.0.130:25730 getblocktemplate in 23798 ms 18:14:32: ERROR: recv1, 0, 0, Success, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 18:14:32: LBRY Credits error getblocktemplate result1 18:15:04: delay rpc_call 192.168.0.130:25730 getblocktemplate in 2103 ms 18:15:25: ERROR: recv1, 0, 2, No such file or directory, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 18:15:25: LBRY Credits error getblocktemplate result1 18:16:08: ERROR: recv1, 0, 2, No such file or directory, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 18:16:08: LBRY Credits error getblocktemplate result1 18:16:52: ERROR: recv1, 0, 2, No such file or directory, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 18:16:52: LBRY Credits error getblocktemplate result1 18:17:33: delay rpc_call 192.168.0.130:25730 getblocktemplate in 19594 ms 18:17:54: ERROR: recv1, 0, 2, No such file or directory, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 18:17:54: LBRY Credits error getblocktemplate result1 18:18:37: delay rpc_call 192.168.0.130:25730 getblocktemplate in 21507 ms 18:18:56: ERROR: recv1, 0, 0, Success, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 18:18:56: LBRY Credits error getblocktemplate result1 18:19:41: ERROR: recv1, 0, 2, No such file or directory, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 18:19:41: LBRY Credits error getblocktemplate result1 18:20:05: delay rpc_call 192.168.0.130:25730 getblocktemplate in 2578 ms 18:20:26: ERROR: recv1, 0, 2, No such file or directory, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 18:20:26: LBRY Credits error getblocktemplate result1 18:20:50: delay rpc_call 192.168.0.130:25730 getblocktemplate in 2893 ms 18:21:11: ERROR: recv1, 0, 2, No such file or directory, {"method":"getblocktemplate","params":[{"rules":["segwit"]}],"id":"4"}, 18:21:11: LBRY Credits error getblocktemplate result1 ```

pinpins commented

2020-12-28 15:06:15 +01:00

(Migrated from github.com)

Tried to run 0.17.4.5, but seems no major improvement.

pinpins commented

2021-05-01 06:34:38 +02:00

(Migrated from github.com)

hello, any further clues on this issue?

marko-lorentz commented

2021-05-27 13:59:55 +02:00

(Migrated from github.com)

Side note @pinpins:
I'm debugging the stratum part of https://github.com/LBRYFoundation/pool to understand the high reject rate. The message I see over and over in the log is

13:40:59: LBRY Credits error getblocktemplate

Looking at the errno of the send()-call indicates Broken pipe. I think I will have a closer look at what's happening behind the scenes in the daemon. Maybe the result can help to fix your problem too.

Side note @pinpins: I'm debugging the stratum part of https://github.com/LBRYFoundation/pool to understand the high reject rate. The message I see over and over in the log is ``` 13:40:59: LBRY Credits error getblocktemplate ``` Looking at the `errno` of the `send()`-call indicates `Broken pipe`. I think I will have a closer look at what's happening behind the scenes in the daemon. Maybe the result can help to fix your problem too.

RPC Calls are very slow to respond #385