[qa] Add logging to test

jnewbery commented at 5:48 pm on February 15, 2017: member

This is a WIP PR. Comments and feedback on the overall approach welcomed!

(For an overview of python’s logging module and terms, see https://docs.python.org/3/library/logging.html and https://docs.python.org/3/howto/logging.html)

This PR adds logging to the test-framwork.py module. The “TestFramework” logger is added as a member of the BitcoinTestFramework class, and two handlers are attached to the logger:

a StreamHandler() which outputs ERROR and higher level records to stderr.
a FileHandler() which outputs all log records to a new test_framework.log file in the temporary test directory.

Test scripts and helper modules can log to the same Logger so there’s a single log output:

Individual test scripts can log to “TestFramework” by calling self.log.[debug|info|warning|error|critical|exception]().
Helper modules should log to child Loggers such as “TestFramework.mininode” or “TestFramework.authproxy”, which will result in log records being propagated up to the “TestFramework” Logger.

I’ve added examples of how individual scripts and helper modules should log events in p2p-segwit.py and mininode.py.

The eventual goal is to remove all print() calls and replace them with logging.

A few notes on the implementation:

a new --loglevel parameter can be used to log lower level records to the console, for example --loglevel=DEBUG will emit all log records to the console.
the date format of test_framework.log is the same as bitcoind’s debug.log. It should be trivial to interleave test_framework.log with the various nodeX/debug.log files for a global view of what’s happening during the test.
this should have no interaction with the existing --tracerpc parameter

fanquake added the label Tests on Feb 15, 2017

laanwj commented at 8:42 am on February 16, 2017: member

If you’re working on custom logging stuff anyway: what would be really nice is something that would queue up debug messages, then print them only if the test fails. This lowers the amount of spam in the Travis log in the good case, and gives full troubleshooting information in the bad case (when you need it).

jnewbery commented at 8:15 pm on February 16, 2017: member

@laanwj done: https://github.com/bitcoin/bitcoin/pull/9780

in qa/rpc-tests/test_framework/test_framework.py: in a8e2ab2ed7 outdated

178             shutil.rmtree(self.options.tmpdir)
179             if not os.listdir(self.options.root):
180                 os.rmdir(self.options.root)
181         else:
182-            print("Not cleaning up dir %s" % self.options.tmpdir)
183+            self.log.info("Not cleaning up dir %s" % self.options.tmpdir)

ryanofsky commented at 9:42 pm on February 16, 2017:

Would upgrade this to a warning, since this is leaving files behind. Also this is a really useful print to see on the console when a test fails.

jnewbery commented at 6:44 pm on March 6, 2017:

good point. Fixed.

in qa/rpc-tests/test_framework/test_framework.py: in a8e2ab2ed7 outdated

112@@ -113,6 +113,8 @@ def main(self):
113                           help="Directory for caching pregenerated datadirs")
114         parser.add_option("--tmpdir", dest="tmpdir", default=tempfile.mkdtemp(prefix="test"),
115                           help="Root directory for datadirs")
116+        parser.add_option("--loglevel", dest="loglevel", default="ERROR",

ryanofsky commented at 9:48 pm on February 16, 2017:

You should say something about test_framework.log and console logging in the tests’ –help output.

What you wrote in the commit message is good, but obviously no one is going to see if it is just in this commit message.

jnewbery commented at 6:43 pm on March 6, 2017:

Thanks. Updated.

in qa/rpc-tests/test_framework/test_framework.py: in a8e2ab2ed7 outdated

145             self.run_test()
146             success = True
147         except JSONRPCException as e:
148-            print("JSONRPC error: "+e.error['message'])
149-            traceback.print_tb(sys.exc_info()[2])
150+            self.log.exception("JSONRPC error: "+e.error['message'])

ryanofsky commented at 9:50 pm on February 16, 2017:

Should stop trying to print e here and below because log.exception already formats and prints the exception and stack trace: https://docs.python.org/3/library/logging.html#logging.Logger.exception. It’s not helpful to see same information printed multiple times and in inconsistent ways.

jnewbery commented at 6:43 pm on March 6, 2017:

Yep, good catch.

in qa/rpc-tests/test_framework/test_framework.py: in a8e2ab2ed7 outdated

112@@ -113,6 +113,8 @@ def main(self):
113                           help="Directory for caching pregenerated datadirs")
114         parser.add_option("--tmpdir", dest="tmpdir", default=tempfile.mkdtemp(prefix="test"),
115                           help="Root directory for datadirs")
116+        parser.add_option("--loglevel", dest="loglevel", default="ERROR",
117+                          help="log events at this level and higher to the console")

