From 165fee860a384b2e1ea4317551bc4463b3d53b61 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Zbigniew=20J=C4=99drzejewski-Szmek?= Date: Wed, 14 Oct 2020 11:59:23 +0200 Subject: [PATCH 1/2] sd-bus: add debug logs where we try to connect When connection to the bus fails it can be mighty hard to figure out what went wrong because we have many different connection mechanisms and we don't log what is happenning. --- src/libsystemd/sd-bus/bus-container.c | 8 +++++++- src/libsystemd/sd-bus/bus-socket.c | 10 ++++++++++ src/libsystemd/sd-bus/sd-bus.c | 10 ++++++++++ 3 files changed, 27 insertions(+), 1 deletion(-) diff --git a/src/libsystemd/sd-bus/bus-container.c b/src/libsystemd/sd-bus/bus-container.c index 40b0e8a947..e85a9eda2b 100644 --- a/src/libsystemd/sd-bus/bus-container.c +++ b/src/libsystemd/sd-bus/bus-container.c @@ -9,6 +9,7 @@ #include "fd-util.h" #include "namespace-util.h" #include "process-util.h" +#include "string-util.h" #include "util.h" int bus_container_connect_socket(sd_bus *b) { @@ -24,10 +25,15 @@ int bus_container_connect_socket(sd_bus *b) { assert(b->nspid > 0 || b->machine); if (b->nspid <= 0) { + log_debug("sd-bus: connecting bus%s%s to machine %s...", + b->description ? " " : "", strempty(b->description), b->machine); + r = container_get_leader(b->machine, &b->nspid); if (r < 0) return r; - } + } else + log_debug("sd-bus: connecting bus%s%s to namespace of PID "PID_FMT"...", + b->description ? " " : "", strempty(b->description), b->nspid); r = namespace_open(b->nspid, &pidnsfd, &mntnsfd, NULL, &usernsfd, &rootfd); if (r < 0) diff --git a/src/libsystemd/sd-bus/bus-socket.c b/src/libsystemd/sd-bus/bus-socket.c index de36a1f278..1a040157f4 100644 --- a/src/libsystemd/sd-bus/bus-socket.c +++ b/src/libsystemd/sd-bus/bus-socket.c @@ -885,6 +885,13 @@ int bus_socket_connect(sd_bus *b) { assert(b->output_fd < 0); assert(b->sockaddr.sa.sa_family != AF_UNSPEC); + if (DEBUG_LOGGING) { + _cleanup_free_ char *pretty = NULL; + (void) sockaddr_pretty(&b->sockaddr.sa, b->sockaddr_size, false, true, &pretty); + log_debug("sd-bus: starting bus%s%s by connecting to %s...", + b->description ? " " : "", strempty(b->description), strnull(pretty)); + } + b->input_fd = socket(b->sockaddr.sa.sa_family, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0); if (b->input_fd < 0) return -errno; @@ -956,6 +963,9 @@ int bus_socket_exec(sd_bus *b) { assert(b->exec_path); assert(b->busexec_pid == 0); + log_debug("sd-bus: starting bus%s%s with %s...", + b->description ? " " : "", strempty(b->description), b->exec_path); + r = socketpair(AF_UNIX, SOCK_STREAM|SOCK_NONBLOCK|SOCK_CLOEXEC, 0, s); if (r < 0) return -errno; diff --git a/src/libsystemd/sd-bus/sd-bus.c b/src/libsystemd/sd-bus/sd-bus.c index 015a215c42..c602088cf8 100644 --- a/src/libsystemd/sd-bus/sd-bus.c +++ b/src/libsystemd/sd-bus/sd-bus.c @@ -1155,6 +1155,16 @@ static int bus_start_fd(sd_bus *b) { assert(b->input_fd >= 0); assert(b->output_fd >= 0); + if (DEBUG_LOGGING) { + _cleanup_free_ char *pi = NULL, *po = NULL; + (void) fd_get_path(b->input_fd, &pi); + (void) fd_get_path(b->output_fd, &po); + log_debug("sd-bus: starting bus%s%s on fds %d/%d (%s, %s)...", + b->description ? " " : "", strempty(b->description), + b->input_fd, b->output_fd, + pi ?: "???", po ?: "???"); + } + r = fd_nonblock(b->input_fd, true); if (r < 0) return r; From ab4a88eb920e2f64a79a60c1ea9aecb7907a9635 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Zbigniew=20J=C4=99drzejewski-Szmek?= Date: Wed, 14 Oct 2020 12:15:58 +0200 Subject: [PATCH 2/2] sd-bus: add custom return code when $XDG_RUNTIME_DIR is not set We would return ENOENT, which is extremely confusing. Strace is not helpful because no *file* is actually missing. So let's add some logs at debug level and also use a custom return code. Let all user-facing utilities print a custom error message in that case. --- man/sd_bus_default.xml | 9 ++++++++- src/busctl/busctl.c | 4 ++-- src/home/homectl.c | 2 +- src/libsystemd/sd-bus/sd-bus.c | 3 ++- src/libsystemd/sd-bus/test-bus-cleanup.c | 2 +- src/libsystemd/sd-bus/test-bus-track.c | 2 +- src/login/inhibit.c | 2 +- src/portable/portablectl.c | 2 +- src/shared/bus-util.h | 14 ++++++++++---- src/systemctl/systemctl-util.c | 2 +- 10 files changed, 28 insertions(+), 14 deletions(-) diff --git a/man/sd_bus_default.xml b/man/sd_bus_default.xml index 06ce1386ac..c218768346 100644 --- a/man/sd_bus_default.xml +++ b/man/sd_bus_default.xml @@ -276,13 +276,20 @@ Returned errors may indicate the following problems: - -EINVAL The specified parameters are invalid. + + -ENOMEDIUM + + The requested bus type is not available because of invalid environment (for example + the user session bus is not available because $XDG_RUNTIME_DIR is not set). + + + -ENOMEM diff --git a/src/busctl/busctl.c b/src/busctl/busctl.c index 4d98941d74..446e474112 100644 --- a/src/busctl/busctl.c +++ b/src/busctl/busctl.c @@ -129,11 +129,11 @@ static int acquire_bus(bool set_monitor, sd_bus **ret) { } } if (r < 0) - return log_error_errno(r, "Failed to set address: %m"); + return bus_log_address_error(r); r = sd_bus_start(bus); if (r < 0) - return log_error_errno(r, "Failed to connect to bus: %m"); + return bus_log_connect_error(r); *ret = TAKE_PTR(bus); diff --git a/src/home/homectl.c b/src/home/homectl.c index 4629499504..486aec066d 100644 --- a/src/home/homectl.c +++ b/src/home/homectl.c @@ -99,7 +99,7 @@ static int acquire_bus(sd_bus **bus) { r = bus_connect_transport(arg_transport, arg_host, false, bus); if (r < 0) - return log_error_errno(r, "Failed to connect to bus: %m"); + return bus_log_connect_error(r); (void) sd_bus_set_allow_interactive_authorization(*bus, arg_ask_password); diff --git a/src/libsystemd/sd-bus/sd-bus.c b/src/libsystemd/sd-bus/sd-bus.c index c602088cf8..daae8aaa6a 100644 --- a/src/libsystemd/sd-bus/sd-bus.c +++ b/src/libsystemd/sd-bus/sd-bus.c @@ -1340,7 +1340,8 @@ int bus_set_address_user(sd_bus *b) { e = secure_getenv("XDG_RUNTIME_DIR"); if (!e) - return -ENOENT; + return log_debug_errno(SYNTHETIC_ERRNO(ENOMEDIUM), + "sd-bus: $XDG_RUNTIME_DIR not set, cannot connect to user bus."); ee = bus_address_escape(e); if (!ee) diff --git a/src/libsystemd/sd-bus/test-bus-cleanup.c b/src/libsystemd/sd-bus/test-bus-cleanup.c index 99d335e3fc..86a2407507 100644 --- a/src/libsystemd/sd-bus/test-bus-cleanup.c +++ b/src/libsystemd/sd-bus/test-bus-cleanup.c @@ -23,7 +23,7 @@ static int test_bus_open(void) { int r; r = sd_bus_open_user(&bus); - if (IN_SET(r, -ECONNREFUSED, -ENOENT)) { + if (IN_SET(r, -ECONNREFUSED, -ENOENT, -ENOMEDIUM)) { r = sd_bus_open_system(&bus); if (IN_SET(r, -ECONNREFUSED, -ENOENT)) return r; diff --git a/src/libsystemd/sd-bus/test-bus-track.c b/src/libsystemd/sd-bus/test-bus-track.c index 68a0010368..5adcf948dd 100644 --- a/src/libsystemd/sd-bus/test-bus-track.c +++ b/src/libsystemd/sd-bus/test-bus-track.c @@ -55,7 +55,7 @@ int main(int argc, char *argv[]) { assert_se(r >= 0); r = sd_bus_open_user(&a); - if (IN_SET(r, -ECONNREFUSED, -ENOENT)) { + if (IN_SET(r, -ECONNREFUSED, -ENOENT, -ENOMEDIUM)) { r = sd_bus_open_system(&a); if (IN_SET(r, -ECONNREFUSED, -ENOENT)) return log_tests_skipped("Failed to connect to bus"); diff --git a/src/login/inhibit.c b/src/login/inhibit.c index e3866eee55..399f70fbc7 100644 --- a/src/login/inhibit.c +++ b/src/login/inhibit.c @@ -282,7 +282,7 @@ static int run(int argc, char *argv[]) { r = sd_bus_default_system(&bus); if (r < 0) - return log_error_errno(r, "Failed to connect to bus: %m"); + return bus_log_connect_error(r); if (arg_action == ACTION_LIST) return print_inhibitors(bus); diff --git a/src/portable/portablectl.c b/src/portable/portablectl.c index 4369dfd156..7a4f60163e 100644 --- a/src/portable/portablectl.c +++ b/src/portable/portablectl.c @@ -178,7 +178,7 @@ static int acquire_bus(sd_bus **bus) { r = bus_connect_transport(arg_transport, arg_host, false, bus); if (r < 0) - return log_error_errno(r, "Failed to connect to bus: %m"); + return bus_log_connect_error(r); (void) sd_bus_set_allow_interactive_authorization(*bus, arg_ask_password); diff --git a/src/shared/bus-util.h b/src/shared/bus-util.h index 9b86f9526e..1a1389fd1e 100644 --- a/src/shared/bus-util.h +++ b/src/shared/bus-util.h @@ -38,13 +38,19 @@ int bus_connect_user_systemd(sd_bus **_bus); int bus_connect_transport(BusTransport transport, const char *host, bool user, sd_bus **bus); int bus_connect_transport_systemd(BusTransport transport, const char *host, bool user, sd_bus **bus); -#define bus_log_connect_error(r) \ - log_error_errno(r, "Failed to create bus connection: %m") +#define bus_log_address_error(r) \ + log_error_errno(r, \ + r == -ENOMEDIUM ? "Failed to set bus address: $DBUS_SESSION_BUS_ADDRESS and $XDG_RUNTIME_DIR not defined" : \ + "Failed to set bus address: %m") +#define bus_log_connect_error(r) \ + log_error_errno(r, \ + r == -ENOMEDIUM ? "Failed to connect to bus: $DBUS_SESSION_BUS_ADDRESS and $XDG_RUNTIME_DIR not defined" : \ + "Failed to connect to bus: %m") -#define bus_log_parse_error(r) \ +#define bus_log_parse_error(r) \ log_error_errno(r, "Failed to parse bus message: %m") -#define bus_log_create_error(r) \ +#define bus_log_create_error(r) \ log_error_errno(r, "Failed to create bus message: %m") int bus_path_encode_unique(sd_bus *b, const char *prefix, const char *sender_id, const char *external_id, char **ret_path); diff --git a/src/systemctl/systemctl-util.c b/src/systemctl/systemctl-util.c index db1888956f..603b1ea4fc 100644 --- a/src/systemctl/systemctl-util.c +++ b/src/systemctl/systemctl-util.c @@ -52,7 +52,7 @@ int acquire_bus(BusFocus focus, sd_bus **ret) { else r = bus_connect_transport(arg_transport, arg_host, user, &buses[focus]); if (r < 0) - return log_error_errno(r, "Failed to connect to bus: %m"); + return bus_log_connect_error(r); (void) sd_bus_set_allow_interactive_authorization(buses[focus], arg_ask_password); }