From 6bcc12325b0b65a46b2d279c22045fa01fcbc715 Mon Sep 17 00:00:00 2001 From: Lennart Poettering Date: Thu, 23 Nov 2023 18:13:51 +0100 Subject: [PATCH 1/4] varlink: switch various log calls to the local log helpers Most code in varlink.c got that right, but some didn't. Fix that. --- src/shared/varlink.c | 42 +++++++++++++++++++++--------------------- 1 file changed, 21 insertions(+), 21 deletions(-) diff --git a/src/shared/varlink.c b/src/shared/varlink.c index 749b644a56..47528b3e70 100644 --- a/src/shared/varlink.c +++ b/src/shared/varlink.c @@ -1006,7 +1006,7 @@ static int varlink_dispatch_local_error(Varlink *v, const char *error) { r = v->reply_callback(v, NULL, error, VARLINK_REPLY_ERROR|VARLINK_REPLY_LOCAL, v->userdata); if (r < 0) - log_debug_errno(r, "Reply callback returned error, ignoring: %m"); + varlink_log_errno(v, r, "Reply callback returned error, ignoring: %m"); return 1; } @@ -1132,7 +1132,7 @@ static int varlink_dispatch_reply(Varlink *v) { if (v->reply_callback) { r = v->reply_callback(v, parameters, error, flags, v->userdata); if (r < 0) - log_debug_errno(r, "Reply callback returned error, ignoring: %m"); + varlink_log_errno(v, r, "Reply callback returned error, ignoring: %m"); } varlink_clear_current(v); @@ -1327,13 +1327,13 @@ static int varlink_dispatch_method(Varlink *v) { v->current_method = hashmap_get(v->server->symbols, method); if (!v->current_method) - log_debug("No interface description defined for method '%s', not validating.", method); + varlink_log(v, "No interface description defined for method '%s', not validating.", method); else { const char *bad_field; r = varlink_idl_validate_method_call(v->current_method, parameters, &bad_field); if (r < 0) { - log_debug_errno(r, "Parameters for method %s() didn't pass validation on field '%s': %m", method, strna(bad_field)); + varlink_log_errno(v, r, "Parameters for method %s() didn't pass validation on field '%s': %m", method, strna(bad_field)); if (!FLAGS_SET(flags, VARLINK_METHOD_ONEWAY)) { r = varlink_errorb(v, VARLINK_ERROR_INVALID_PARAMETER, JSON_BUILD_OBJECT(JSON_BUILD_PAIR_STRING("parameter", bad_field))); @@ -1347,7 +1347,7 @@ static int varlink_dispatch_method(Varlink *v) { if (!invalid) { r = callback(v, parameters, flags, v->userdata); if (r < 0) { - log_debug_errno(r, "Callback for %s returned error: %m", method); + varlink_log_errno(v, r, "Callback for %s returned error: %m", method); /* We got an error back from the callback. Propagate it to the client if the method call remains unanswered. */ if (v->state == VARLINK_PROCESSED_METHOD) @@ -2272,7 +2272,7 @@ int varlink_reply(Varlink *v, JsonVariant *parameters) { r = varlink_idl_validate_method_reply(v->current_method, parameters, &bad_field); if (r < 0) - log_debug_errno(r, "Return parameters for method reply %s() didn't pass validation on field '%s', ignoring: %m", v->current_method->name, strna(bad_field)); + varlink_log_errno(v, r, "Return parameters for method reply %s() didn't pass validation on field '%s', ignoring: %m", v->current_method->name, strna(bad_field)); } r = varlink_enqueue_json(v, m); @@ -2343,13 +2343,13 @@ int varlink_error(Varlink *v, const char *error_id, JsonVariant *parameters) { VarlinkSymbol *symbol = hashmap_get(v->server->symbols, error_id); if (!symbol) - log_debug("No interface description defined for error '%s', not validating.", error_id); + varlink_log(v, "No interface description defined for error '%s', not validating.", error_id); else { const char *bad_field = NULL; r = varlink_idl_validate_error(symbol, parameters, &bad_field); if (r < 0) - log_debug_errno(r, "Parameters for error %s didn't pass validation on field '%s', ignoring: %m", error_id, strna(bad_field)); + varlink_log_errno(v, r, "Parameters for error %s didn't pass validation on field '%s', ignoring: %m", error_id, strna(bad_field)); } r = varlink_enqueue_json(v, m); @@ -2464,7 +2464,7 @@ int varlink_notify(Varlink *v, JsonVariant *parameters) { r = varlink_idl_validate_method_reply(v->current_method, parameters, &bad_field); if (r < 0) - log_debug_errno(r, "Return parameters for method reply %s() didn't pass validation on field '%s', ignoring: %m", v->current_method->name, strna(bad_field)); + varlink_log_errno(v, r, "Return parameters for method reply %s() didn't pass validation on field '%s', ignoring: %m", v->current_method->name, strna(bad_field)); } r = varlink_enqueue_json(v, m); @@ -3023,7 +3023,7 @@ static int count_connection(VarlinkServer *server, const struct ucred *ucred) { if (FLAGS_SET(server->flags, VARLINK_SERVER_ACCOUNT_UID)) { r = hashmap_ensure_allocated(&server->by_uid, NULL); if (r < 0) - return log_debug_errno(r, "Failed to allocate UID hash table: %m"); + return varlink_server_log_errno(server, r, "Failed to allocate UID hash table: %m"); c = PTR_TO_UINT(hashmap_get(server->by_uid, UID_TO_PTR(ucred->uid))); @@ -3032,7 +3032,7 @@ static int count_connection(VarlinkServer *server, const struct ucred *ucred) { r = hashmap_replace(server->by_uid, UID_TO_PTR(ucred->uid), UINT_TO_PTR(c + 1)); if (r < 0) - return log_debug_errno(r, "Failed to increment counter in UID hash table: %m"); + return varlink_server_log_errno(server, r, "Failed to increment counter in UID hash table: %m"); } return 0; @@ -3472,7 +3472,7 @@ int varlink_server_bind_method(VarlinkServer *s, const char *method, VarlinkMeth if (varlink_symbol_in_interface(method, "org.varlink.service") || varlink_symbol_in_interface(method, "io.systemd")) - return log_debug_errno(SYNTHETIC_ERRNO(EEXIST), "Cannot bind server to '%s'.", method); + return varlink_server_log_errno(s, SYNTHETIC_ERRNO(EEXIST), "Cannot bind server to '%s'.", method); m = strdup(method); if (!m) @@ -3482,7 +3482,7 @@ int varlink_server_bind_method(VarlinkServer *s, const char *method, VarlinkMeth if (r == -ENOMEM) return log_oom_debug(); if (r < 0) - return log_debug_errno(r, "Failed to register callback: %m"); + return varlink_server_log_errno(s, r, "Failed to register callback: %m"); if (r > 0) TAKE_PTR(m); @@ -3519,7 +3519,7 @@ int varlink_server_bind_connect(VarlinkServer *s, VarlinkConnect callback) { assert_return(s, -EINVAL); if (callback && s->connect_callback && callback != s->connect_callback) - return log_debug_errno(SYNTHETIC_ERRNO(EBUSY), "A different callback was already set."); + return varlink_server_log_errno(s, SYNTHETIC_ERRNO(EBUSY), "A different callback was already set."); s->connect_callback = callback; return 0; @@ -3529,7 +3529,7 @@ int varlink_server_bind_disconnect(VarlinkServer *s, VarlinkDisconnect callback) assert_return(s, -EINVAL); if (callback && s->disconnect_callback && callback != s->disconnect_callback) - return log_debug_errno(SYNTHETIC_ERRNO(EBUSY), "A different callback was already set."); + return varlink_server_log_errno(s, SYNTHETIC_ERRNO(EBUSY), "A different callback was already set."); s->disconnect_callback = callback; return 0; @@ -3543,7 +3543,7 @@ int varlink_server_add_interface(VarlinkServer *s, const VarlinkInterface *inter assert_return(interface->name, -EINVAL); if (hashmap_contains(s->interfaces, interface->name)) - return log_debug_errno(SYNTHETIC_ERRNO(EEXIST), "Duplicate registration of interface '%s'.", interface->name); + return varlink_server_log_errno(s, SYNTHETIC_ERRNO(EEXIST), "Duplicate registration of interface '%s'.", interface->name); r = hashmap_ensure_put(&s->interfaces, &string_hash_ops, interface->name, (void*) interface); if (r < 0) @@ -3696,11 +3696,11 @@ int varlink_server_deserialize_one(VarlinkServer *s, const char *value, FDSet *f return log_oom_debug(); if (v[n] != ' ') - return log_debug_errno(SYNTHETIC_ERRNO(EINVAL), + return varlink_server_log_errno(s, SYNTHETIC_ERRNO(EINVAL), "Failed to deserialize VarlinkServerSocket: %s: %m", value); v = startswith(v + n + 1, "varlink-server-socket-fd="); if (!v) - return log_debug_errno(SYNTHETIC_ERRNO(EINVAL), + return varlink_server_log_errno(s, SYNTHETIC_ERRNO(EINVAL), "Failed to deserialize VarlinkServerSocket fd %s: %m", value); n = strcspn(v, " "); @@ -3708,9 +3708,9 @@ int varlink_server_deserialize_one(VarlinkServer *s, const char *value, FDSet *f fd = parse_fd(buf); if (fd < 0) - return log_debug_errno(fd, "Unable to parse VarlinkServerSocket varlink-server-socket-fd=%s: %m", buf); + return varlink_server_log_errno(s, fd, "Unable to parse VarlinkServerSocket varlink-server-socket-fd=%s: %m", buf); if (!fdset_contains(fds, fd)) - return log_debug_errno(SYNTHETIC_ERRNO(EBADF), + return varlink_server_log_errno(s, SYNTHETIC_ERRNO(EBADF), "VarlinkServerSocket varlink-server-socket-fd= has unknown fd %d: %m", fd); ss = new(VarlinkServerSocket, 1); @@ -3725,7 +3725,7 @@ int varlink_server_deserialize_one(VarlinkServer *s, const char *value, FDSet *f r = varlink_server_add_socket_event_source(s, ss, SD_EVENT_PRIORITY_NORMAL); if (r < 0) - return log_debug_errno(r, "Failed to add VarlinkServerSocket event source to the event loop: %m"); + return varlink_server_log_errno(s, r, "Failed to add VarlinkServerSocket event source to the event loop: %m"); LIST_PREPEND(sockets, s->sockets, TAKE_PTR(ss)); return 0; From c931c871aa93c689f42ecd3078d3aad87f1d04bf Mon Sep 17 00:00:00 2001 From: Lennart Poettering Date: Thu, 23 Nov 2023 18:15:14 +0100 Subject: [PATCH 2/4] varlink: never turn method call handler errors into connection errors Let's make sure method call handlers failing will result in that very method call failing but not the whole connection. We mostly got that right, except for "oneway" calls where the method reply is supposed to be eaten up, but wasn't. Fix that. --- src/shared/varlink.c | 9 +++------ 1 file changed, 3 insertions(+), 6 deletions(-) diff --git a/src/shared/varlink.c b/src/shared/varlink.c index 47528b3e70..3f022e88bd 100644 --- a/src/shared/varlink.c +++ b/src/shared/varlink.c @@ -1350,9 +1350,7 @@ static int varlink_dispatch_method(Varlink *v) { varlink_log_errno(v, r, "Callback for %s returned error: %m", method); /* We got an error back from the callback. Propagate it to the client if the method call remains unanswered. */ - if (v->state == VARLINK_PROCESSED_METHOD) - r = 0; /* already processed */ - else if (!FLAGS_SET(flags, VARLINK_METHOD_ONEWAY)) { + if (v->state != VARLINK_PROCESSED_METHOD && !FLAGS_SET(flags, VARLINK_METHOD_ONEWAY)) { r = varlink_error_errno(v, r); if (r < 0) return r; @@ -1363,8 +1361,7 @@ static int varlink_dispatch_method(Varlink *v) { r = varlink_errorb(v, VARLINK_ERROR_METHOD_NOT_FOUND, JSON_BUILD_OBJECT(JSON_BUILD_PAIR("method", JSON_BUILD_STRING(method)))); if (r < 0) return r; - } else - r = 0; + } switch (v->state) { @@ -1386,7 +1383,7 @@ static int varlink_dispatch_method(Varlink *v) { assert_not_reached(); } - return r; + return 1; invalid: r = -EINVAL; From a13518231af95e2c771b8c981068e4138ea320e3 Mon Sep 17 00:00:00 2001 From: Lennart Poettering Date: Thu, 23 Nov 2023 18:23:40 +0100 Subject: [PATCH 3/4] varlink: add an extra assert encoding our assumption that ucred is valid here --- src/shared/varlink.c | 2 ++ 1 file changed, 2 insertions(+) diff --git a/src/shared/varlink.c b/src/shared/varlink.c index 3f022e88bd..52a946f8c9 100644 --- a/src/shared/varlink.c +++ b/src/shared/varlink.c @@ -3018,6 +3018,8 @@ static int count_connection(VarlinkServer *server, const struct ucred *ucred) { server->n_connections++; if (FLAGS_SET(server->flags, VARLINK_SERVER_ACCOUNT_UID)) { + assert(uid_is_valid(ucred->uid)); + r = hashmap_ensure_allocated(&server->by_uid, NULL); if (r < 0) return varlink_server_log_errno(server, r, "Failed to allocate UID hash table: %m"); From 7ff96ce383512ab02bed92f75e2afb447bd38427 Mon Sep 17 00:00:00 2001 From: Lennart Poettering Date: Fri, 24 Nov 2023 16:11:46 +0100 Subject: [PATCH 4/4] varlink: check state rather than flags to determine whether it makes sense to reply We already checked the flags before, and updated the state accordingly, hence let's only look at the state afterwards. This allows us to use the same expressions for all cases where we want to reply automatically to clients. --- src/shared/varlink.c | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/src/shared/varlink.c b/src/shared/varlink.c index 52a946f8c9..3735c20773 100644 --- a/src/shared/varlink.c +++ b/src/shared/varlink.c @@ -1335,7 +1335,7 @@ static int varlink_dispatch_method(Varlink *v) { if (r < 0) { varlink_log_errno(v, r, "Parameters for method %s() didn't pass validation on field '%s': %m", method, strna(bad_field)); - if (!FLAGS_SET(flags, VARLINK_METHOD_ONEWAY)) { + if (IN_SET(v->state, VARLINK_PROCESSING_METHOD, VARLINK_PROCESSING_METHOD_MORE)) { r = varlink_errorb(v, VARLINK_ERROR_INVALID_PARAMETER, JSON_BUILD_OBJECT(JSON_BUILD_PAIR_STRING("parameter", bad_field))); if (r < 0) return r; @@ -1350,14 +1350,14 @@ static int varlink_dispatch_method(Varlink *v) { varlink_log_errno(v, r, "Callback for %s returned error: %m", method); /* We got an error back from the callback. Propagate it to the client if the method call remains unanswered. */ - if (v->state != VARLINK_PROCESSED_METHOD && !FLAGS_SET(flags, VARLINK_METHOD_ONEWAY)) { + if (IN_SET(v->state, VARLINK_PROCESSING_METHOD, VARLINK_PROCESSING_METHOD_MORE)) { r = varlink_error_errno(v, r); if (r < 0) return r; } } } - } else if (!FLAGS_SET(flags, VARLINK_METHOD_ONEWAY)) { + } else if (IN_SET(v->state, VARLINK_PROCESSING_METHOD, VARLINK_PROCESSING_METHOD_MORE)) { r = varlink_errorb(v, VARLINK_ERROR_METHOD_NOT_FOUND, JSON_BUILD_OBJECT(JSON_BUILD_PAIR("method", JSON_BUILD_STRING(method)))); if (r < 0) return r;