Merge #12755: [tests] Better stderr testing

beee49b [tests] Allow stderr to be tested against specified string (John Newbery)
e503671 [Tests] Use LIBC_FATAL_STDERR_=1 in tests (John Newbery)
c22ce8a [Tests] Write stdout/stderr to datadir instead of temp file. (John Newbery)

Pull request description:

  **Due to a merge conflict, this is now based on #10267. Please review that PR first!**

  Subset of #12379 now that parts of that PR have been merged.

  #12362 was only observed when running the functional tests locally because:

  - by defatul libc logs to `/dev/tty` instead of stderr
  - the functional tests only check for substring inclusion in stderr when we're expecting bitcoind to fail.

  This PR tightens our checking of stderr and will cause tests to fail if there is any unexpected message in stderr:

  - commit *Write stdout/stderr to datadir instead of temp file* writes stderr to a file in the datadir instead of a temporary file. This helps with debugging in the case of failure.
  - commit *Use LIBC_FATAL_STDERR=1 in tests* ensures that libc failures are logged to stderr instead of the terminal.
  commit *Assert that bitcoind stdout is empty on shutdown* asserts that stderr is empty on bitcoind shutdown.

Tree-SHA512: 21111030e667b3b686f2a7625c2b625ebcfb6998e1cccb4f3932e8b5d21fb514b19a73ac971595d049343430e9a63155986a7f5648cad55b8f36f3c58b1c7048
This commit is contained in:
Wladimir J. van der Laan 2018-05-09 16:45:42 +02:00
commit 612ba35ab1
No known key found for this signature in database
GPG Key ID: 1E4AED62986CD25D
4 changed files with 43 additions and 22 deletions

View File

