From 3e0e196efdad7cc0b11f859eeb6d8747dbfd0ef6 Mon Sep 17 00:00:00 2001
From: Lennart Poettering <lennart@poettering.net>
Date: Wed, 20 Dec 2017 12:50:43 +0100
Subject: [PATCH] sd-bus: log about bus state changes

Let's unify all state changes in a new helper function, from which we
can then debug log all state changes
---
 src/libsystemd/sd-bus/bus-internal.h |  5 +++-
 src/libsystemd/sd-bus/bus-socket.c   |  6 ++---
 src/libsystemd/sd-bus/sd-bus.c       | 35 +++++++++++++++++++++++-----
 3 files changed, 36 insertions(+), 10 deletions(-)

diff --git a/src/libsystemd/sd-bus/bus-internal.h b/src/libsystemd/sd-bus/bus-internal.h
index abda27fd56..53f3194bef 100644
--- a/src/libsystemd/sd-bus/bus-internal.h
+++ b/src/libsystemd/sd-bus/bus-internal.h
@@ -166,7 +166,8 @@ enum bus_state {
         BUS_HELLO,           /* we are waiting for the Hello() response */
         BUS_RUNNING,
         BUS_CLOSING,
-        BUS_CLOSED
+        BUS_CLOSED,
+        _BUS_STATE_MAX,
 };
 
 static inline bool BUS_IS_OPEN(enum bus_state state) {
@@ -411,3 +412,5 @@ int bus_maybe_reply_error(sd_bus_message *m, int r, sd_bus_error *error);
         } while (false)
 
 void bus_enter_closing(sd_bus *bus);
+
+void bus_set_state(sd_bus *bus, enum bus_state state);
diff --git a/src/libsystemd/sd-bus/bus-socket.c b/src/libsystemd/sd-bus/bus-socket.c
index e2991bc8b2..61539313bc 100644
--- a/src/libsystemd/sd-bus/bus-socket.c
+++ b/src/libsystemd/sd-bus/bus-socket.c
@@ -675,7 +675,7 @@ int bus_socket_start_auth(sd_bus *b) {
 
         bus_get_peercred(b);
 
-        b->state = BUS_AUTHENTICATING;
+        bus_set_state(b, BUS_AUTHENTICATING);
         b->auth_timeout = now(CLOCK_MONOTONIC) + BUS_AUTH_TIMEOUT;
 
         if (sd_is_socket(b->input_fd, AF_UNIX, 0, 0) <= 0)
@@ -894,7 +894,7 @@ int bus_socket_connect(sd_bus *b) {
                                 /* Note that very likely we are already in BUS_OPENING state here, as we enter it when
                                  * we start parsing the address string. The only reason we set the state explicitly
                                  * here, is to undo BUS_WATCH_BIND, in case we did the inotify magic. */
-                                b->state = BUS_OPENING;
+                                bus_set_state(b, BUS_OPENING);
                                 return 1;
                         }
 
@@ -910,7 +910,7 @@ int bus_socket_connect(sd_bus *b) {
                                 if (inotify_done) {
                                         /* inotify set up already, don't do it again, just return now, and remember
                                          * that we are waiting for inotify events now. */
-                                        b->state = BUS_WATCH_BIND;
+                                        bus_set_state(b, BUS_WATCH_BIND);
                                         return 1;
                                 }
 
diff --git a/src/libsystemd/sd-bus/sd-bus.c b/src/libsystemd/sd-bus/sd-bus.c
index 74d54f785f..671d2e45fb 100644
--- a/src/libsystemd/sd-bus/sd-bus.c
+++ b/src/libsystemd/sd-bus/sd-bus.c
@@ -452,6 +452,29 @@ static int synthesize_connected_signal(sd_bus *bus) {
         return 0;
 }
 
+void bus_set_state(sd_bus *bus, enum bus_state state) {
+
+        static const char * const table[_BUS_STATE_MAX] = {
+                [BUS_UNSET] = "UNSET",
+                [BUS_WATCH_BIND] = "WATCH_BIND",
+                [BUS_OPENING] = "OPENING",
+                [BUS_AUTHENTICATING] = "AUTHENTICATING",
+                [BUS_HELLO] = "HELLO",
+                [BUS_RUNNING] = "RUNNING",
+                [BUS_CLOSING] = "CLOSING",
+                [BUS_CLOSED] = "CLOSED",
+        };
+
+        assert(bus);
+        assert(state < _BUS_STATE_MAX);
+
+        if (state == bus->state)
+                return;
+
+        log_debug("Bus %s: changing state %s → %s", strna(bus->description), table[bus->state], table[state]);
+        bus->state = state;
+}
+
 static int hello_callback(sd_bus_message *reply, void *userdata, sd_bus_error *error) {
         const char *s;
         sd_bus *bus;
@@ -478,7 +501,7 @@ static int hello_callback(sd_bus_message *reply, void *userdata, sd_bus_error *e
                 return -ENOMEM;
 
         if (bus->state == BUS_HELLO) {
-                bus->state = BUS_RUNNING;
+                bus_set_state(bus, BUS_RUNNING);
 
                 r = synthesize_connected_signal(bus);
                 if (r < 0)
@@ -532,11 +555,11 @@ int bus_start_running(sd_bus *bus) {
         }
 
         if (bus->bus_client) {
-                bus->state = BUS_HELLO;
+                bus_set_state(bus, BUS_HELLO);
                 return 1;
         }
 
-        bus->state = BUS_RUNNING;
+        bus_set_state(bus, BUS_RUNNING);
 
         r = synthesize_connected_signal(bus);
         if (r < 0)
@@ -1090,7 +1113,7 @@ _public_ int sd_bus_start(sd_bus *bus) {
         assert_return(bus->state == BUS_UNSET, -EPERM);
         assert_return(!bus_pid_changed(bus), -ECHILD);
 
-        bus->state = BUS_OPENING;
+        bus_set_state(bus, BUS_OPENING);
 
         if (bus->is_server && bus->bus_client)
                 return -EINVAL;
@@ -1403,7 +1426,7 @@ _public_ void sd_bus_close(sd_bus *bus) {
         if (bus_pid_changed(bus))
                 return;
 
-        bus->state = BUS_CLOSED;
+        bus_set_state(bus, BUS_CLOSED);
 
         sd_bus_detach_event(bus);
 
@@ -1432,7 +1455,7 @@ void bus_enter_closing(sd_bus *bus) {
         if (!IN_SET(bus->state, BUS_WATCH_BIND, BUS_OPENING, BUS_AUTHENTICATING, BUS_HELLO, BUS_RUNNING))
                 return;
 
-        bus->state = BUS_CLOSING;
+        bus_set_state(bus, BUS_CLOSING);
 }
 
 _public_ sd_bus *sd_bus_ref(sd_bus *bus) {