ryanofsky commented at 9:53 pm on February 16, 2017:

Can you list what the log levels are? At least should probably mention that passing –loglevel=0 will show complete log output.

jnewbery commented at 6:43 pm on March 6, 2017:

Updated

in qa/rpc-tests/test_framework/test_framework.py: in a8e2ab2ed7 outdated

188             sys.exit(1)
189 
190+    def start_logging(self):
191+        # Add logger and logging handlers
192+        self.log = logging.getLogger('TestFramework')
193+        self.log.setLevel(logging.DEBUG)

ryanofsky commented at 10:07 pm on February 16, 2017:

I think you’re better off dropping this call. The default debug level seems to be 0, and the value of DEBUG is 10 so this potentially throws away logs.

Also would drop the 3 other setLevel(logging.DEBUG) calls below.

jnewbery commented at 6:46 pm on March 6, 2017:

I think DEBUG is good here. We shouldn’t encourage people to log messages at custom levels (ie not one of debug, info, warning, error and critical), and we especially shouldn’t encourage people to log at a level lower than DEBUG.

ryanofsky commented at 9:17 pm on March 6, 2017:

I think DEBUG is good here. We shouldn’t encourage people to log messages at custom levels (ie not one of debug, info, warning, error and critical), and we especially shouldn’t encourage people to log at a level lower than DEBUG.

Actually setting DEBUG seems to be needed here in order to be able to see debug messages at all, otherwise python seems to fall back to root logger level which is WARNING.

Still I would consider dropping the “fh.setLevel()” call below. Having that call seems less like “not encouraging” people to log messages at custom levels, and more like going out of our way to punish and confuse them.

jnewbery commented at 3:35 pm on March 7, 2017:

I still don’t agree. logging at non-standard levels is harder (you need to call self.log.log(lvl, message) rather than self.log.debug(message) or similar). Why would anyone want do that, and why would we want to allow people to add confusing logging levels to the test cases?

in qa/rpc-tests/test_framework/test_framework.py: in a8e2ab2ed7 outdated

194+        # Create file handler to log all messages
195+        fh = logging.FileHandler(self.options.tmpdir + '/test_framework.log')
196+        fh.setLevel(logging.DEBUG)
197+        # Create console handler to log messages to stderr. By default this logs only error messages, but can be configured with --loglevel.
198+        ch = logging.StreamHandler()
199+        console_log_level = getattr(logging, self.options.loglevel.upper(), None)

ryanofsky commented at 10:08 pm on February 16, 2017:

Calling getattr doesn’t seem to be necessary, the documentation says setLevel already accepts a string: https://docs.python.org/3/library/logging.html#logging.Handler.setLevel. Maybe upper() is still useful though.

jnewbery commented at 6:50 pm on March 6, 2017:

Agree. I was following the Python ’logging how to’ guide here: https://docs.python.org/3/howto/logging.html#logging-to-a-file which uses getattr(). I guess that was written before 3.2, which is when setlevel() was updated to take a string argument.

I’ve tested the logging module and:

we do need to use upper() to set the log levels to uppercase
calling with an invalid string causes logging to raise a helpful exception (I was worried that it might fail silently).

So calling setlevel directly with self.options.loglevel.upper() is better.

in qa/rpc-tests/test_framework/test_framework.py: in a8e2ab2ed7 outdated

212+            rpc_logger = logging.getLogger("BitcoinRPC")
213+            rpc_logger.setLevel(logging.DEBUG)
214+            rpc_handler = logging.StreamHandler()
215+            rpc_handler.setLevel(logging.DEBUG)
216+            rpc_logger.addHandler(rpc_handler)
217+            rpc_logger.debug("debug")

ryanofsky commented at 10:10 pm on February 16, 2017:

