dbus: register to DBus asynchronously

Chen Jie observed and analyzed a deadlock. Assuming systemd-kmsg-syslogd
is already stopped, but rsyslogd is not started yet:
 1. systemd makes a synchronous call to dbus-daemon.
 2. dbus-daemon wants to write something to syslog.
 3. syslog needs to be started by systemd.
   ... but cannot be, because systemd is waiting in 1.

Solve this by avoiding synchronous D-Bus calls. I had to write an async
bus registration call. Interestingly, D-Bus authors anticipated this, in
documentation to dbus_bus_set_unique_name():
> The only reason to use this function is to re-implement the equivalent
> of dbus_bus_register() yourself. One (probably unusual) reason to do
> that might be to do the bus registration call asynchronously instead
> of synchronously.

Lennart's comments from IRC:
> though I think this doesn't fix the problem in its entirety
> simply because dbus_connection_open_private() itself is still synchronous
> i.e. the connect() call behind it is not async
> I think I listed that issue actually on some D-Bus todo list
> i.e. to make dbus_connection_get() fully async
> but that's going to be hard
> so your patch looks good

So it may not be perfect, but it's clearly an improvement.
I did not manage to reproduce the original deadlock with the patch.

3 files changed, 262 insertions, 119 deletions

diff --git a/src/dbus.c b/src/dbus.c
index daa2c84a05..81b4f53434 100644
--- a/src/dbus.c
+++ b/src/dbus.c
@@ -48,6 +48,11 @@
 
 #define CONNECTIONS_MAX 52
 
+/* Well-known address (http://dbus.freedesktop.org/doc/dbus-specification.html#message-bus-types) */
+#define DBUS_SYSTEM_BUS_DEFAULT_ADDRESS "unix:path=/var/run/dbus/system_bus_socket"
+/* Only used as a fallback */
+#define DBUS_SESSION_BUS_DEFAULT_ADDRESS "autolaunch:"
+
 static const char bus_properties_interface[] = BUS_PROPERTIES_INTERFACE;
 static const char bus_introspectable_interface[] = BUS_INTROSPECTABLE_INTERFACE;
 
@@ -767,37 +772,19 @@ static void bus_new_connection(
         dbus_connection_ref(new_connection);
 }
 
