From 84b9e3e72b2bf8590603072d709a3ea294dd5483 Mon Sep 17 00:00:00 2001 From: Rusty Russell Date: Wed, 10 Oct 2018 09:36:33 +1030 Subject: [PATCH] lightningd: reduce log spam from bitcoin-cli invocations. During tests, this is half our log! And Travis truncates it if we get a failure in test_restart_many_payments. Interestingly, test_logging had a bug which relied on this spam :) Signed-off-by: Rusty Russell --- lightningd/bitcoind.c | 12 +++++++----- tests/test_misc.py | 2 +- 2 files changed, 8 insertions(+), 6 deletions(-) diff --git a/lightningd/bitcoind.c b/lightningd/bitcoind.c index 79bcf9697..e3c44a393 100644 --- a/lightningd/bitcoind.c +++ b/lightningd/bitcoind.c @@ -164,10 +164,14 @@ static void bcli_finished(struct io_conn *conn UNUSED, struct bitcoin_cli *bcli) struct bitcoind *bitcoind = bcli->bitcoind; enum bitcoind_prio prio = bcli->prio; bool ok; + u64 msec = time_to_msec(time_between(time_now(), bcli->start)); + + /* If it took over 10 seconds, that's rather strange. */ + if (msec > 10000) + log_unusual(bitcoind->log, + "bitcoin-cli: finished %s (%"PRIu64" ms)", + bcli_args(tmpctx, bcli), msec); - log_debug(bitcoind->log, "bitcoin-cli: finished %s (%"PRIu64" ms)", - bcli_args(tmpctx, bcli), - time_to_msec(time_between(time_now(), bcli->start))); assert(bitcoind->num_requests[prio] > 0); /* FIXME: If we waited for SIGCHILD, this could never hang! */ @@ -224,8 +228,6 @@ static void next_bcli(struct bitcoind *bitcoind, enum bitcoind_prio prio) if (!bcli) return; - log_debug(bitcoind->log, "bitcoin-cli: starting %s", - bcli_args(tmpctx, bcli)); bcli->pid = pipecmdarr(&bcli->fd, NULL, &bcli->fd, cast_const2(char **, bcli->args)); if (bcli->pid < 0) diff --git a/tests/test_misc.py b/tests/test_misc.py index f8479ae1e..327b99b99 100644 --- a/tests/test_misc.py +++ b/tests/test_misc.py @@ -943,7 +943,7 @@ def test_logging(node_factory): def check_new_log(): log2 = open(logpath).readlines() - return len(log2) > 1 and log2[0].endswith("Started log due to SIGHUP\n") + return len(log2) > 0 and log2[0].endswith("Started log due to SIGHUP\n") wait_for(check_new_log)