Junk lines?

jnewbery commented at 6:50 pm on March 6, 2017:

yes. Junk lines from when I was testing this. Thanks. Removed.

ryanofsky commented at 11:12 am on February 17, 2017: member

utACK 3e7ed8c21c3f52a312a538746aebbbb06f67e3a1

jnewbery commented at 9:45 pm on February 17, 2017: member

@ryanofsky thanks for the great feedback. I’m going to hold back on making any changes until I get some more concept ACKs/NACKs. I want to make sure people are happy going in this direction before I spend any time addressing review comments.

jnewbery commented at 1:27 am on February 22, 2017: member

@MarcoFalke @laanwj @jonasschnelli @sdaftuar you’re the most active contributors to the qa directory. Can you have a quick look and give me a concept ACK/NACK so I know whether to continue in this direction.

No rush. Obviously you’re all busy with the 0.14 release.

sdaftuar commented at 6:16 pm on February 27, 2017: member

Concept ACK.

I haven’t reviewed this PR in detail yet, but what I’d find useful is if the default behavior when running a single test locally was to print all log messages to the console, and only suppress log messages when running the tests through the rpc-tests.py script.

jnewbery commented at 4:29 pm on February 28, 2017: member

@sdaftuar the eventual aim will be to add a lot more low-level logging (eg logging when every p2p message is sent or received on the mininode connection). Those low-level logs will always be saved to test_framework.log, but by default are not printed to the console. If the user want low-level logs printed to console, they can specify –loglevel when running the script.

jnewbery force-pushed on Mar 6, 2017

jnewbery commented at 7:13 pm on March 6, 2017: member

I’ve addressed @ryanofsky’s review comments and repushed. A few updates since I opened this PR:

microsecond debug logging is now set by default on all test nodes. I’ve removed all places in the test code where debugging is set manually, since there’s no reason not to use debug logging in these test cases.
I’ve added logging to the test_framework submodules
I’ve replaced print functions in the individual test-cases with logging calls

I’ve been running with this patch set locally for some time, together with a tool to interleave test_framwork logs with individual node logs. It makes troubleshooting testcases a lot easier since I have a global view of everything that’s happening in the test case (ie I can see messages being sent in by the test framework and then received by the node).

I believe this is ready for merge, but any further review comments are welcomed.

in qa/rpc-tests/test_framework/test_framework.py: in fb74effd87 outdated

137@@ -139,38 +138,35 @@ def main(self):
138         success = False
139         try:
140             os.makedirs(self.options.tmpdir, exist_ok=False)

ryanofsky commented at 7:23 pm on March 6, 2017:

Should move the os.makedirs, and self.start_logging calls above the try: block, so error information won’t be lost if these calls fail for some reason.

jnewbery commented at 3:32 pm on March 7, 2017:

Good idea. I needed to put start_logging() below the os.makedirs() call, but you’re right that this should be outside the large try/except block. I’ve now moved them both up.

in qa/rpc-tests/test_framework/test_framework.py: in fb74effd87 outdated

177@@ -182,12 +178,36 @@ def main(self):
178                     from collections import deque
179                     print("".join(deque(open(f), MAX_LINES_TO_PRINT)))
180         if success:
181-            print("Tests successful")
182+            self.log.info("Tests successful")
183             sys.exit(0)
184         else:
185-            print("Failed")
186+            self.log.warning("Failed")

ryanofsky commented at 7:24 pm on March 6, 2017:

This should be changed to error instead of warning, to avoid potential for silent errors slipping through (even though in most cases, an error probably did print previously).

Also, I think it would be good for this message to mention the temp directory path (or alternately the path to test_framework.log), since it is no longer printed by default and is a piece of information you probably need to understand what happened.

jnewbery commented at 3:32 pm on March 7, 2017:

Agree. Done both.

in qa/rpc-tests/test_framework/test_framework.py: in fb74effd87 outdated

