diff --git a/contrib/pyln-testing/pyln/testing/utils.py b/contrib/pyln-testing/pyln/testing/utils.py index 62d650cb3..590097b0f 100644 --- a/contrib/pyln-testing/pyln/testing/utils.py +++ b/contrib/pyln-testing/pyln/testing/utils.py @@ -199,15 +199,24 @@ class TailableProc(object): # pass it to the log matcher and not print it to stdout). self.log_filter = lambda line: False - def start(self, stdin=None): - """Start the underlying process and start monitoring it. + def start(self, stdin=None, stdout_redir=True): + """Start the underlying process and start monitoring it. If + stdout_redir is false, you have to make sure logs go into + outputDir/log + """ logging.debug("Starting '%s'", " ".join(self.cmd_line)) - self.proc = subprocess.Popen(self.cmd_line, - stdin=stdin, - stdout=self.stdout_write, - stderr=self.stderr_write, - env=self.env) + if stdout_redir: + self.proc = subprocess.Popen(self.cmd_line, + stdin=stdin, + stdout=self.stdout_write, + stderr=self.stderr_write, + env=self.env) + else: + self.proc = subprocess.Popen(self.cmd_line, + stdin=stdin, + stderr=self.stderr_write, + env=self.env) def stop(self, timeout=10): self.proc.terminate() @@ -529,7 +538,8 @@ class ElementsD(BitcoinD): class LightningD(TailableProc): def __init__(self, lightning_dir, bitcoindproxy, port=9735, random_hsm=False, node_id=0): - TailableProc.__init__(self, lightning_dir) + # We handle our own version of verbose, below. + TailableProc.__init__(self, lightning_dir, verbose=False) self.executable = 'lightningd' self.lightning_dir = lightning_dir self.port = port @@ -568,6 +578,10 @@ class LightningD(TailableProc): self.opts['dev-fast-gossip'] = None self.opts['dev-bitcoind-poll'] = 1 self.prefix = 'lightningd-%d' % (node_id) + # Log to stdout so we see it in failure cases, and log file for TailableProc. + self.opts['log-file'] = ['-', os.path.join(lightning_dir, "log")] + # In case you want specific ordering! + self.early_opts = [] def cleanup(self): # To force blackhole to exit, disconnect file must be truncated! @@ -588,11 +602,11 @@ class LightningD(TailableProc): else: opts.append("--{}={}".format(k, v)) - return self.cmd_prefix + [self.executable] + opts + return self.cmd_prefix + [self.executable] + self.early_opts + opts def start(self, stdin=None, wait_for_initialized=True): self.opts['bitcoin-rpcport'] = self.rpcproxy.rpcport - TailableProc.start(self, stdin) + TailableProc.start(self, stdin, stdout_redir=False) if wait_for_initialized: self.wait_for_log("Server started with public key") logging.info("LightningD started") diff --git a/lightningd/options.c b/lightningd/options.c index e7e2b9cc4..2af57ac09 100644 --- a/lightningd/options.c +++ b/lightningd/options.c @@ -493,6 +493,16 @@ static char *opt_important_plugin(const char *arg, struct lightningd *ld) return NULL; } +/* Test code looks in logs, so we print prompts to log as well as stdout */ +static void prompt(struct lightningd *ld, const char *str) +{ + printf("%s\n", str); + log_debug(ld->log, "PROMPT: %s", str); + /* If we don't flush we might end up being buffered and we might seem + * to hang while we wait for the password. */ + fflush(stdout); +} + /* Prompt the user to enter a password, from which will be derived the key used * for `hsm_secret` encryption. * The algorithm used to derive the key is Argon2(id), to which libsodium @@ -509,18 +519,15 @@ static char *opt_set_hsm_password(struct lightningd *ld) return tal_fmt(NULL, "Could not access 'hsm_secret': %s", strerror(errno)); - printf("The hsm_secret is encrypted with a password. In order to " - "decrypt it and start the node you must provide the password.\n"); - printf("Enter hsm_secret password:\n"); - /* If we don't flush we might end up being buffered and we might seem - * to hang while we wait for the password. */ - fflush(stdout); + prompt(ld, "The hsm_secret is encrypted with a password. In order to " + "decrypt it and start the node you must provide the password."); + prompt(ld, "Enter hsm_secret password:"); passwd = read_stdin_pass_with_exit_code(&err_msg, &opt_exitcode); if (!passwd) return err_msg; if (!is_encrypted) { - printf("Confirm hsm_secret password:\n"); + prompt(ld, "Confirm hsm_secret password:"); fflush(stdout); passwd_confirmation = read_stdin_pass_with_exit_code(&err_msg, &opt_exitcode); if (!passwd_confirmation) @@ -532,7 +539,7 @@ static char *opt_set_hsm_password(struct lightningd *ld) } free(passwd_confirmation); } - printf("\n"); + prompt(ld, ""); ld->config.keypass = tal(NULL, struct secret); diff --git a/tests/test_misc.py b/tests/test_misc.py index d209778af..e6bf96c8e 100644 --- a/tests/test_misc.py +++ b/tests/test_misc.py @@ -1007,8 +1007,11 @@ def test_daemon_option(node_factory): l1.stop() os.unlink(l1.rpc.socket_path) + # Stop it from logging to stdout! logfname = os.path.join(l1.daemon.lightning_dir, TEST_NETWORK, "log-daemon") - subprocess.run(l1.daemon.cmd_line + ['--daemon', '--log-file={}'.format(logfname)], env=l1.daemon.env, + l1.daemon.opts['log-file'] = logfname + l1.daemon.opts['daemon'] = None + subprocess.run(l1.daemon.cmd_line, env=l1.daemon.env, check=True) # Test some known output (wait for rpc to be ready) @@ -2399,7 +2402,10 @@ def test_version_reexec(node_factory, bitcoind): def test_notimestamp_logging(node_factory): - l1 = node_factory.get_node(options={'log-timestamps': False}) + l1 = node_factory.get_node(start=False) + # Make sure this is specified *before* other options! + l1.daemon.early_opts = ['--log-timestamps=false'] + l1.start() assert l1.daemon.logs[0].startswith("DEBUG") assert l1.rpc.listconfigs()['log-timestamps'] is False