rpc: Worker threads still run after timeout error for two gettxoutsetinfo RPC calls #16979

UPDATE: see #16979 (comment)

Having a default number (DEFAULT_HTTP_THREADS=4;) of HTTP worker threads.

A single gettxoutsetinfo RPC call returns:

hebasto@odroid:~$ time bitcoin-cli gettxoutsetinfo
{
  "height": 596966,
  "bestblock": "0000000000000000000016b72d77ce09ff1ffd98824e671e92c4e6b536e05b2c",
  "transactions": 36147771,
  "txouts": 62227414,
  "bogosize": 4681101424,
  "hash_serialized_2": "5523a667c0b00094c104b37f85d469b8db9c7615d861e17a22bbdef36717f3e1",
  "disk_size": 3761251169,
  "total_amount": 17961904.82206827
}

real	6m36.365s
user	0m0.006s
sys	0m0.012s

... and a worker thread gets the "sleeping" status (from the top output).

When running two gettxoutsetinfo RPC calls from two terminals (nearly) simultaneously, each of them returns with a timeout error:

hebasto@odroid:~$ time bitcoin-cli gettxoutsetinfo
error: Could not connect to the server 127.0.0.1:8332 (error code 0 - "timeout reached")

Make sure the bitcoind server is running and that you are connecting to the correct RPC port.

real	15m0.120s
user	0m0.008s
sys	0m0.012s

... and two worker threads do not sleep and still consume CPU cycles ~until bitcoind is stopped~ too long.

System information

<!-- What version of Bitcoin Core are you using, where did you get it (website, self-compiled, etc)? -->

hebasto@odroid:~$ bitcoind -version | head -n 1
Bitcoin Core Daemon version v0.18.0
hebasto@odroid:~$ lsb_release -ds
Ubuntu 18.04.3 LTS

<!-- What type of machine are you observing the error on (OS/CPU and disk type)? -->

Hardware: ODROID-HC1

Have you tried with other RPC? Looks like a bug in the HTTP server (?).

bitcoin-cli gettxoutsetinfo
error: Could not connect to the server 127.0.0.1:8332 (error code 0 - "timeout reached")

How long until the 2nd line is printed?

How long until the 2nd line is printed?

15 minutes.

It might take longer when two threads fight over disk access on a slow disk.

15 minutes

That is the rpc timeout (900s), have you tried increasing it?

  -rpcclienttimeout=<n>
       Timeout in seconds during HTTP requests, or 0 for no timeout. (default:
       900)

That is the rpc timeout (900s), have you tried increasing it?

With increased value of -rpcclienttimeout it takes about 74 min to finish two concurrent gettxoutsetinfo RPC calls instead of about 6 min for a single one.

Did they report the correct result?

Did they report the correct result?

Yes.

I presume the issue is just disk access. If you feel like digging, you can try running through /usr/bin/time -v ... or similar.

I presume the issue is just disk access. If you feel like digging, you can try running through /usr/bin/time -v ... or similar.

$ date; /usr/bin/time -v bitcoin-cli -rpcclienttimeout=86400 gettxoutsetinfo
Sat Oct 12 15:40:47 UTC 2019
{
  "height": 599069,
  "bestblock": "00000000000000000003c798f8dfe68ff0d813b5ee3126376385cf289643f62b",
  "transactions": 36735954,
  "txouts": 63065683,
  "bogosize": 4743358939,
  "hash_serialized_2": "63a6e567364f0143fb795d0ab9d0caa150dbb023b3d42e42792918e169aaa647",
  "disk_size": 3774113243,
  "total_amount": 17988192.32195437
}
	Command being timed: "bitcoin-cli -rpcclienttimeout=86400 gettxoutsetinfo"
	User time (seconds): 0.00
	System time (seconds): 0.01
	Percent of CPU this job got: 0%
	Elapsed (wall clock) time (h:mm:ss or m:ss): 1:09:44
	Average shared text size (kbytes): 0
	Average unshared data size (kbytes): 0
	Average stack size (kbytes): 0
	Average total size (kbytes): 0
	Maximum resident set size (kbytes): 2316
	Average resident set size (kbytes): 0
	Major (requiring I/O) page faults: 18
	Minor (reclaiming a frame) page faults: 265
	Voluntary context switches: 39
	Involuntary context switches: 1
	Swaps: 0
	File system inputs: 3128
	File system outputs: 0
	Socket messages sent: 0
	Socket messages received: 0
	Signals delivered: 0
	Page size (bytes): 4096
	Exit status: 0

ARM big.LITTLE architecture could be the root of issue. How can I find out which core, big or LITTLE, runs a particular thread?

I think the cli simply disconnects, but the server doesn't know that, so the thread keeps running?

I think the cli simply disconnects, but the server doesn't know that, so the thread keeps running?

Yes, only thing "interrupting" requests ATM is shutdown.

My ODROID-HC1 is out of order now (I hope this is a temporary problem); and I couldn't make more tests.

So closing for now.

Cheap hardware (SD card) and trash software (stock OS) were the root of this issue.

The same ODROID-HC1 with a new good & reliable SD card, powered by Armbian Focal OS -- all issues are gone.