111@@ -112,6 +112,8 @@ def main(self):
112                           help="Directory for caching pregenerated datadirs")
113         parser.add_option("--tmpdir", dest="tmpdir", default=tempfile.mkdtemp(prefix="test"),
114                           help="Root directory for datadirs")
115+        parser.add_option("--loglevel", dest="loglevel", default="ERROR",

ryanofsky commented at 7:46 pm on March 6, 2017:

Maybe I missed some discussion, but why is the default level error instead of debug or warning? I can understand disabling debug output by default when running pull-tester. But I run individual tests from the command line every day, and I can’t remember a time when I’ve ever wanted to do this without seeing output.

If we have make error the default, can we at least support abbreviating “–loglevel=” as “-l”, and allow passing integer log levels? This way it’d be possible to see debug output with -l0 instead of --loglevel=debug

Also would note that even the default level for the root python logger is warning, not error.

jnewbery commented at 3:31 pm on March 7, 2017:

You’re right. This should be INFO by default. DEBUG emits way too much to the console to be the default.

pull-tester diverts stdout from the subtests, so there’s no output to console at all.

–loglevel now accepts ints as well as the named strings and can be specified with the short option -l

in qa/rpc-tests/test_framework/test_framework.py: in fb74effd87 outdated

193+        # Create file handler to log all messages
194+        fh = logging.FileHandler(self.options.tmpdir + '/test_framework.log')
195+        fh.setLevel(logging.DEBUG)
196+        # Create console handler to log messages to stderr. By default this logs only error messages, but can be configured with --loglevel.
197+        ch = logging.StreamHandler()
198+        ch.setLevel(self.options.loglevel.upper())

ryanofsky commented at 8:21 pm on March 6, 2017:

Would be nice to support integer debug levels for less verbose command line usage. Maybe setLevel(int(self.options.loglevel) if self.options.loglevel.isdigit() else self.options.loglevel.upper()).

jnewbery commented at 3:35 pm on March 7, 2017:

Yep. Good idea. Done (although I’ve split this over two lines for readability).

in qa/rpc-tests/bip68-sequence.py: in 3b336aba4e outdated

53-        print("Activating BIP68 (and 112/113)")
54+        self.log.info("Activating BIP68 (and 112/113)")
55         self.activateCSV()
56 
57-        print("Verifying nVersion=2 transactions are standard.")
58-        print("Note that with current versions of bitcoin software, nVersion=2 transactions are always standard (independent of BIP68 activation status).")

ryanofsky commented at 8:33 pm on March 6, 2017:

Why drop mention of previous versions? Also, it seems like without this qualification, maybe the word “always” should be dropped too.

jnewbery commented at 3:40 pm on March 7, 2017:

Because I previously thought that it was a bug that Core v0.13 (and a few earlier versions) always relayed v2 transactions - hence the ‘with current versions’ comment. See #9739 for the discussion. Whether or not it’s a bug is moot now, and I think the ‘with current verions’ comment doesn’t clarify.

‘always’ here means ‘both before and after BIP 68 activation’.

in qa/rpc-tests/bip68-sequence.py: in 3b336aba4e outdated

59+        self.log.info("Verifying nVersion=2 transactions are standard.")
60+        self.log.info("Note that nVersion=2 transactions are always standard (independent of BIP68 activation status).")
61         self.test_version2_relay()
62 
63-        print("Passed\n")
64+        self.log.info("Passed\n")

ryanofsky commented at 8:35 pm on March 6, 2017:

Probably best to remove trailing and prefix \n here and in other logging lines. (There seem to be 4-5 other occurrances in this PR.)

jnewbery commented at 3:40 pm on March 7, 2017:

Thanks. Done.

in qa/rpc-tests/test_framework/comptool.py: in 3b336aba4e outdated

20@@ -21,6 +21,10 @@
21 from .blockstore import BlockStore, TxStore
22 from .util import p2p_port
23 
24+import logging
25+
26+logger=logging("TestFramework.comptool")

ryanofsky commented at 8:40 pm on March 6, 2017:

Should be logging.getLogger. This is causing travis errors.

jnewbery commented at 3:40 pm on March 7, 2017:

Yep. My mistake. Fixed.

ryanofsky commented at 9:37 pm on March 6, 2017: member

ACK 3b336aba4ef250868d6f3dc2bf741b0bbf621d39 assuming travis tests will be fixed.

jnewbery force-pushed on Mar 7, 2017

jnewbery commented at 3:44 pm on March 7, 2017: member

@ryanofsky’s comments addressed and repushed: c9755da51a742c0d86572f750e16573e87fdd166 / https://github.com/jnewbery/bitcoin/tree/pr9768.3

jnewbery force-pushed on Mar 7, 2017

jnewbery commented at 8:19 pm on March 7, 2017: member

rebased: https://github.com/bitcoin/bitcoin/pull/9768/commits/2c9fc0e5f786dd4daa906f20fc322a615bc5b6e2 / https://github.com/jnewbery/bitcoin/tree/pr9768.4

jnewbery force-pushed on Mar 7, 2017

jnewbery commented at 2:42 pm on March 8, 2017: member

@laanwj @MarcoFalke I think this is a real improvement and helps debugging and fixing test cases when they fail. I’ve addressed #9768 (comment) in #9780 which builds off this PR. Any chance I can convince you to take a look at this?

in qa/rpc-tests/proxy_test.py: in f546d06ac2 outdated

82@@ -83,13 +83,13 @@ def setup_nodes(self):
83         # Note: proxies are not used to connect to local nodes
84         # this is because the proxy to use is based on CService.GetNetwork(), which return NET_UNROUTABLE for localhost
85         args = [
86-            ['-listen', '-debug=net', '-debug=proxy', '-proxy=%s:%i' % (self.conf1.addr),'-proxyrandomize=1'],

ryanofsky commented at 4:49 pm on March 8, 2017:

Line 72 Warning: testing without local IPv6 support above is now a print again, not sure if this was intentional.

jnewbery commented at 6:17 pm on March 8, 2017:

yes - proxy_test does a lot of work in the __init__() method, which is called before the temp directory is set up. Logging requires the temp directory, so we can’t use self.log until we’re in main() and _start_logging() has been called.

I left this as a print() rather than trying to do anything clever to coerce the test into being log friendly.

ryanofsky commented at 4:56 pm on March 8, 2017: member

utACK f546d06ac21e2953c0dc0b1d8fef459b186781ce

Thanks for supporting -l0.

I think this is a real improvement and helps debugging and fixing test cases when they fail.

Definitely agree. It should be especially useful to easily see interleaved python and bitcoin debug.log output while debugging.

jnewbery renamed this:
~~[qa] [WIP] Add logging to test_framework.py~~
[qa] Add logging to test_framework.py
on Mar 8, 2017

MarcoFalke commented at 10:31 pm on March 8, 2017: member

Concept ACK. Going to give some feedback later tonight.

On Wed, Mar 8, 2017 at 3:42 PM, John Newbery notifications@github.com wrote:

@laanwj @MarcoFalke I think this is a real improvement and helps debugging and fixing test cases when they fail. I’ve addressed #9768 (comment) in #9780 which builds off this PR. Any chance I can convince you to take a look at this?

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub, or mute the thread.

in qa/rpc-tests/invalidateblock.py: in f546d06ac2 outdated

76+        self.log.info("Verify all nodes are at the right height")
77         time.sleep(5)
78-        for i in range(3):
79-            print(i,self.nodes[i].getblockcount())
80         assert(self.nodes[2].getblockcount() == 3)
81         assert(self.nodes[0].getblockcount() == 4)

MarcoFalke commented at 0:35 am on March 9, 2017:

If you remove the prints above, you need to change those to assert_equal to maintain the debug print in case of failure.

jnewbery commented at 2:22 pm on March 9, 2017:

Done.

in qa/rpc-tests/test_framework/mininode.py: in f546d06ac2 outdated

1748 
1749     def send_message(self, message, pushbuf=False):
1750         if self.state != "connected" and not pushbuf:
1751             raise IOError('Not connected, no pushbuf')
1752-        self.show_debug_msg("Send %s" % repr(message))
1753+            logger.debug("Send message to %s:%d: %s" % (self.dstaddr, self.dstport, repr(message)))

MarcoFalke commented at 0:48 am on March 9, 2017:

Please don’t change indentation here.

jnewbery commented at 2:22 pm on March 9, 2017:

Oops. Fixed.

in qa/rpc-tests/test_framework/test_framework.py: in f546d06ac2 outdated

210+        self.log.addHandler(ch)
211+
212+        if self.options.trace_rpc:
213+            rpc_logger = logging.getLogger("BitcoinRPC")
214+            rpc_logger.setLevel(logging.DEBUG)
215+            rpc_handler = logging.StreamHandler()

MarcoFalke commented at 0:54 am on March 9, 2017:

Any reason you switched the rpc handler to stderr by falling back to the default value?

jnewbery commented at 2:27 pm on March 9, 2017:

No reason. Just an oversight. Now fixed.

in qa/rpc-tests/test_framework/test_framework.py: in f546d06ac2 outdated

185+            self.log.info("Tests successful")
186             sys.exit(0)
187         else:
188-            print("Failed")
189+            self.log.error("Test failed. Test logging available at %s/test_framework.log", self.options.tmpdir)
190             sys.exit(1)

MarcoFalke commented at 1:05 am on March 9, 2017:

You might need to shutdown (flush) the logs here.

jnewbery commented at 2:22 pm on March 9, 2017:

Done.

in qa/rpc-tests/p2p-segwit.py: in f546d06ac2 outdated

906@@ -908,7 +907,7 @@ def test_witness_tx_relay_before_segwit_activation(self):
907         # a witness transaction ought not result in a getdata.
908         try:
909             self.test_node.announce_tx_and_wait_for_getdata(tx, timeout=2)
910-            print("Error: duplicate tx getdata!")
911+            self.log.error("Error: duplicate tx getdata!")
912             assert(False)

MarcoFalke commented at 1:06 am on March 9, 2017:

You don’t need the assert(False) when you pass any AssertionError below. Though maybe a fix for an unrelated follow up pr.

jnewbery commented at 2:23 pm on March 9, 2017:

That’s pre-existing behaviour, which is unrelated to this PR. I agree it should be fixed in a different PR.

in qa/rpc-tests/test_framework/test_framework.py: in f546d06ac2 outdated

202+        ll = int(self.options.loglevel) if self.options.loglevel.isdigit() else self.options.loglevel.upper()
203+        ch.setLevel(ll)
204+        # Format logs the same as bitcoind's debug.log with microprecision (so log files can be concatenated and sorted)
205+        formatter = logging.Formatter(fmt = '%(asctime)s.%(msecs)03d000 %(name)s (%(levelname)s): %(message)s', datefmt='%Y-%m-%d %H:%M:%S')
206+        fh.setFormatter(formatter)
207+        ch.setFormatter(formatter)

MarcoFalke commented at 1:16 am on March 9, 2017:

I think the print to stdout can use a formatter that produces smaller lines. (Maybe without the timestamp?) But no strong opinion.

jnewbery commented at 2:23 pm on March 9, 2017:

I specifically set the format of the logs to be the same as what bitcoind produces with microsecond logging.

MarcoFalke commented at 1:18 am on March 9, 2017: member

utACK f546d06

jnewbery force-pushed on Mar 9, 2017

Add logging to test_framework.py

This commit adds python logging to test_framework.py. By default this
will output all log levels (DEBUG-INFO-WARNING-ERROR-CRITICAL) to a
test_framework.log file in the temporary test directory, and higher
level logs (WARNING-ERROR-CRITICAL) to the console. The level of logging
to the console can be controlled by a new log-level parameter.

This should have no interaction with the existing trace-rpc parameter.

0e6d23dd53

Add logging to p2p-segwit.py 553a976929

Use logging in mininode.py

This commit adds a TestFramework.mininode Logger to the mininode module.
This is a child logger of TestFramework, so the handlers set up in
test_framework.py will receive records from this logger and emit them
to the log file and console as appropriate.

6d0e3250bb

Always enable debug log and microsecond logging for test nodes. af1363cb1c

Remove manual debug settings in qa tests.

-debug and -logtimemicros are now set by default. Individual test cases
no longer need to set these parameters manually.

b0dec4a04a

Use logging in test_framework/util.py 2a9c7c74dc

Use logging in test_framework/blockstore.py ff190739be

Use logging in test_framework/comptool.py 38ad281b2a

Use logging in individual tests 64c080051b

jnewbery force-pushed on Mar 9, 2017

jnewbery commented at 2:37 pm on March 9, 2017: member

Thanks for the feedback @MarcoFalke . I believe the latest commit should address all your comments.

MarcoFalke commented at 2:39 pm on March 9, 2017: member

Ok, will take a quick look later and plan to merge this before the meeting.

On Thu, Mar 9, 2017 at 3:37 PM, John Newbery notifications@github.com wrote:

Thanks for the feedback @MarcoFalke https://github.com/MarcoFalke . I believe the latest commit should address all your comments.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/bitcoin/bitcoin/pull/9768#issuecomment-285368237, or mute the thread https://github.com/notifications/unsubscribe-auth/AGGmvz4ztjuB7cndYVx9sVdeT2RIPdMiks5rkA6mgaJpZM4MCCBG .

MarcoFalke merged this on Mar 9, 2017

MarcoFalke closed this on Mar 9, 2017

MarcoFalke referenced this in commit 8910b4717e on Mar 9, 2017

MarcoFalke referenced this in commit 21833f9456 on Mar 10, 2017

Sjors commented at 1:46 pm on November 27, 2017: member

This works if you call test/functional/bumpfee.py --loglevel=INFO, but not if you call test/functional/test_runner.py --loglevel=INFO bumpfee (which just shows dots). Not sure if that’s intended, but it did confuse me.

jnewbery commented at 2:49 pm on November 27, 2017: member

documentation is here: https://github.com/bitcoin/bitcoin/blob/master/test/README.md#test-logging :

when run through the test_runner harness, all logs are written to test_framework.log and no logs are output to the console.

Feel free to open a PR if you think the documentation could be improved.

Sjors commented at 5:10 pm on November 27, 2017: member

@jnewberry it’s probably sufficient if /test_runner.py --help says that next to the --loglevel flag (or if it doesn’t show that option).

jnewbery deleted the branch on Nov 27, 2017

jnewbery commented at 5:33 pm on November 27, 2017: member

The help text for --loglevel comes from test_framework.py. test_runner.py grabs that help text and appends it to its own help text. I suppose that test_runner could remove the --loglevel help before displaying it. The relevant code is here: https://github.com/bitcoin/bitcoin/blob/a89221873a3ee2451c73b41bbe2d99d36f439d31/test/functional/test_runner.py#L258

Sjors commented at 6:34 pm on November 27, 2017: member

Thanks, I’ll take a look.

PastaPastaPasta referenced this in commit 1a98c8bc0d on Jan 2, 2019

PastaPastaPasta referenced this in commit 087885e9b8 on Jan 2, 2019

PastaPastaPasta referenced this in commit eea5fb192b on Jan 2, 2019

PastaPastaPasta referenced this in commit e931cc79bd on Jan 2, 2019

PastaPastaPasta referenced this in commit 06823635dd on Jan 2, 2019

PastaPastaPasta referenced this in commit ceb59d5dfe on Jan 2, 2019

PastaPastaPasta referenced this in commit 6087a3f7f1 on Jan 3, 2019

PastaPastaPasta referenced this in commit b47c06edf0 on Jan 3, 2019

PastaPastaPasta referenced this in commit 427375b5db on Jan 21, 2019

PastaPastaPasta referenced this in commit 2e7939b6bd on Jan 21, 2019

PastaPastaPasta referenced this in commit 6bc67b78ce on Jan 29, 2019

PastaPastaPasta referenced this in commit 2e5d899481 on Jan 29, 2019

PastaPastaPasta referenced this in commit dad8c67d38 on Feb 26, 2019

PastaPastaPasta referenced this in commit 31385edcd8 on Feb 26, 2019

PastaPastaPasta referenced this in commit 914bd78770 on Feb 26, 2019

UdjinM6 referenced this in commit bcb2373b3a on Mar 9, 2019

UdjinM6 referenced this in commit 82791f3a89 on Mar 9, 2019

PastaPastaPasta referenced this in commit 7299bb673b on Mar 10, 2019

PastaPastaPasta referenced this in commit d136b6ad5d on Mar 10, 2019

MarcoFalke locked this on Dec 16, 2021

[qa] Add logging to test_framework.py #9768