tests: Running with --usecli ~5x slower than without #15309

Bought up in IRC here (line 603). More discussion here (line 10).

master @ cb35f1d305d88934df64c2e7fb80700b673360e6 with --usecli:

test/functional/test_runner.py --usecli wallet_disableprivatekeys.py
Temporary test directory at /var/folders/z2/cn877pxd3czdfh47mfkmbwgm0000gn/T/test_runner_₿_🏃_20190201_113059
1/1 - wallet_disableprivatekeys.py passed, Duration: 35 s             

TEST                         | STATUS    | DURATION

wallet_disableprivatekeys.py | ✓ Passed  | 35 s

ALL                          | ✓ Passed  | 35 s (accumulated) 
Runtime: 35 s

without --usecli:

test/functional/test_runner.py wallet_disableprivatekeys.py
Temporary test directory at /var/folders/z2/cn877pxd3czdfh47mfkmbwgm0000gn/T/test_runner_₿_🏃_20190201_113144
1/1 - wallet_disableprivatekeys.py passed, Duration: 7 s

TEST                         | STATUS    | DURATION

wallet_disableprivatekeys.py | ✓ Passed  | 7 s

ALL                          | ✓ Passed  | 7 s (accumulated) 
Runtime: 7 s

It's expected to be somewhat slower due to the process creation overhead, this overhead counts in tests that do a lot of RPC calls. But agree even then 5× is much slower than expected.

This happens because there is a 30 second overhead to exit the http event loop:

 node0 ...:09.423988Z Flushed wallet.dat 0ms 
 node0 ...:37.123147Z Exited http event loop 

Is this related to #14670?

From IRC, it might be related to #14993:

[00:53:49] <aj> i'd seen it in december, as at cb52cee2 fwiw

PR #14670 seems to have slowed down tests considerably, particularly when using --usecli.

I bisected this and commit e98a9eede2fb48ff33a020acc888cbcd83e24bbf is the first one I see that consistently slows down performance (I was running test/functional/wallet_multiwallet.py --usecli, and prior that commit it consistently takes 20 seconds on my machine, while after that commit it takes more than 40 seconds). The following commit 8d3f46ec3938e2ba17654fecacd1d2629f9915fd slows things down considerably more -- that same test takes over 5 minutes after that commit.

I'm not familiar with the changes in #14670 so perhaps the reviewers from that PR can comment further?

ping @promag

@sdaftuar thanks, looks like the client is not closing the connection and the server is allowing the connection to persist, this leads to the connection timeout (by default 60sec 30sec).

Do you observe slow down only with --usecli?. It's strange because bitcoin-cli sends Connection: close header and libevent should close the connection after it - unless there are other events in the event base.

I'll revisit this along with #14993.

Going to close this, as I am no longer seeing any significant difference, i.e only 1-2s on applicable tests, with or without --usecli. Using master at 89a1f7a250ef70ff2d65701564f1e24bb9280d90.