-static int bus_init_system(Manager *m) {
-        DBusError error;
-        int r;
-
-        assert(m);
-
-        dbus_error_init(&error);
-
-        if (m->system_bus)
-                return 0;
-
-        if (m->running_as == MANAGER_SYSTEM && m->api_bus)
-                m->system_bus = m->api_bus;
-        else {
-                if (!(m->system_bus = dbus_bus_get_private(DBUS_BUS_SYSTEM, &error))) {
-                        log_debug("Failed to get system D-Bus connection, retrying later: %s", bus_error_message(&error));
-                        r = 0;
-                        goto fail;
-                }
-
-                if ((r = bus_setup_loop(m, m->system_bus)) < 0)
-                        goto fail;
-        }
+static int init_registered_system_bus(Manager *m) {
+        char *id;
 
         if (!dbus_connection_add_filter(m->system_bus, system_bus_message_filter, m, NULL)) {
                 log_error("Not enough memory");
-                r = -ENOMEM;
-                goto fail;
+                return -ENOMEM;
         }
 
         if (m->running_as != MANAGER_SYSTEM) {
+                DBusError error;
+
+                dbus_error_init(&error);
+
                 dbus_bus_add_match(m->system_bus,
                                    "type='signal',"
                                    "interface='org.freedesktop.systemd1.Agent',"
@@ -807,59 +794,28 @@ static int bus_init_system(Manager *m) {
 
                 if (dbus_error_is_set(&error)) {
                         log_error("Failed to register match: %s", bus_error_message(&error));
-                        r = -EIO;
-                        goto fail;
+                        dbus_error_free(&error);
+                        return -1;
                 }
         }
 
-        if (m->api_bus != m->system_bus) {
-                char *id;
-                log_debug("Successfully connected to system D-Bus bus %s as %s",
-                         strnull((id = dbus_connection_get_server_id(m->system_bus))),
-                         strnull(dbus_bus_get_unique_name(m->system_bus)));
-                dbus_free(id);
-        }
+        log_debug("Successfully connected to system D-Bus bus %s as %s",
+                 strnull((id = dbus_connection_get_server_id(m->system_bus))),
+                 strnull(dbus_bus_get_unique_name(m->system_bus)));
+        dbus_free(id);
 
         return 0;
-
-fail:
-        bus_done_system(m);
-        dbus_error_free(&error);
-
-        return r;
 }
 
-static int bus_init_api(Manager *m) {
-        DBusError error;
+static int init_registered_api_bus(Manager *m) {
         int r;
 
-        assert(m);
-
-        dbus_error_init(&error);
-
-        if (m->api_bus)
-                return 0;
-
-        if (m->running_as == MANAGER_SYSTEM && m->system_bus)
-                m->api_bus = m->system_bus;
-        else {
-                if (!(m->api_bus = dbus_bus_get_private(m->running_as == MANAGER_USER ? DBUS_BUS_SESSION : DBUS_BUS_SYSTEM, &error))) {
-                        log_debug("Failed to get API D-Bus connection, retrying later: %s", bus_error_message(&error));
-                        r = 0;
-                        goto fail;
-                }
-
-                if ((r = bus_setup_loop(m, m->api_bus)) < 0)
-                        goto fail;
-        }
-
         if (!dbus_connection_register_object_path(m->api_bus, "/org/freedesktop/systemd1", &bus_manager_vtable, m) ||
             !dbus_connection_register_fallback(m->api_bus, "/org/freedesktop/systemd1/unit", &bus_unit_vtable, m) ||
             !dbus_connection_register_fallback(m->api_bus, "/org/freedesktop/systemd1/job", &bus_job_vtable, m) ||
             !dbus_connection_add_filter(m->api_bus, api_bus_message_filter, m, NULL)) {
                 log_error("Not enough memory");
-                r = -ENOMEM;
-                goto fail;
+                return -ENOMEM;
         }
 
         /* Get NameOwnerChange messages */
@@ -869,13 +825,7 @@ static int bus_init_api(Manager *m) {
                            "interface='"DBUS_INTERFACE_DBUS"',"
                            "member='NameOwnerChanged',"
                            "path='"DBUS_PATH_DBUS"'",
-                           &error);
-
-        if (dbus_error_is_set(&error)) {
-                log_error("Failed to register match: %s", bus_error_message(&error));
-                r = -EIO;
-                goto fail;
-        }
+                           NULL);
 
         /* Get activation requests */
         dbus_bus_add_match(m->api_bus,
@@ -884,33 +834,225 @@ static int bus_init_api(Manager *m) {
                            "interface='org.freedesktop.systemd1.Activator',"
                            "member='ActivationRequest',"
                            "path='"DBUS_PATH_DBUS"'",
-                           &error);
-
-        if (dbus_error_is_set(&error)) {
-                log_error("Failed to register match: %s", bus_error_message(&error));
-                r = -EIO;
-                goto fail;
-        }
+                           NULL);
 
-        if ((r = request_name(m)) < 0)
-                goto fail;
+        r = request_name(m);
+        if (r < 0)
+                return r;
 
-        if ((r = query_name_list(m)) < 0)
-                goto fail;
+        r = query_name_list(m);
+        if (r < 0)
+                return r;
 
-        if (m->api_bus != m->system_bus) {
+        if (m->running_as == MANAGER_USER) {
                 char *id;
                 log_debug("Successfully connected to API D-Bus bus %s as %s",
                          strnull((id = dbus_connection_get_server_id(m->api_bus))),
                          strnull(dbus_bus_get_unique_name(m->api_bus)));
                 dbus_free(id);
+        } else
+                log_debug("Successfully initialized API on the system bus");
+
+        return 0;
+}
+
+static void bus_register_cb(DBusPendingCall *pending, void *userdata) {
+        Manager *m = userdata;
+        DBusConnection **conn;
+        DBusMessage *reply;
+        DBusError error;
+        const char *name;
+        int r = 0;
+
+        dbus_error_init(&error);
+
+        conn = dbus_pending_call_get_data(pending, m->conn_data_slot);
+        assert(conn == &m->system_bus || conn == &m->api_bus);
+
+        reply = dbus_pending_call_steal_reply(pending);
+
+        switch (dbus_message_get_type(reply)) {
+        case DBUS_MESSAGE_TYPE_ERROR:
+                assert_se(dbus_set_error_from_message(&error, reply));
+                log_warning("Failed to register to bus: %s", bus_error_message(&error));
+                r = -1;
+                break;
+        case DBUS_MESSAGE_TYPE_METHOD_RETURN:
+                if (!dbus_message_get_args(reply, &error,
+                                           DBUS_TYPE_STRING, &name,
+                                           DBUS_TYPE_INVALID)) {
+                        log_error("Failed to parse Hello reply: %s", bus_error_message(&error));
+                        r = -1;
+                        break;
+                }
+
+                log_debug("Received name %s in reply to Hello", name);
+                if (!dbus_bus_set_unique_name(*conn, name)) {
+                        log_error("Failed to set unique name");
+                        r = -1;
+                        break;
+                }
+
+                if (conn == &m->system_bus) {
+                        r = init_registered_system_bus(m);
+                        if (r == 0 && m->running_as == MANAGER_SYSTEM)
+                                r = init_registered_api_bus(m);
+                } else
+                        r = init_registered_api_bus(m);
+
+                break;
+        default:
+                assert_not_reached("Invalid reply message");
+        }
+
+        dbus_message_unref(reply);
+        dbus_error_free(&error);
+
+        if (r < 0) {
+                if (conn == &m->system_bus) {
+                        log_debug("Failed setting up the system bus");
+                        bus_done_system(m);
+                } else {
+                        log_debug("Failed setting up the API bus");
+                        bus_done_api(m);
+                }
+        }
+}
+
+static int manager_bus_async_register(Manager *m, DBusConnection **conn) {
+        DBusMessage *message = NULL;
+        DBusPendingCall *pending = NULL;
+
+        message = dbus_message_new_method_call(DBUS_SERVICE_DBUS,
+                                               DBUS_PATH_DBUS,
+                                               DBUS_INTERFACE_DBUS,
+                                               "Hello");
+        if (!message)
+                goto oom;
+
+        if (!dbus_connection_send_with_reply(*conn, message, &pending, -1))
+                goto oom;
+
+        if (!dbus_pending_call_set_data(pending, m->conn_data_slot, conn, NULL))
+                goto oom;
+
+        if (!dbus_pending_call_set_notify(pending, bus_register_cb, m, NULL))
+                goto oom;
+
+        dbus_message_unref(message);
+        dbus_pending_call_unref(pending);
+
+        return 0;
+oom:
+        if (pending) {
+                dbus_pending_call_cancel(pending);
+                dbus_pending_call_unref(pending);
+        }
+
+        if (message)
+                dbus_message_unref(message);
+
+        return -ENOMEM;
+}
+
+static DBusConnection* manager_bus_connect_private(Manager *m, DBusBusType type) {
+        const char *address;
+        DBusConnection *connection;
+        DBusError error;
+
+        switch (type) {
+        case DBUS_BUS_SYSTEM:
+                address = getenv("DBUS_SYSTEM_BUS_ADDRESS");
+                if (!address || !address[0])
+                        address = DBUS_SYSTEM_BUS_DEFAULT_ADDRESS;
+                break;
+        case DBUS_BUS_SESSION:
+                address = getenv("DBUS_SESSION_BUS_ADDRESS");
+                if (!address || !address[0])
+                        address = DBUS_SESSION_BUS_DEFAULT_ADDRESS;
+                break;
+        default:
+                assert_not_reached("Invalid bus type");
+        }
+
+        dbus_error_init(&error);
+
+        connection = dbus_connection_open_private(address, &error);
+        if (!connection) {
+                log_warning("Failed to open private bus connection: %s", bus_error_message(&error));
+                goto fail;
+        }
+
+        return connection;
+fail:
+        if (connection)
+                dbus_connection_close(connection);
+        dbus_error_free(&error);
+        return NULL;
+}
+
+static int bus_init_system(Manager *m) {
+        int r;
+
+        if (m->system_bus)
+                return 0;
+
+        m->system_bus = manager_bus_connect_private(m, DBUS_BUS_SYSTEM);
+        if (!m->system_bus) {
+                log_debug("Failed to connect to system D-Bus, retrying later");
+                r = 0;
+                goto fail;
         }
 
+        r = bus_setup_loop(m, m->system_bus);
+        if (r < 0)
+                goto fail;
+
+        r = manager_bus_async_register(m, &m->system_bus);
+        if (r < 0)
+                goto fail;
+
         return 0;
+fail:
+        bus_done_system(m);
+
+        return r;
+}
+
+static int bus_init_api(Manager *m) {
+        int r;
+
+        if (m->api_bus)
+                return 0;
+
+        if (m->running_as == MANAGER_SYSTEM) {
+                m->api_bus = m->system_bus;
+                /* In this mode there is no distinct connection to the API bus,
+                 * the API is published on the system bus.
+                 * bus_register_cb() is aware of that and will init the API
+                 * when the system bus gets registered.
+                 * No need to setup anything here. */
+                return 0;
+        }
+
+        m->api_bus = manager_bus_connect_private(m, DBUS_BUS_SESSION);
+        if (!m->api_bus) {
+                log_debug("Failed to connect to API D-Bus, retrying later");
+                r = 0;
+                goto fail;
+        }
+
+        r = bus_setup_loop(m, m->api_bus);
+        if (r < 0)
+                goto fail;
 
+        r = manager_bus_async_register(m, &m->api_bus);
+        if (r < 0)
+                goto fail;
+
+        return 0;
 fail:
         bus_done_api(m);
-        dbus_error_free(&error);
 
         return r;
 }
@@ -989,22 +1131,20 @@ int bus_init(Manager *m, bool try_bus_connect) {
         int r;
 
         if (set_ensure_allocated(&m->bus_connections, trivial_hash_func, trivial_compare_func) < 0 ||
-            set_ensure_allocated(&m->bus_connections_for_dispatch, trivial_hash_func, trivial_compare_func) < 0) {
-                log_error("Not enough memory");
-                return -ENOMEM;
-        }
+            set_ensure_allocated(&m->bus_connections_for_dispatch, trivial_hash_func, trivial_compare_func) < 0)
+                goto oom;
 
         if (m->name_data_slot < 0)
-                if (!dbus_pending_call_allocate_data_slot(&m->name_data_slot)) {
-                        log_error("Not enough memory");
-                        return -ENOMEM;
-                }
+                if (!dbus_pending_call_allocate_data_slot(&m->name_data_slot))
+                        goto oom;
+
+        if (m->conn_data_slot < 0)
+                if (!dbus_pending_call_allocate_data_slot(&m->conn_data_slot))
+                        goto oom;
 
         if (m->subscribed_data_slot < 0)
-                if (!dbus_connection_allocate_data_slot(&m->subscribed_data_slot)) {
-                        log_error("Not enough memory");
-                        return -ENOMEM;
-                }
+                if (!dbus_connection_allocate_data_slot(&m->subscribed_data_slot))
+                        goto oom;
 
         if (try_bus_connect) {
                 if ((r = bus_init_system(m)) < 0 ||
@@ -1016,6 +1156,9 @@ int bus_init(Manager *m, bool try_bus_connect) {
                 return r;
 
         return 0;
+oom:
+        log_error("Not enough memory");
+        return -ENOMEM;
 }
 
 static void shutdown_connection(Manager *m, DBusConnection *c) {
@@ -1059,42 +1202,38 @@ static void shutdown_connection(Manager *m, DBusConnection *c) {
 }
 
 static void bus_done_api(Manager *m) {
-        assert(m);
-
-        if (m->api_bus) {
-                if (m->system_bus == m->api_bus)
-                        m->system_bus = NULL;
+        if (!m->api_bus)
+                return;
 
+        if (m->running_as == MANAGER_USER)
                 shutdown_connection(m, m->api_bus);
-                m->api_bus = NULL;
-        }
 
+        m->api_bus = NULL;
 
-       if (m->queued_message) {
-               dbus_message_unref(m->queued_message);
-               m->queued_message = NULL;
-       }
+        if (m->queued_message) {
+                dbus_message_unref(m->queued_message);
+                m->queued_message = NULL;
+        }
 }
 
 static void bus_done_system(Manager *m) {
-        assert(m);
+        if (!m->system_bus)
+                return;
 
-        if (m->system_bus == m->api_bus)
+        if (m->running_as == MANAGER_SYSTEM)
                 bus_done_api(m);
 
-        if (m->system_bus) {
-                shutdown_connection(m, m->system_bus);
-                m->system_bus = NULL;
-        }
+        shutdown_connection(m, m->system_bus);
+        m->system_bus = NULL;
 }
 
 static void bus_done_private(Manager *m) {
+        if (!m->private_bus)
+                return;
 
-        if (m->private_bus) {
-                dbus_server_disconnect(m->private_bus);
-                dbus_server_unref(m->private_bus);
-                m->private_bus = NULL;
-        }
+        dbus_server_disconnect(m->private_bus);
+        dbus_server_unref(m->private_bus);
+        m->private_bus = NULL;
 }
 
 void bus_done(Manager *m) {
@@ -1116,6 +1255,9 @@ void bus_done(Manager *m) {
         if (m->name_data_slot >= 0)
                dbus_pending_call_free_data_slot(&m->name_data_slot);
 
+        if (m->conn_data_slot >= 0)
+               dbus_pending_call_free_data_slot(&m->conn_data_slot);
+
         if (m->subscribed_data_slot >= 0)
                 dbus_connection_free_data_slot(&m->subscribed_data_slot);
 }
diff --git a/src/manager.c b/src/manager.c
index 111167a8c2..6acc821e9c 100644
--- a/src/manager.c
+++ b/src/manager.c
@@ -231,7 +231,7 @@ int manager_new(ManagerRunningAs running_as, Manager **_m) {
         dual_timestamp_get(&m->startup_timestamp);
 
         m->running_as = running_as;
-        m->name_data_slot = m->subscribed_data_slot = -1;
+        m->name_data_slot = m->conn_data_slot = m->subscribed_data_slot = -1;
         m->exit_code = _MANAGER_EXIT_CODE_INVALID;
         m->pin_cgroupfs_fd = -1;
 
diff --git a/src/manager.h b/src/manager.h
index 5deb5696b7..6e7558e175 100644
--- a/src/manager.h
+++ b/src/manager.h
@@ -179,6 +179,7 @@ struct Manager {
 
         Hashmap *watch_bus;  /* D-Bus names => Unit object n:1 */
         int32_t name_data_slot;
+        int32_t conn_data_slot;
         int32_t subscribed_data_slot;
 
         uint32_t current_job_id;