Suppress noisy output from qa tests in Travis #9780

jnewbery · 2017-02-16T20:14:52Z

The QA tests are currently quite noisy even when they run successfully. They output progress information which fills up pages of screen. This might be what you want when running the tests locally, but for build/integration tools it fills the output log with spam.

This PR suppresses noisy output from the qa tests. It builds on and requires both #9657 and #9768. There are three commits specifically for this PR:

commit 1 adds a 'quiet' option to rpc-tests.py, which suppresses the progress output to stdout.
commit 2 updates .travis.yml to use quiet mode
commit 3 prints out the final 1000 lines of test_framework.log if the test fails.

Example of a successful travis run: https://travis-ci.org/jnewbery/bitcoin/jobs/202373787
Example of a failed travis run: https://travis-ci.org/jnewbery/bitcoin/jobs/202374810

ryanofsky · 2017-02-16T22:17:23Z

qa/pull-tester/rpc-tests.py


+    # Set up logging handler
+    sh = logging.StreamHandler()
+    sh.setLevel((logging.INFO if args.quiet else logging.DEBUG))


Maybe only call sh.setLevel if args.quiet is true, because logging.DEBUG can still throw away logs at levels < 10.

ryanofsky · 2017-02-16T22:26:12Z

qa/rpc-tests/test_framework/test_framework.py

+                    try:
+                        print("From" , f, ":")
+                        print("".join(deque(open(f), MAX_LINES_TO_PRINT)))
+                    except:


I think this very broad exception handler could hide information we might like to know about. I would remove it, or narrow it, or at least at stick a "traceback.print_exc()" call in here.

If this handler is supposed to handle the case where f does not exist, you could add an "if os.path.exists(f)" or similar check above.

Printing the tails of the log files here is simply to help if the test case fails on travis. My thinking in adding the try/except handling is that if reading a log file fails for any reason, we should just continue and try to print out the other log files. I don't want there to be any chance that this commit makes the logging available on travis any worse.

I've added a print out of the stack trace exception in the except branch. Does that allay your concerns here?

The print addresses most of my concern. If something goes wrong, I would prefer to know about it.

I also think you should change the bare except to except OSError or except Exception. It isn't right to ignore exceptions like SystemExit or KeyboardInterrupt and keep looping if someone is trying to kill the program. (For reference: https://docs.python.org/3/library/exceptions.html#exception-hierarchy)

Agree on catching only a more concrete exception, specially if you're expecting one in particular, as it seems to be the case in a2a5651 . Also you could print the message of the exception too (before the traceback).

laanwj · 2017-02-17T08:09:17Z

Concept ACK, filtering signal/noise has been a pet peeve of me for as long as we have a travis run, but never got around to it. Thanks for doing this.

JeremyRubin · 2017-02-17T08:27:30Z

I like the approach, but I think that it would be preferable to have some output (e.g., periods) while the tests are running. This is because of a limitation in Travis CI where if no output is seen for 10 minutes the build will fail. This has been a problem historically in the unit tests, but was only addressed (by me) by making them run more quickly such that this is not an issue.

laanwj · 2017-02-17T10:10:17Z

Yes, printing periods or another kind of progress display would be nice. My issue is with tons of unnecessary debug output.

Edit: But don't we already do that during the RPC tests, printing periods?

ryanofsky · 2017-02-17T11:12:41Z

utACK d580707

jnewbery · 2017-02-17T21:51:23Z

@laanwj - this PR suppresses the period printing when running --quiet mode. Do you want me to put that back in?

laanwj · 2017-02-18T09:21:48Z

this PR suppresses the period printing when running --quiet mode. Do you want me to put that back in?

Not necessarily. Just in the mode that Travis uses, apparently it needs to print something (and dots are better than text spam :-) to avoid the timeout problem that @JeremyRubin mentions.

jnewbery · 2017-02-23T21:38:16Z

I've rebased this now that #9657 has been merged. I've also made a change so that period printing still happens in quiet mode. That should prevent any Travis timeout issues.

ryanofsky · 2017-03-08T18:52:33Z

re-utACK 85312c075e7bf3379e0a277e3393e734f940b71c. Confirmed no changes since last rebase other than restoring the print('.').

I would definitely prefer not to be adding the catch-all except handler here, though: #9780 (comment)

jnewbery · 2017-03-15T18:46:01Z

rebased and addressed #9780 (comment).

jtimon · 2017-03-21T14:38:53Z

utACK a2a565180449b80c054c05c12c93097f1e8752c2 except for @ryanofsky 's nit. Needs rebase.

jnewbery · 2017-03-21T15:03:58Z

Updated the exception handler to catch only OSError exceptions as suggested by @ryanofsky and rebased.

jtimon · 2017-03-25T13:11:27Z

Needs rebase again.

