[tests] Better stderr testing #12755

1. 
   jnewbery commented at 1:52 pm on March 22, 2018: member

   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.
2. fanquake added the label Tests on Mar 22, 2018
3. in test/functional/test_framework/test_node.py:189 in c23f8046d7 outdated

   185@@ -174,11 +186,12 @@ def assert_start_raises_init_error(self, extra_args=None, expected_msg=None, par
   186 
   187         Will throw if bitcoind starts without an error.
   188         Will throw if an expected_msg is provided and it does not match bitcoind's stdout."""
   189-        with tempfile.SpooledTemporaryFile(max_size=2**16) as log_stderr:
   190+        with tempfile.NamedTemporaryFile(dir=os.path.join(self.datadir, 'stderr'), delete=False) as log_stderr, \
   

   ---

   ---

   

   annanay25 commented at 7:35 am on March 23, 2018:

   Unable to replicate this bug on my machine, but the tests it fails on some machines is from these declarations. A small analysis -

   The error reported is FileNotFoundError, however, checking the code for creating temp files in python:

    0def _mkstemp_inner(dir, pre, suf, flags):
    1    """Code common to mkstemp, TemporaryFile, and NamedTemporaryFile."""
    2
    3    names = _get_candidate_names()
    4
    5    for seq in xrange(TMP_MAX):
    6        name = names.next()
    7        file = _os.path.join(dir, pre + name + suf)
    8        try:
    9            fd = _os.open(file, flags, 0600)
   10            _set_cloexec(fd)
   11            return (fd, _os.path.abspath(file))
   12        except OSError, e:
   13            if e.errno == _errno.EEXIST:
   14                continue # try again
   15            raise
   16
   17    raise IOError, (_errno.EEXIST, "No usable temporary file name found")
   

   Such an error could not have originated from this function. So the OS created the file but its not visible? Reading the docs gives this -

   0Under Unix, the directory entry for the file is either not created at all or is removed immediately after the file is created. 
   1Other platforms do not support this; your code should not rely on a temporary file created using this function having or not having a visible name in the file system.
   2...
   3Whether the name can be used to open the file a second time, while the named temporary file is still open, varies across platforms (it can be so used on Unix; it cannot on Windows NT or later). 
   

4. jnewbery force-pushed on Apr 30, 2018
5. 
   jnewbery commented at 7:36 pm on April 30, 2018: member

   Fixed the failing feature_config_args.py and rebased on master.
6. jnewbery force-pushed on Apr 30, 2018
7. jnewbery force-pushed on Apr 30, 2018
8. jnewbery force-pushed on May 1, 2018
9. 
   jnewbery commented at 3:46 pm on May 1, 2018: member

   I’ve rebased this on top of #10267, since there’s now a conflict between the two and it doesn’t make sense for that PR to be held up on this.

   This PR effectively takes the stderr checking in feature_includeconf.py added in 488f9477623d2c5eee65f0376b1f5db41d1f61a6 and makes it generic for all functional tests.

10. kallewoof approved
11. 
    kallewoof commented at 5:20 am on May 7, 2018: member

    utACK 6a003e0c09c28dcac41323668e855e23abdeec7e
12. 
    kallewoof commented at 8:56 am on May 9, 2018: member

    @jnewbery #10267 is now merged, so you can trim out the duplicate commits.
13. [Tests] Write stdout/stderr to datadir instead of temp file. c22ce8a7b8
14. [Tests] Use LIBC_FATAL_STDERR_=1 in tests

    By default, libc will print fatal errors to /dev/tty instead of stderr.
    Adding the LIBC_FATAL_STDERR_ to the environment variables allows
    us to catch libc errors in stderr and test for them.

    e5036715c8
15. jnewbery force-pushed on May 9, 2018
16. 
    jnewbery commented at 2:21 pm on May 9, 2018: member

    Thanks @kallewoof - rebased on master to trim out the #10267 commits
17. 
    laanwj commented at 2:37 pm on May 9, 2018: member

    silly linting error from travis:

    010.78s$ if [ "$TRAVIS_EVENT_TYPE" = "pull_request" ]; then contrib/devtools/lint-all.sh; fi
    1./test/functional/feature_includeconf.py:19:1: F401 'test_framework.test_framework.assert_equal' imported but unused
    2^---- failure generated from contrib/devtools/lint-python.sh
    

18. [tests] Allow stderr to be tested against specified string

    Allow bitcoind's stderr to be tested against a specified string on
    shutdown.

    beee49ba1f
19. jnewbery force-pushed on May 9, 2018
20. 
    jnewbery commented at 2:39 pm on May 9, 2018: member

    Thanks linter! Fixed.
21. 
    laanwj commented at 2:55 pm on May 9, 2018: member

    utACK beee49b
22. laanwj merged this on May 9, 2018
23. laanwj closed this on May 9, 2018

    ---

24. jnewbery deleted the branch on May 9, 2018
25. laanwj referenced this in commit 612ba35ab1 on May 9, 2018
26. laanwj referenced this in commit 682698970d on May 14, 2018
27. 
    MarcoFalke commented at 3:16 pm on May 23, 2018: member

    post merge utACK beee49ba1f17937539aa4b543d5b28a9d76c0f4a
28. TheArbitrator referenced this in commit 92bb93cef0 on Jun 7, 2021
29. UdjinM6 referenced this in commit a57a82be1a on Jun 18, 2021
30. UdjinM6 referenced this in commit 207defb4c0 on Jun 18, 2021
31. UdjinM6 referenced this in commit 9e9cd7c035 on Jun 24, 2021
32. UdjinM6 referenced this in commit 5cf96e8fdf on Jun 24, 2021
33. UdjinM6 referenced this in commit 37b4656d23 on Jun 26, 2021
34. UdjinM6 referenced this in commit 62abb11c33 on Jun 26, 2021
35. UdjinM6 referenced this in commit 18e8ca4fa1 on Jun 26, 2021
36. UdjinM6 referenced this in commit c9edd3e8ea on Jun 26, 2021
37. UdjinM6 referenced this in commit cc38451955 on Jun 28, 2021
38. UdjinM6 referenced this in commit ec9f526cec on Jun 28, 2021
39. MarcoFalke locked this on Sep 8, 2021

Contributors
jnewbery annanay25 kallewoof laanwj MarcoFalke

Labels
Tests