diff --git a/lightningd/jsonrpc.c b/lightningd/jsonrpc.c index 67dab8285..c5a381956 100644 --- a/lightningd/jsonrpc.c +++ b/lightningd/jsonrpc.c @@ -912,7 +912,9 @@ parse_request(struct json_connection *jcon, const jsmntok_t tok[]) "Expected string for method"); } - log_debug(jcon->log, "IN:id=%s", c->id); + /* Debug was too chatty, so we use IO here, even though we're + * actually just logging the id */ + log_io(jcon->log, LOG_IO_IN, NULL, c->id, NULL, 0); c->json_cmd = find_cmd(jcon->ld->jsonrpc, jcon->buffer, method); if (!c->json_cmd) { @@ -1353,7 +1355,7 @@ struct jsonrpc_request *jsonrpc_request_start_( json_object_start(r->stream, "params"); } if (log) - log_debug(log, "OUT:id=%s", r->id); + log_io(log, LOG_IO_OUT, NULL, r->id, NULL, 0); return r; } diff --git a/tests/test_invoices.py b/tests/test_invoices.py index 58d2aeeca..277f03d58 100644 --- a/tests/test_invoices.py +++ b/tests/test_invoices.py @@ -12,7 +12,7 @@ import unittest def test_invoice(node_factory, chainparams): - l1, l2 = node_factory.line_graph(2, fundchannel=False) + l1, l2 = node_factory.line_graph(2, fundchannel=False, opts={'log-level': 'io'}) addr1 = l2.rpc.newaddr('bech32')['bech32'] addr2 = l2.rpc.newaddr('p2sh-segwit')['p2sh-segwit'] @@ -21,7 +21,7 @@ def test_invoice(node_factory, chainparams): # Side note: invoice calls out to listincoming, so check JSON id is as expected myname = os.path.splitext(os.path.basename(sys.argv[0]))[0] - l1.daemon.wait_for_log(": OUT:id={}:invoice#[0-9]*/cln:listincoming#[0-9]*".format(myname)) + l1.daemon.wait_for_log(r": {}:invoice#[0-9]*/cln:listincoming#[0-9]*\[OUT\]".format(myname)) after = int(time.time()) b11 = l1.rpc.decodepay(inv['bolt11']) diff --git a/tests/test_misc.py b/tests/test_misc.py index b86449b5f..9b846347f 100644 --- a/tests/test_misc.py +++ b/tests/test_misc.py @@ -863,7 +863,7 @@ def test_malformed_rpc(node_factory): def test_cli(node_factory): - l1 = node_factory.get_node() + l1 = node_factory.get_node(options={'log-level': 'io'}) out = subprocess.check_output(['cli/lightning-cli', '--network={}'.format(TEST_NETWORK), @@ -874,7 +874,7 @@ def test_cli(node_factory): assert 'help [command]\n List available commands, or give verbose help on one {command}' in out # Check JSON id is as expected - l1.daemon.wait_for_log("jsonrpc#[0-9]*: IN:id=cli:help#[0-9]*") + l1.daemon.wait_for_log(r"jsonrpc#[0-9]*: cli:help#[0-9]*\[IN\]") # Test JSON output. out = subprocess.check_output(['cli/lightning-cli', diff --git a/tests/test_plugin.py b/tests/test_plugin.py index cb29400df..53d474c2d 100644 --- a/tests/test_plugin.py +++ b/tests/test_plugin.py @@ -1478,7 +1478,8 @@ def test_libplugin(node_factory): """Sanity checks for plugins made with libplugin""" plugin = os.path.join(os.getcwd(), "tests/plugins/test_libplugin") l1 = node_factory.get_node(options={"plugin": plugin, - 'allow-deprecated-apis': False}) + 'allow-deprecated-apis': False, + 'log-level': 'io'}) # Test startup assert l1.daemon.is_in_log("test_libplugin initialised!") @@ -1490,7 +1491,7 @@ def test_libplugin(node_factory): myname = os.path.splitext(os.path.basename(sys.argv[0]))[0] # Side note: getmanifest will trace back to plugin_start - l1.daemon.wait_for_log(": OUT:id={}:plugin#[0-9]*/cln:getmanifest#[0-9]*".format(myname)) + l1.daemon.wait_for_log(r": {}:plugin#[0-9]*/cln:getmanifest#[0-9]*\[OUT\]".format(myname)) # Test commands assert l1.rpc.call("helloworld") == {"hello": "world"} @@ -1504,9 +1505,9 @@ def test_libplugin(node_factory): assert l1.rpc.call("helloworld", {"name": "test"}) == {"hello": "test"} # Test hooks and notifications (add plugin, so we can test hook id) - l2 = node_factory.get_node(options={"plugin": plugin}) + l2 = node_factory.get_node(options={"plugin": plugin, 'log-level': 'io'}) l2.connect(l1) - l2.daemon.wait_for_log(": OUT:id={}:connect#[0-9]*/cln:peer_connected#[0-9]*".format(myname)) + l2.daemon.wait_for_log(r": {}:connect#[0-9]*/cln:peer_connected#[0-9]*\[OUT\]".format(myname)) l1.daemon.wait_for_log("{} peer_connected".format(l2.info["id"])) l1.daemon.wait_for_log("{} connected".format(l2.info["id"])) diff --git a/tests/test_wallet.py b/tests/test_wallet.py index 19211b8d3..a90fca091 100644 --- a/tests/test_wallet.py +++ b/tests/test_wallet.py @@ -29,7 +29,7 @@ HSM_BAD_PASSWORD = 22 def test_withdraw(node_factory, bitcoind): amount = 1000000 # Don't get any funds from previous runs. - l1 = node_factory.get_node(random_hsm=True) + l1 = node_factory.get_node(random_hsm=True, options={'log-level': 'io'}) l2 = node_factory.get_node(random_hsm=True) addr = l1.rpc.newaddr()['bech32'] @@ -62,7 +62,7 @@ def test_withdraw(node_factory, bitcoind): # Side note: sendrawtransaction will trace back to withdrawl myname = os.path.splitext(os.path.basename(sys.argv[0]))[0] - l1.daemon.wait_for_log(": OUT:id={}:withdraw#[0-9]*/cln:withdraw#[0-9]*/txprepare:sendpsbt#[0-9]*/cln:sendrawtransaction#[0-9]*".format(myname)) + l1.daemon.wait_for_log(r": {}:withdraw#[0-9]*/cln:withdraw#[0-9]*/txprepare:sendpsbt#[0-9]*/cln:sendrawtransaction#[0-9]*\[OUT\]".format(myname)) # Make sure bitcoind received the withdrawal unspent = l1.bitcoin.rpc.listunspent(0)