2017-08-15 23:34:07 +02:00
#!/usr/bin/env python3
# Copyright (c) 2017 The Bitcoin Core developers
# Distributed under the MIT software license, see the accompanying
# file COPYING or http://www.opensource.org/licenses/mit-license.php.
2019-09-23 21:36:47 +02:00
""" Class for dashd node under test """
2017-08-15 23:34:07 +02:00
2017-08-24 22:01:16 +02:00
import decimal
2017-08-15 23:34:07 +02:00
import errno
import http . client
2017-08-24 22:01:16 +02:00
import json
2017-08-15 23:34:07 +02:00
import logging
import os
2018-01-12 23:24:36 +01:00
import re
2017-08-15 23:34:07 +02:00
import subprocess
import time
2017-11-08 19:10:43 +01:00
from . authproxy import JSONRPCException
2020-04-10 19:24:33 +02:00
from . messages import MY_SUBVERSION
2017-08-15 23:34:07 +02:00
from . util import (
assert_equal ,
2018-04-10 01:11:07 +02:00
delete_cookie_file ,
2017-08-15 23:34:07 +02:00
get_rpc_proxy ,
rpc_url ,
2017-09-06 20:02:08 +02:00
wait_until ,
2017-11-08 19:10:43 +01:00
p2p_port ,
2017-08-15 23:34:07 +02:00
)
2018-01-12 23:24:36 +01:00
# For Python 3.4 compatibility
JSONDecodeError = getattr ( json , " JSONDecodeError " , ValueError )
2017-09-06 20:02:08 +02:00
BITCOIND_PROC_WAIT_TIMEOUT = 60
2017-08-15 23:34:07 +02:00
class TestNode ( ) :
2019-09-23 21:36:47 +02:00
""" A class for representing a dashd node under test.
2017-08-15 23:34:07 +02:00
This class contains :
- state about the node ( whether it ' s running, etc)
- a Python subprocess . Popen object representing the running process
- an RPC connection to the node
2017-11-08 19:10:43 +01:00
- one or more P2P connections to the node
2017-08-15 23:34:07 +02:00
2017-11-08 19:10:43 +01:00
To make things easier for the test writer , any unrecognised messages will
be dispatched to the RPC connection . """
2017-08-15 23:34:07 +02:00
2020-04-16 11:23:49 +02:00
def __init__ ( self , i , dirname , extra_args , extra_args_from_options , rpchost , timewait , binary , stderr , mocktime , coverage_dir , use_cli = False ) :
2017-08-15 23:34:07 +02:00
self . index = i
self . datadir = os . path . join ( dirname , " node " + str ( i ) )
self . rpchost = rpchost
2017-08-23 18:05:43 +02:00
if timewait :
self . rpc_timeout = timewait
else :
# Wait for up to 60 seconds for the RPC server to respond
self . rpc_timeout = 60
2017-08-15 23:34:07 +02:00
if binary is None :
2019-09-23 21:36:47 +02:00
self . binary = os . getenv ( " BITCOIND " , " dashd " )
2017-08-15 23:34:07 +02:00
else :
self . binary = binary
self . stderr = stderr
self . coverage_dir = coverage_dir
2020-04-17 07:52:06 +02:00
self . mocktime = mocktime
2017-08-15 23:34:07 +02:00
# Most callers will just need to add extra args to the standard list below. For those callers that need more flexibity, they can just set the args property directly.
self . extra_args = extra_args
2020-04-16 11:23:49 +02:00
self . extra_args_from_options = extra_args_from_options
2017-08-15 23:34:07 +02:00
self . args = [ self . binary , " -datadir= " + self . datadir , " -server " , " -keypool=1 " , " -discover=0 " , " -rest " , " -logtimemicros " , " -debug " , " -debugexclude=libevent " , " -debugexclude=leveldb " , " -mocktime= " + str ( mocktime ) , " -uacomment=testnode %d " % i ]
2019-09-24 01:09:01 +02:00
self . cli = TestNodeCLI ( os . getenv ( " BITCOINCLI " , " dash-cli " ) , self . datadir )
2018-01-12 23:24:36 +01:00
self . use_cli = use_cli
2017-08-24 22:01:16 +02:00
2019-09-23 21:43:21 +02:00
# Don't try auto backups (they fail a lot when running tests)
self . args . append ( " -createwalletbackups=0 " )
2017-08-15 23:34:07 +02:00
self . running = False
self . process = None
self . rpc_connected = False
self . rpc = None
self . url = None
self . log = logging . getLogger ( ' TestFramework.node %d ' % i )
2018-04-08 17:05:44 +02:00
self . cleanup_on_exit = True # Whether to kill the node when this object goes away
2017-08-15 23:34:07 +02:00
2017-11-08 19:10:43 +01:00
self . p2ps = [ ]
2018-04-08 17:05:44 +02:00
def __del__ ( self ) :
2020-06-11 10:39:04 +02:00
# Ensure that we don't leave any dashd processes lying around after
2018-04-08 17:05:44 +02:00
# the test ends
if self . process and self . cleanup_on_exit :
# Should only happen on test failure
# Avoid using logger, as that may have already been shutdown when
# this destructor is called.
print ( " Cleaning up leftover process " )
self . process . kill ( )
2017-11-08 19:10:43 +01:00
def __getattr__ ( self , name ) :
2018-01-12 23:24:36 +01:00
""" Dispatches any unrecognised messages to the RPC connection or a CLI instance. """
if self . use_cli :
return getattr ( self . cli , name )
else :
assert self . rpc_connected and self . rpc is not None , " Error: no RPC connection "
return getattr ( self . rpc , name )
2017-08-15 23:34:07 +02:00
2018-01-19 17:44:27 +01:00
def start ( self , extra_args = None , stderr = None , * args , * * kwargs ) :
2017-08-15 23:34:07 +02:00
""" Start the node. """
2017-09-01 18:47:13 +02:00
if extra_args is None :
extra_args = self . extra_args
if stderr is None :
stderr = self . stderr
2020-04-16 11:23:49 +02:00
all_args = self . args + self . extra_args_from_options + extra_args
2020-04-17 07:52:06 +02:00
if self . mocktime != 0 :
all_args = all_args + [ " -mocktime= %d " % self . mocktime ]
2018-04-10 01:11:07 +02:00
# Delete any existing cookie file -- if such a file exists (eg due to
2020-06-11 10:39:04 +02:00
# unclean shutdown), it will get overwritten anyway by dashd, and
2018-04-10 01:11:07 +02:00
# potentially interfere with our attempt to authenticate
delete_cookie_file ( self . datadir )
2020-04-17 07:52:06 +02:00
self . process = subprocess . Popen ( all_args , stderr = stderr , * args , * * kwargs )
2017-08-15 23:34:07 +02:00
self . running = True
2019-09-23 21:36:47 +02:00
self . log . debug ( " dashd started, waiting for RPC to come up " )
2017-08-15 23:34:07 +02:00
def wait_for_rpc_connection ( self ) :
2019-09-23 21:36:47 +02:00
""" Sets up an RPC connection to the dashd process. Returns False if unable to connect. """
2017-08-23 18:05:43 +02:00
# Poll at a rate of four times per second
poll_per_s = 4
for _ in range ( poll_per_s * self . rpc_timeout ) :
assert self . process . poll ( ) is None , " dashd exited with status %i during initialization " % self . process . returncode
2017-08-15 23:34:07 +02:00
try :
2017-09-01 18:47:13 +02:00
self . rpc = get_rpc_proxy ( rpc_url ( self . datadir , self . index , self . rpchost ) , self . index , timeout = self . rpc_timeout , coveragedir = self . coverage_dir )
2017-08-15 23:34:07 +02:00
self . rpc . getblockcount ( )
# If the call to getblockcount() succeeds then the RPC connection is up
self . rpc_connected = True
self . url = self . rpc . url
self . log . debug ( " RPC successfully started " )
return
except IOError as e :
if e . errno != errno . ECONNREFUSED : # Port not yet open?
raise # unknown IO error
except JSONRPCException as e : # Initialization phase
2019-10-17 11:59:21 +02:00
# -28 RPC in warmup
# -342 Service unavailable, RPC server started but is shutting down due to error
if e . error [ ' code ' ] != - 28 and e . error [ ' code ' ] != - 342 :
2017-08-15 23:34:07 +02:00
raise # unknown JSON RPC exception
2019-09-23 21:36:47 +02:00
except ValueError as e : # cookie file not found and no rpcuser or rpcassword. dashd still starting
2017-08-15 23:34:07 +02:00
if " No RPC credentials " not in str ( e ) :
raise
2017-08-20 15:04:26 +02:00
time . sleep ( 1.0 / poll_per_s )
2019-09-23 21:36:47 +02:00
raise AssertionError ( " Unable to connect to dashd " )
2017-08-15 23:34:07 +02:00
def get_wallet_rpc ( self , wallet_name ) :
2018-01-12 23:24:36 +01:00
if self . use_cli :
return self . cli ( " -rpcwallet= {} " . format ( wallet_name ) )
else :
assert self . rpc_connected
assert self . rpc
wallet_path = " wallet/ %s " % wallet_name
return self . rpc / wallet_path
2017-08-15 23:34:07 +02:00
Merge #14670: http: Fix HTTP server shutdown
28479f926f21f2a91bec5a06671c60e5b0c55532 qa: Test bitcond shutdown (João Barbosa)
8d3f46ec3938e2ba17654fecacd1d2629f9915fd http: Remove timeout to exit event loop (João Barbosa)
e98a9eede2fb48ff33a020acc888cbcd83e24bbf http: Remove unnecessary event_base_loopexit call (João Barbosa)
6b13580f4e3842c11abd9b8bee7255fb2472b6fe http: Unlisten sockets after all workers quit (João Barbosa)
18e968581697078c36a3c3818f8906cf134ccadd http: Send "Connection: close" header if shutdown is requested (João Barbosa)
02e1e4eff6cda0bfc24b455a7c1583394cbff6eb rpc: Add wait argument to stop (João Barbosa)
Pull request description:
Fixes #11777. Reverts #11006. Replaces #13501.
With this change the HTTP server will exit gracefully, meaning that all requests will finish processing and sending the response, even if this means to wait more than 2 seconds (current time allowed to exit the event loop).
Another small change is that connections are accepted even when the server is stopping, but HTTP requests are rejected. This can be improved later, especially if chunked replies are implemented.
Briefly, before this PR, this is the order or events when a request arrives (RPC `stop`):
1. `bufferevent_disable(..., EV_READ)`
2. `StartShutdown()`
3. `evhttp_del_accept_socket(...)`
4. `ThreadHTTP` terminates (event loop exits) because there are no active or pending events thanks to 1. and 3.
5. client doesn't get the response thanks to 4.
This can be verified by applying
```diff
// Event loop will exit after current HTTP requests have been handled, so
// this reply will get back to the client.
StartShutdown();
+ MilliSleep(2000);
return "Bitcoin server stopping";
}
```
and checking the log output:
```
Received a POST request for / from 127.0.0.1:62443
ThreadRPCServer method=stop user=__cookie__
Interrupting HTTP server
** Exited http event loop
Interrupting HTTP RPC server
Interrupting RPC
tor: Thread interrupt
Shutdown: In progress...
torcontrol thread exit
Stopping HTTP RPC server
addcon thread exit
opencon thread exit
Unregistering HTTP handler for / (exactmatch 1)
Unregistering HTTP handler for /wallet/ (exactmatch 0)
Stopping RPC
RPC stopped.
Stopping HTTP server
Waiting for HTTP worker threads to exit
msghand thread exit
net thread exit
... sleep 2 seconds ...
Waiting for HTTP event thread to exit
Stopped HTTP server
```
For this reason point 3. is moved right after all HTTP workers quit. In that moment HTTP replies are queued in the event loop which keeps spinning util all connections are closed. In order to trigger the server side close with keep alive connections (implicit in HTTP/1.1) the header `Connection: close` is sent if shutdown was requested. This can be tested by
```
bitcoind -regtest
nc localhost 18443
POST / HTTP/1.1
Authorization: Basic ...
Content-Type: application/json
Content-Length: 44
{"jsonrpc": "2.0","method":"stop","id":123}
```
Summing up, this PR:
- removes explicit event loop exit — event loop exits once there are no active or pending events
- changes the moment the listening sockets are removed — explained above
- sends header `Connection: close` on active requests when shutdown was requested which is relevant when it's a persistent connection (default in HTTP 1.1) — libevent is aware of this header and closes the connection gracefully
- removes event loop explicit break after 2 seconds timeout
Tree-SHA512: 4dac1e86abe388697c1e2dedbf31fb36a394cfafe5e64eadbf6ed01d829542785a8c3b91d1ab680d3f03f912d14fc87176428041141441d25dcb6c98a1e069d8
2018-12-06 17:42:52 +01:00
def stop_node ( self , wait = 0 ) :
2017-08-15 23:34:07 +02:00
""" Stop the node. """
if not self . running :
return
self . log . debug ( " Stopping node " )
try :
Merge #14670: http: Fix HTTP server shutdown
28479f926f21f2a91bec5a06671c60e5b0c55532 qa: Test bitcond shutdown (João Barbosa)
8d3f46ec3938e2ba17654fecacd1d2629f9915fd http: Remove timeout to exit event loop (João Barbosa)
e98a9eede2fb48ff33a020acc888cbcd83e24bbf http: Remove unnecessary event_base_loopexit call (João Barbosa)
6b13580f4e3842c11abd9b8bee7255fb2472b6fe http: Unlisten sockets after all workers quit (João Barbosa)
18e968581697078c36a3c3818f8906cf134ccadd http: Send "Connection: close" header if shutdown is requested (João Barbosa)
02e1e4eff6cda0bfc24b455a7c1583394cbff6eb rpc: Add wait argument to stop (João Barbosa)
Pull request description:
Fixes #11777. Reverts #11006. Replaces #13501.
With this change the HTTP server will exit gracefully, meaning that all requests will finish processing and sending the response, even if this means to wait more than 2 seconds (current time allowed to exit the event loop).
Another small change is that connections are accepted even when the server is stopping, but HTTP requests are rejected. This can be improved later, especially if chunked replies are implemented.
Briefly, before this PR, this is the order or events when a request arrives (RPC `stop`):
1. `bufferevent_disable(..., EV_READ)`
2. `StartShutdown()`
3. `evhttp_del_accept_socket(...)`
4. `ThreadHTTP` terminates (event loop exits) because there are no active or pending events thanks to 1. and 3.
5. client doesn't get the response thanks to 4.
This can be verified by applying
```diff
// Event loop will exit after current HTTP requests have been handled, so
// this reply will get back to the client.
StartShutdown();
+ MilliSleep(2000);
return "Bitcoin server stopping";
}
```
and checking the log output:
```
Received a POST request for / from 127.0.0.1:62443
ThreadRPCServer method=stop user=__cookie__
Interrupting HTTP server
** Exited http event loop
Interrupting HTTP RPC server
Interrupting RPC
tor: Thread interrupt
Shutdown: In progress...
torcontrol thread exit
Stopping HTTP RPC server
addcon thread exit
opencon thread exit
Unregistering HTTP handler for / (exactmatch 1)
Unregistering HTTP handler for /wallet/ (exactmatch 0)
Stopping RPC
RPC stopped.
Stopping HTTP server
Waiting for HTTP worker threads to exit
msghand thread exit
net thread exit
... sleep 2 seconds ...
Waiting for HTTP event thread to exit
Stopped HTTP server
```
For this reason point 3. is moved right after all HTTP workers quit. In that moment HTTP replies are queued in the event loop which keeps spinning util all connections are closed. In order to trigger the server side close with keep alive connections (implicit in HTTP/1.1) the header `Connection: close` is sent if shutdown was requested. This can be tested by
```
bitcoind -regtest
nc localhost 18443
POST / HTTP/1.1
Authorization: Basic ...
Content-Type: application/json
Content-Length: 44
{"jsonrpc": "2.0","method":"stop","id":123}
```
Summing up, this PR:
- removes explicit event loop exit — event loop exits once there are no active or pending events
- changes the moment the listening sockets are removed — explained above
- sends header `Connection: close` on active requests when shutdown was requested which is relevant when it's a persistent connection (default in HTTP 1.1) — libevent is aware of this header and closes the connection gracefully
- removes event loop explicit break after 2 seconds timeout
Tree-SHA512: 4dac1e86abe388697c1e2dedbf31fb36a394cfafe5e64eadbf6ed01d829542785a8c3b91d1ab680d3f03f912d14fc87176428041141441d25dcb6c98a1e069d8
2018-12-06 17:42:52 +01:00
self . stop ( wait = wait )
2017-08-15 23:34:07 +02:00
except http . client . CannotSendRequest :
self . log . exception ( " Unable to stop node. " )
2017-11-08 19:10:43 +01:00
del self . p2ps [ : ]
2017-08-15 23:34:07 +02:00
def is_node_stopped ( self ) :
""" Checks whether the node has stopped.
Returns True if the node has stopped . False otherwise .
This method is responsible for freeing resources ( self . process ) . """
if not self . running :
return True
return_code = self . process . poll ( )
2017-09-06 20:02:08 +02:00
if return_code is None :
return False
# process has stopped. Assert that it didn't return an error code.
assert_equal ( return_code , 0 )
self . running = False
self . process = None
self . rpc_connected = False
self . rpc = None
self . log . debug ( " Node stopped " )
return True
def wait_until_stopped ( self , timeout = BITCOIND_PROC_WAIT_TIMEOUT ) :
wait_until ( self . is_node_stopped , timeout = timeout )
2017-08-15 23:34:07 +02:00
def node_encrypt_wallet ( self , passphrase ) :
""" " Encrypts the wallet.
2019-09-23 21:36:47 +02:00
This causes dashd to shutdown , so this method takes
2017-08-15 23:34:07 +02:00
care of cleaning up resources . """
self . encryptwallet ( passphrase )
2017-09-06 20:02:08 +02:00
self . wait_until_stopped ( )
2017-08-24 22:01:16 +02:00
2020-04-05 13:12:45 +02:00
def add_p2p_connection ( self , p2p_conn , * args , * * kwargs ) :
2017-11-08 19:10:43 +01:00
""" Add a p2p connection to the node.
This method adds the p2p connection to the self . p2ps list and also
returns the connection to the caller . """
if ' dstport ' not in kwargs :
kwargs [ ' dstport ' ] = p2p_port ( self . index )
if ' dstaddr ' not in kwargs :
kwargs [ ' dstaddr ' ] = ' 127.0.0.1 '
2020-04-05 13:12:45 +02:00
p2p_conn . peer_connect ( * args , * * kwargs )
2017-11-08 19:10:43 +01:00
self . p2ps . append ( p2p_conn )
return p2p_conn
@property
def p2p ( self ) :
""" Return the first p2p connection
Convenience property - most tests only use a single p2p connection to each
node , so this saves having to write node . p2ps [ 0 ] many times . """
assert self . p2ps , " No p2p connection "
return self . p2ps [ 0 ]
2017-11-14 08:56:04 +01:00
def disconnect_p2ps ( self ) :
""" Close all p2p connections to the node. """
for p in self . p2ps :
2020-04-05 13:12:45 +02:00
p . peer_disconnect ( )
del self . p2ps [ : ]
2017-11-14 08:56:04 +01:00
2020-04-10 19:24:33 +02:00
# wait for p2p connections to disappear from getpeerinfo()
def check_peers ( ) :
for p in self . getpeerinfo ( ) :
if p [ ' subver ' ] == MY_SUBVERSION . decode ( ) :
return False
return True
wait_until ( check_peers , timeout = 5 )
2018-01-12 23:24:36 +01:00
class TestNodeCLIAttr :
def __init__ ( self , cli , command ) :
self . cli = cli
self . command = command
def __call__ ( self , * args , * * kwargs ) :
return self . cli . send_cli ( self . command , * args , * * kwargs )
def get_request ( self , * args , * * kwargs ) :
return lambda : self ( * args , * * kwargs )
2017-11-08 19:10:43 +01:00
2017-08-24 22:01:16 +02:00
class TestNodeCLI ( ) :
2020-06-11 10:39:04 +02:00
""" Interface to dash-cli for an individual node """
2017-08-24 22:01:16 +02:00
def __init__ ( self , binary , datadir ) :
2018-01-24 14:49:33 +01:00
self . options = [ ]
2017-08-24 22:01:16 +02:00
self . binary = binary
self . datadir = datadir
2017-09-06 18:07:21 +02:00
self . input = None
2020-06-11 10:39:04 +02:00
self . log = logging . getLogger ( ' TestFramework.dashcli ' )
2017-09-06 18:07:21 +02:00
2018-01-24 14:49:33 +01:00
def __call__ ( self , * options , input = None ) :
2020-06-11 10:39:04 +02:00
# TestNodeCLI is callable with dash-cli command-line options
2018-01-12 23:24:36 +01:00
cli = TestNodeCLI ( self . binary , self . datadir )
2018-01-24 14:49:33 +01:00
cli . options = [ str ( o ) for o in options ]
2018-01-12 23:24:36 +01:00
cli . input = input
return cli
2017-08-24 22:01:16 +02:00
def __getattr__ ( self , command ) :
2018-01-12 23:24:36 +01:00
return TestNodeCLIAttr ( self , command )
def batch ( self , requests ) :
results = [ ]
for request in requests :
try :
results . append ( dict ( result = request ( ) ) )
except JSONRPCException as e :
results . append ( dict ( error = e ) )
return results
2017-08-24 22:01:16 +02:00
2018-01-24 14:49:33 +01:00
def send_cli ( self , command = None , * args , * * kwargs ) :
2020-06-11 10:39:04 +02:00
""" Run dash-cli command. Deserializes returned string as python object. """
2017-08-24 22:01:16 +02:00
pos_args = [ str ( arg ) for arg in args ]
named_args = [ str ( key ) + " = " + str ( value ) for ( key , value ) in kwargs . items ( ) ]
2020-06-11 10:39:04 +02:00
assert not ( pos_args and named_args ) , " Cannot use positional arguments and named arguments in the same dash-cli call "
2018-01-24 14:49:33 +01:00
p_args = [ self . binary , " -datadir= " + self . datadir ] + self . options
2017-08-24 22:01:16 +02:00
if named_args :
p_args + = [ " -named " ]
2018-01-24 14:49:33 +01:00
if command is not None :
p_args + = [ command ]
p_args + = pos_args + named_args
2020-06-11 10:39:04 +02:00
self . log . debug ( " Running dash-cli command: %s " % command )
2017-09-06 17:36:13 +02:00
process = subprocess . Popen ( p_args , stdin = subprocess . PIPE , stdout = subprocess . PIPE , stderr = subprocess . PIPE , universal_newlines = True )
cli_stdout , cli_stderr = process . communicate ( input = self . input )
returncode = process . poll ( )
if returncode :
2018-01-12 23:24:36 +01:00
match = re . match ( r ' error code: ([-0-9]+) \ nerror message: \ n(.*) ' , cli_stderr )
if match :
code , message = match . groups ( )
raise JSONRPCException ( dict ( code = int ( code ) , message = message ) )
2017-09-06 17:36:13 +02:00
# Ignore cli_stdout, raise with cli_stderr
raise subprocess . CalledProcessError ( returncode , self . binary , output = cli_stderr )
2018-01-12 23:24:36 +01:00
try :
return json . loads ( cli_stdout , parse_float = decimal . Decimal )
except JSONDecodeError :
return cli_stdout . rstrip ( " \n " )