@ -15,9 +15,8 @@ Verify that:
file.
"""
import os
import tempfile
from test_framework.test_framework import BitcoinTestFramework, assert_equal
from test_framework.test_framework import BitcoinTestFramework
class IncludeConfTest(BitcoinTestFramework):
def set_test_params(self):
@ -44,20 +43,18 @@ class IncludeConfTest(BitcoinTestFramework):
self.log.info("-includeconf cannot be used as command-line arg. subversion should still end with 'main; relative)/'")
self.stop_node(0)
with tempfile.SpooledTemporaryFile(max_size=2**16) as log_stderr:
self.start_node(0, extra_args=["-includeconf=relative2.conf"], stderr=log_stderr)
subversion = self.nodes[0].getnetworkinfo()["subversion"]
assert subversion.endswith("main; relative)/")
log_stderr.seek(0)
stderr = log_stderr.read().decode('utf-8').strip()
assert_equal(stderr, 'warning: -includeconf cannot be used from commandline; ignoring -includeconf=relative2.conf')
self.start_node(0, extra_args=["-includeconf=relative2.conf"])
subversion = self.nodes[0].getnetworkinfo()["subversion"]
assert subversion.endswith("main; relative)/")
self.stop_node(0, expected_stderr="warning: -includeconf cannot be used from commandline; ignoring -includeconf=relative2.conf")
self.log.info("-includeconf cannot be used recursively. subversion should end with 'main; relative)/'")
with open(os.path.join(self.options.tmpdir, "node0", "relative.conf"), "a", encoding="utf8") as f:
f.write("includeconf=relative2.conf\n")
self.restart_node(0)
self.start_node(0)
subversion = self.nodes[0].getnetworkinfo()["subversion"]
assert subversion.endswith("main; relative)/")

View File

@ -256,7 +256,7 @@ class BitcoinTestFramework(metaclass=BitcoinTestMetaClass):
assert_equal(len(extra_args), num_nodes)
assert_equal(len(binary), num_nodes)
for i in range(num_nodes):
self.nodes.append(TestNode(i, get_datadir_path(self.options.tmpdir, i), rpchost=rpchost, timewait=timewait, bitcoind=binary[i], bitcoin_cli=self.options.bitcoincli, stderr=None, mocktime=self.mocktime, coverage_dir=self.options.coveragedir, extra_conf=extra_confs[i], extra_args=extra_args[i], use_cli=self.options.usecli))
self.nodes.append(TestNode(i, get_datadir_path(self.options.tmpdir, i), rpchost=rpchost, timewait=timewait, bitcoind=binary[i], bitcoin_cli=self.options.bitcoincli, mocktime=self.mocktime, coverage_dir=self.options.coveragedir, extra_conf=extra_confs[i], extra_args=extra_args[i], use_cli=self.options.usecli))
def start_node(self, i, *args, **kwargs):
"""Start a bitcoind"""
@ -289,9 +289,9 @@ class BitcoinTestFramework(metaclass=BitcoinTestMetaClass):
for node in self.nodes:
coverage.write_all_rpc_commands(self.options.coveragedir, node.rpc)
def stop_node(self, i):
def stop_node(self, i, expected_stderr=''):
"""Stop a bitcoind test node"""
self.nodes[i].stop_node()
self.nodes[i].stop_node(expected_stderr)
self.nodes[i].wait_until_stopped()
def stop_nodes(self):
@ -407,7 +407,7 @@ class BitcoinTestFramework(metaclass=BitcoinTestMetaClass):
args = [self.options.bitcoind, "-datadir=" + datadir]
if i > 0:
args.append("-connect=127.0.0.1:" + str(p2p_port(0)))
self.nodes.append(TestNode(i, get_datadir_path(self.options.cachedir, i), extra_conf=["bind=127.0.0.1"], extra_args=[], rpchost=None, timewait=None, bitcoind=self.options.bitcoind, bitcoin_cli=self.options.bitcoincli, stderr=None, mocktime=self.mocktime, coverage_dir=None))
self.nodes.append(TestNode(i, get_datadir_path(self.options.cachedir, i), extra_conf=["bind=127.0.0.1"], extra_args=[], rpchost=None, timewait=None, bitcoind=self.options.bitcoind, bitcoin_cli=self.options.bitcoincli, mocktime=self.mocktime, coverage_dir=None))
self.nodes[i].args = args
self.start_node(i)

View File

@ -10,6 +10,7 @@ from enum import Enum
import http.client
import json
import logging
import os
import re
import subprocess
import tempfile
@ -55,9 +56,11 @@ class TestNode():
To make things easier for the test writer, any unrecognised messages will
be dispatched to the RPC connection."""
def __init__(self, i, datadir, rpchost, timewait, bitcoind, bitcoin_cli, stderr, mocktime, coverage_dir, extra_conf=None, extra_args=None, use_cli=False):
def __init__(self, i, datadir, rpchost, timewait, bitcoind, bitcoin_cli, mocktime, coverage_dir, extra_conf=None, extra_args=None, use_cli=False):
self.index = i
self.datadir = datadir
self.stdout_dir = os.path.join(self.datadir, "stdout")
self.stderr_dir = os.path.join(self.datadir, "stderr")
self.rpchost = rpchost
if timewait:
self.rpc_timeout = timewait
@ -65,7 +68,6 @@ class TestNode():
# Wait for up to 60 seconds for the RPC server to respond
self.rpc_timeout = 60
self.binary = bitcoind
self.stderr = stderr
self.coverage_dir = coverage_dir
if extra_conf != None:
append_config(datadir, extra_conf)
@ -124,17 +126,29 @@ class TestNode():
assert self.rpc_connected and self.rpc is not None, self._node_msg("Error: no RPC connection")
return getattr(self.rpc, name)
def start(self, extra_args=None, stderr=None, *args, **kwargs):
def start(self, extra_args=None, stdout=None, stderr=None, *args, **kwargs):
"""Start the node."""
if extra_args is None:
extra_args = self.extra_args
# Add a new stdout and stderr file each time bitcoind is started
if stderr is None:
stderr = self.stderr
stderr = tempfile.NamedTemporaryFile(dir=self.stderr_dir, delete=False)
if stdout is None:
stdout = tempfile.NamedTemporaryFile(dir=self.stdout_dir, delete=False)
self.stderr = stderr
self.stdout = stdout
# Delete any existing cookie file -- if such a file exists (eg due to
# unclean shutdown), it will get overwritten anyway by bitcoind, and
# potentially interfere with our attempt to authenticate
delete_cookie_file(self.datadir)
self.process = subprocess.Popen(self.args + extra_args, stderr=stderr, *args, **kwargs)
# add environment variable LIBC_FATAL_STDERR_=1 so that libc errors are written to stderr and not the terminal
subp_env = dict(os.environ, LIBC_FATAL_STDERR_="1")
self.process = subprocess.Popen(self.args + extra_args, env=subp_env, stdout=stdout, stderr=stderr, *args, **kwargs)
self.running = True
self.log.debug("bitcoind started, waiting for RPC to come up")
@ -174,7 +188,7 @@ class TestNode():
wallet_path = "wallet/%s" % wallet_name
return self.rpc / wallet_path
def stop_node(self):
def stop_node(self, expected_stderr=''):
"""Stop the node."""
if not self.running:
return
@ -183,6 +197,13 @@ class TestNode():
self.stop()
except http.client.CannotSendRequest:
self.log.exception("Unable to stop node.")
# Check that stderr is as expected
self.stderr.seek(0)
stderr = self.stderr.read().decode('utf-8').strip()
if stderr != expected_stderr:
raise AssertionError("Unexpected stderr {} != {}".format(stderr, expected_stderr))
del self.p2ps[:]
def is_node_stopped(self):
@ -217,9 +238,10 @@ class TestNode():
Will throw if bitcoind starts without an error.
Will throw if an expected_msg is provided and it does not match bitcoind's stdout."""
with tempfile.SpooledTemporaryFile(max_size=2**16) as log_stderr:
with tempfile.NamedTemporaryFile(dir=self.stderr_dir, delete=False) as log_stderr, \
tempfile.NamedTemporaryFile(dir=self.stdout_dir, delete=False) as log_stdout:
try:
self.start(extra_args, stderr=log_stderr, *args, **kwargs)
self.start(extra_args, stdout=log_stdout, stderr=log_stderr, *args, **kwargs)
self.wait_for_rpc_connection()
self.stop_node()
self.wait_until_stopped()

View File

@ -301,6 +301,8 @@ def initialize_datadir(dirname, n):
f.write("keypool=1\n")
f.write("discover=0\n")
f.write("listenonion=0\n")
os.makedirs(os.path.join(datadir, 'stderr'), exist_ok=True)
os.makedirs(os.path.join(datadir, 'stdout'), exist_ok=True)
return datadir
def get_datadir_path(dirname, n):