common: log when we toggle IO logging, don't edit env in tests!

Tests were failing when in the same thread after a test which set
log_all_io=True, because SIGUSR1 seemed to be turning logging *off*.

This is due to Python using references not copies for assignment.

Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>

common/status.c

@@ -17,6 +17,7 @@
 static int status_fd = -1;
 static struct daemon_conn *status_conn;
 volatile bool logging_io = false;
+static bool was_logging_io = false;
 
 static void got_sigusr1(int signal UNUSED)
 {
@@ -34,31 +35,43 @@ static void setup_logging_sighandler(void)
 	sigaction(SIGUSR1, &act, NULL);
 }
 
+static void report_logging_io(const char *why)
+{
+	if (logging_io != was_logging_io) {
+		was_logging_io = logging_io;
+		status_trace("%s: IO LOGGING %s",
+			     why, logging_io ? "ENABLED" : "DISABLED");
+	}
+}
+
 void status_setup_sync(int fd)
 {
-#if DEVELOPER
-	logging_io = (getenv("LIGHTNINGD_DEV_LOG_IO") != NULL);
-#endif
 	assert(status_fd == -1);
 	assert(!status_conn);
 	status_fd = fd;
 	setup_logging_sighandler();
+#if DEVELOPER
+	logging_io = (getenv("LIGHTNINGD_DEV_LOG_IO") != NULL);
+	report_logging_io("LIGHTNINGD_DEV_LOG_IO");
+#endif
 }
 
 void status_setup_async(struct daemon_conn *master)
 {
-#if DEVELOPER
-	logging_io = (getenv("LIGHTNINGD_DEV_LOG_IO") != NULL);
-#endif
 	assert(status_fd == -1);
 	assert(!status_conn);
 	status_conn = master;
 
 	setup_logging_sighandler();
+#if DEVELOPER
+	logging_io = (getenv("LIGHTNINGD_DEV_LOG_IO") != NULL);
+	report_logging_io("LIGHTNINGD_DEV_LOG_IO");
+#endif
 }
 
 void status_send(const u8 *msg TAKES)
 {
+	report_logging_io("SIGUSR1");
 	if (status_fd >= 0) {
 		int type =fromwire_peektype(msg);
 		if (!wire_sync_write(status_fd, msg))
@@ -82,6 +95,7 @@ static void status_peer_io_short(enum log_level iodir, const u8 *p)
 
 void status_peer_io(enum log_level iodir, const u8 *p)
 {
+	report_logging_io("SIGUSR1");
 	if (logging_io)
 		status_io_full(iodir, "", p);
 	/* We get a huge amount of gossip; don't log it */
@@ -92,6 +106,7 @@ void status_peer_io(enum log_level iodir, const u8 *p)
 void status_io(enum log_level iodir, const char *who,
 	       const void *data, size_t len)
 {
+	report_logging_io("SIGUSR1");
 	if (!logging_io)
 		return;
 	/* Horribly inefficient, but so is logging IO generally. */

tests/utils.py

@@ -81,7 +81,7 @@ class TailableProc(object):
     def __init__(self, outputDir=None, verbose=True):
         self.logs = []
         self.logs_cond = threading.Condition(threading.RLock())
-        self.env = os.environ
+        self.env = os.environ.copy()
         self.running = False
         self.proc = None
         self.outputDir = outputDir