rpt-tests.py outputs progress information as it runs tests. This commit adds a --quiet option that suppresses that progress output and only prints a summary of results (and logs from failed tests).

jnewbery · 2017-03-27T15:58:27Z

rebased. I think this is useful PR since it suppresses noisy output in travis when tests pass and also increases the amount of logging available when the test fails. This will be helpful in debugging intermittent functional test failures in Travis. @MarcoFalke , @laanwj - can I convince you to review this PR?

laanwj · 2017-03-27T17:36:23Z

utACK 2c0be25

maflcko · 2017-03-27T22:26:26Z

utACK 2c0be25bd6b744cab60a3672409750545522733a. Please squash the fixup commit.

jnewbery · 2017-03-27T23:34:38Z

squashed

8c7288c Print out the final 1000 lines of test_framework.log if test fails (John Newbery) 6d780b1 Update travis config to run rpc-tests.py in quiet mode (John Newbery) 55992f1 Add --quiet option to suppress rpc-tests.py output (John Newbery) Tree-SHA512: ab080458a07a9346d3b3cbc8ab59b73cea3d4010b1cb0206bb5fade0aaac7562c623475d0a02993f001b22ae9d1ba68e2d0d1a3645cea7e79cc1045b42e2ce3a

jnewbery mentioned this pull request Feb 16, 2017

[qa] Add logging to test_framework.py #9768

Merged

ryanofsky reviewed Feb 16, 2017

View reviewed changes

fanquake added the Tests label Feb 17, 2017

jnewbery force-pushed the travislogging branch from d580707 to 85312c0 Compare February 23, 2017 21:36

jnewbery force-pushed the travislogging branch from 85312c0 to a2a5651 Compare March 15, 2017 18:45

jnewbery force-pushed the travislogging branch from a2a5651 to c308d7c Compare March 21, 2017 15:02

jnewbery force-pushed the travislogging branch from c308d7c to da22976 Compare March 27, 2017 15:52

jnewbery added 2 commits March 27, 2017 11:55

Add --quiet option to suppress rpc-tests.py output

55992f1

rpt-tests.py outputs progress information as it runs tests. This commit adds a --quiet option that suppresses that progress output and only prints a summary of results (and logs from failed tests).

Update travis config to run rpc-tests.py in quiet mode

6d780b1

jnewbery force-pushed the travislogging branch from da22976 to 2c0be25 Compare March 27, 2017 15:56

Print out the final 1000 lines of test_framework.log if test fails

8c7288c

jnewbery force-pushed the travislogging branch from 2c0be25 to 8c7288c Compare March 27, 2017 23:34

maflcko merged commit 8c7288c into bitcoin:master Mar 28, 2017

jnewbery mentioned this pull request Mar 28, 2017

[tests] fixup - make all Travis test runs quiet, non just cron job runs #10105

Merged

codablock mentioned this pull request Jun 18, 2019

Backports 0.15 pr14 dashpay/dash#2974

Merged

bitcoin locked as resolved and limited conversation to collaborators Sep 8, 2021

Suppress noisy output from qa tests in Travis #9780

Suppress noisy output from qa tests in Travis #9780

Uh oh!

Conversation

jnewbery commented Feb 16, 2017

Uh oh!

ryanofsky Feb 16, 2017

Choose a reason for hiding this comment

Uh oh!

ryanofsky Feb 16, 2017

Choose a reason for hiding this comment

Uh oh!

jnewbery Mar 15, 2017

Choose a reason for hiding this comment

Uh oh!

ryanofsky Mar 15, 2017

Choose a reason for hiding this comment

Uh oh!

jtimon Mar 21, 2017

Choose a reason for hiding this comment

Uh oh!

laanwj commented Feb 17, 2017

Uh oh!

JeremyRubin commented Feb 17, 2017

Uh oh!

laanwj commented Feb 17, 2017 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

ryanofsky commented Feb 17, 2017

Uh oh!

jnewbery commented Feb 17, 2017

Uh oh!

laanwj commented Feb 18, 2017 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

jnewbery commented Feb 23, 2017

Uh oh!

ryanofsky commented Mar 8, 2017

Uh oh!

jnewbery commented Mar 15, 2017

Uh oh!

jtimon commented Mar 21, 2017 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

jnewbery commented Mar 21, 2017

Uh oh!

jtimon commented Mar 25, 2017

Uh oh!

jnewbery commented Mar 27, 2017

Uh oh!

laanwj commented Mar 27, 2017

Uh oh!

maflcko commented Mar 27, 2017

Uh oh!

jnewbery commented Mar 27, 2017

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

7 participants

laanwj commented Feb 17, 2017 •

edited

Loading

laanwj commented Feb 18, 2017 •

edited

Loading

jtimon commented Mar 21, 2017 •

edited

Loading