From 83c942dac2fec09e5077b601438229f7da8e6c33 Mon Sep 17 00:00:00 2001 From: Colin Walters Date: Tue, 15 May 2018 16:32:45 -0400 Subject: [PATCH 1/5] daemon: Load sd unit for callers, log it The high level goal is to render in a better way what caused an update: https://github.com/projectatomic/rpm-ostree/issues/247#issuecomment-386615707 This gets us for Cockpit: `Initiated txn DownloadUpdateRpmDiff for client(dbus:1.28 unit:session-6.scope uid:0): /org/projectatomic/rpmostree1/fedora_atomic` which isn't as good as I'd hoped; I was thinking we'd get `cockpit.service` but actually Cockpit does invocations as a real login for good reason. We get a similar result from the CLI. --- src/daemon/rpmostreed-daemon.c | 83 ++++++++++++++++++++++++++++++---- 1 file changed, 73 insertions(+), 10 deletions(-) diff --git a/src/daemon/rpmostreed-daemon.c b/src/daemon/rpmostreed-daemon.c index 3af221c6c4..2d7ee838f5 100644 --- a/src/daemon/rpmostreed-daemon.c +++ b/src/daemon/rpmostreed-daemon.c @@ -26,6 +26,7 @@ #include #include +#include #include #include @@ -35,6 +36,9 @@ #define DAEMON_CONFIG_GROUP "Daemon" #define EXPERIMENTAL_CONFIG_GROUP "Experimental" +struct RpmOstreeClient; +static struct RpmOstreeClient *client_new (RpmostreedDaemon *self, const char *address); + /** * SECTION: daemon * @title: RpmostreedDaemon @@ -96,26 +100,39 @@ G_DEFINE_TYPE_WITH_CODE (RpmostreedDaemon, rpmostreed_daemon, G_TYPE_OBJECT, struct RpmOstreeClient { char *address; guint name_watch_id; + /* In Rust this'd be Option etc. */ gboolean uid_valid; uid_t uid; + gboolean pid_valid; + pid_t pid; + char *sd_unit; }; static void rpmostree_client_free (struct RpmOstreeClient *client) { + if (!client) + return; g_free (client->address); + g_free (client->sd_unit); g_free (client); } static char * rpmostree_client_to_string (struct RpmOstreeClient *client) { - g_autoptr(GString) buf = g_string_new ("client "); + /* Since DBus addresses have a leading ':', let's avoid another. Yeah it's not + * symmetric, but it does read better. + */ + g_autoptr(GString) buf = g_string_new ("client(dbus"); g_string_append (buf, client->address); + if (client->sd_unit) + g_string_append_printf (buf, " unit:%s", client->sd_unit); if (client->uid_valid) - g_string_append_printf (buf, " (uid %lu)", (unsigned long) client->uid); + g_string_append_printf (buf, " uid:%lu", (unsigned long) client->uid); else - g_string_append (buf, " (unknown uid)"); + g_string_append (buf, " uid:"); + g_string_append_c (buf, ')'); return g_string_free (g_steal_pointer (&buf), FALSE); } @@ -223,16 +240,24 @@ on_active_txn_changed (GObject *object, g_variant_get (active_txn, "(&s&s&s)", &method, &sender, &path); if (*method) { - g_autofree char *client_str = rpmostreed_daemon_client_get_string (self, sender); struct RpmOstreeClient *clientdata = g_hash_table_lookup (self->bus_clients, sender); + struct RpmOstreeClient *clientdata_owned = NULL; + /* If the caller didn't register (e.g. Cockpit doesn't today), + * then let's gather the relevant client info now. + */ + if (!clientdata) + clientdata = clientdata_owned = client_new (self, sender); + g_autofree char *client_str = rpmostree_client_to_string (clientdata); g_autofree char *client_data_msg = NULL; - if (clientdata && clientdata->uid_valid) + if (clientdata->uid_valid) client_data_msg = g_strdup_printf ("CLIENT_UID=%u", clientdata->uid); + /* TODO: convert other client fields to structured log */ sd_journal_send ("MESSAGE_ID=" SD_ID128_FORMAT_STR, SD_ID128_FORMAT_VAL(RPMOSTREE_MESSAGE_TRANSACTION_STARTED), "MESSAGE=Initiated txn %s for %s: %s", method, client_str, path, "BUS_ADDRESS=%s", sender, client_data_msg ?: NULL, NULL); + rpmostree_client_free (clientdata_owned); } } @@ -616,6 +641,48 @@ rpmostreed_get_client_uid (RpmostreedDaemon *self, return TRUE; } +static gboolean +get_client_pid (RpmostreedDaemon *self, + const char *client, + pid_t *out_pid) +{ + g_autoptr(GError) local_error = NULL; + g_autoptr(GVariant) all = g_dbus_proxy_call_sync (self->bus_proxy, + "GetConnectionUnixProcessID", + g_variant_new ("(s)", client), + G_DBUS_CALL_FLAGS_NONE, + 2000, NULL, &local_error); + if (!all) + { + sd_journal_print (LOG_WARNING, "Failed to GetConnectionUnixProcessID for client %s: %s", + client, local_error->message); + return FALSE; + } + + g_variant_get (all, "(u)", out_pid); + return TRUE; +} + +/* Given a DBus address, load metadata for it */ +static struct RpmOstreeClient * +client_new (RpmostreedDaemon *self, const char *address) +{ + struct RpmOstreeClient *client = g_new0 (struct RpmOstreeClient, 1); + client->address = g_strdup (address); + if (rpmostreed_get_client_uid (self, address, &client->uid)) + client->uid_valid = TRUE; + if (get_client_pid (self, address, &client->pid)) + { + client->pid_valid = TRUE; + if (sd_pid_get_user_unit (client->pid, &client->sd_unit) == 0) + {} + else if (sd_pid_get_unit (client->pid, &client->sd_unit) == 0) + {} + } + + return g_steal_pointer (&client); +} + void rpmostreed_daemon_add_client (RpmostreedDaemon *self, const char *client) @@ -623,8 +690,7 @@ rpmostreed_daemon_add_client (RpmostreedDaemon *self, if (g_hash_table_lookup (self->bus_clients, client)) return; - struct RpmOstreeClient *clientdata = g_new0 (struct RpmOstreeClient, 1); - clientdata->address = g_strdup (client); + struct RpmOstreeClient *clientdata = client_new (self, client); clientdata->name_watch_id = g_dbus_connection_signal_subscribe (self->connection, "org.freedesktop.DBus", @@ -637,9 +703,6 @@ rpmostreed_daemon_add_client (RpmostreedDaemon *self, g_object_ref (self), g_object_unref); - if (rpmostreed_get_client_uid (self, client, &clientdata->uid)) - clientdata->uid_valid = TRUE; - g_hash_table_insert (self->bus_clients, (char*)clientdata->address, clientdata); g_autofree char *clientstr = rpmostree_client_to_string (clientdata); sd_journal_print (LOG_INFO, "%s added; new total=%u", clientstr, g_hash_table_size (self->bus_clients)); From abac65fb6025460fa099778d7f6d78bbce78e66c Mon Sep 17 00:00:00 2001 From: Colin Walters Date: Tue, 15 May 2018 17:37:51 -0400 Subject: [PATCH 2/5] daemon: Add an 'id' param to RegisterClient, log it This makes the logs a bit more useful, but the ultimate goal here is to write the originating client `id` to the cached update data, so users know that e.g. `gnome-software` triggered it. --- src/app/rpmostree-dbus-helpers.c | 4 ++++ src/daemon/org.projectatomic.rpmostree1.xml | 2 +- src/daemon/rpmostreed-daemon.c | 20 ++++++++++++++------ src/daemon/rpmostreed-daemon.h | 3 ++- src/daemon/rpmostreed-sysroot.c | 9 ++++++--- 5 files changed, 27 insertions(+), 11 deletions(-) diff --git a/src/app/rpmostree-dbus-helpers.c b/src/app/rpmostree-dbus-helpers.c index c363d57abf..78d069c321 100644 --- a/src/app/rpmostree-dbus-helpers.c +++ b/src/app/rpmostree-dbus-helpers.c @@ -34,6 +34,8 @@ #include "rpmostree-util.h" #include "rpmostree-rpm-util.h" +#define RPMOSTREE_CLI_ID "cli" + void rpmostree_cleanup_peer (GPid *peer_pid) { @@ -211,6 +213,8 @@ rpmostree_load_sysroot (gchar *sysroot, g_autoptr(GError) local_error = NULL; g_autoptr(GVariantBuilder) options_builder = g_variant_builder_new (G_VARIANT_TYPE ("a{sv}")); + g_variant_builder_add (options_builder, "{sv}", "id", + g_variant_new_string (RPMOSTREE_CLI_ID)); g_autoptr(GVariant) res = g_dbus_connection_call_sync (connection, bus_name, sysroot_objpath, "org.projectatomic.rpmostree1.Sysroot", diff --git a/src/daemon/org.projectatomic.rpmostree1.xml b/src/daemon/org.projectatomic.rpmostree1.xml index a8bdf8f5c5..c321537a8e 100644 --- a/src/daemon/org.projectatomic.rpmostree1.xml +++ b/src/daemon/org.projectatomic.rpmostree1.xml @@ -32,7 +32,7 @@ to either invoke methods on the daemon, or monitor status. If no clients are registered, the daemon may exit. - No options are currently defined. + 'name' (type 's') - Package/component name (e.g. `cockpit`, `gnome-software`) --> diff --git a/src/daemon/rpmostreed-daemon.c b/src/daemon/rpmostreed-daemon.c index 2d7ee838f5..843eb2a258 100644 --- a/src/daemon/rpmostreed-daemon.c +++ b/src/daemon/rpmostreed-daemon.c @@ -37,7 +37,7 @@ #define EXPERIMENTAL_CONFIG_GROUP "Experimental" struct RpmOstreeClient; -static struct RpmOstreeClient *client_new (RpmostreedDaemon *self, const char *address); +static struct RpmOstreeClient *client_new (RpmostreedDaemon *self, const char *address, const char *id); /** * SECTION: daemon @@ -98,6 +98,7 @@ G_DEFINE_TYPE_WITH_CODE (RpmostreedDaemon, rpmostreed_daemon, G_TYPE_OBJECT, rpmostreed_daemon_initable_iface_init)) struct RpmOstreeClient { + char *id; char *address; guint name_watch_id; /* In Rust this'd be Option etc. */ @@ -113,6 +114,7 @@ rpmostree_client_free (struct RpmOstreeClient *client) { if (!client) return; + g_free (client->id); g_free (client->address); g_free (client->sd_unit); g_free (client); @@ -121,10 +123,13 @@ rpmostree_client_free (struct RpmOstreeClient *client) static char * rpmostree_client_to_string (struct RpmOstreeClient *client) { + g_autoptr(GString) buf = g_string_new ("client("); + if (client->id) + g_string_append_printf (buf, "id:%s ", client->id); /* Since DBus addresses have a leading ':', let's avoid another. Yeah it's not * symmetric, but it does read better. */ - g_autoptr(GString) buf = g_string_new ("client(dbus"); + g_string_append (buf, "dbus"); g_string_append (buf, client->address); if (client->sd_unit) g_string_append_printf (buf, " unit:%s", client->sd_unit); @@ -246,7 +251,7 @@ on_active_txn_changed (GObject *object, * then let's gather the relevant client info now. */ if (!clientdata) - clientdata = clientdata_owned = client_new (self, sender); + clientdata = clientdata_owned = client_new (self, sender, NULL); g_autofree char *client_str = rpmostree_client_to_string (clientdata); g_autofree char *client_data_msg = NULL; if (clientdata->uid_valid) @@ -665,10 +670,12 @@ get_client_pid (RpmostreedDaemon *self, /* Given a DBus address, load metadata for it */ static struct RpmOstreeClient * -client_new (RpmostreedDaemon *self, const char *address) +client_new (RpmostreedDaemon *self, const char *address, + const char *client_id) { struct RpmOstreeClient *client = g_new0 (struct RpmOstreeClient, 1); client->address = g_strdup (address); + client->id = g_strdup (client_id); if (rpmostreed_get_client_uid (self, address, &client->uid)) client->uid_valid = TRUE; if (get_client_pid (self, address, &client->pid)) @@ -685,12 +692,13 @@ client_new (RpmostreedDaemon *self, const char *address) void rpmostreed_daemon_add_client (RpmostreedDaemon *self, - const char *client) + const char *client, + const char *client_id) { if (g_hash_table_lookup (self->bus_clients, client)) return; - struct RpmOstreeClient *clientdata = client_new (self, client); + struct RpmOstreeClient *clientdata = client_new (self, client, client_id); clientdata->name_watch_id = g_dbus_connection_signal_subscribe (self->connection, "org.freedesktop.DBus", diff --git a/src/daemon/rpmostreed-daemon.h b/src/daemon/rpmostreed-daemon.h index c9b77b5a3f..1269b45312 100644 --- a/src/daemon/rpmostreed-daemon.h +++ b/src/daemon/rpmostreed-daemon.h @@ -34,7 +34,8 @@ gboolean rpmostreed_get_client_uid (RpmostreedDaemon *self, const char *client, uid_t *out_uid); void rpmostreed_daemon_add_client (RpmostreedDaemon *self, - const char *client); + const char *client, + const char *client_id); void rpmostreed_daemon_remove_client (RpmostreedDaemon *self, const char *client); char * rpmostreed_daemon_client_get_string (RpmostreedDaemon *self, diff --git a/src/daemon/rpmostreed-sysroot.c b/src/daemon/rpmostreed-sysroot.c index c0481e2114..17a7967ef6 100644 --- a/src/daemon/rpmostreed-sysroot.c +++ b/src/daemon/rpmostreed-sysroot.c @@ -391,11 +391,14 @@ handle_register_client (RPMOSTreeSysroot *object, GDBusMethodInvocation *invocation, GVariant *arg_options) { - const char *sender; - sender = g_dbus_method_invocation_get_sender (invocation); + const char *sender = g_dbus_method_invocation_get_sender (invocation); g_assert (sender); - rpmostreed_daemon_add_client (rpmostreed_daemon_get (), sender); + g_autoptr(GVariantDict) optdict = g_variant_dict_new (arg_options); + const char *client_id = NULL; + g_variant_dict_lookup (optdict, "id", "&s", &client_id); + + rpmostreed_daemon_add_client (rpmostreed_daemon_get (), sender, client_id); rpmostree_sysroot_complete_register_client (object, invocation); return TRUE; From 912bccf03b1748face3795060f6748d61b479b1d Mon Sep 17 00:00:00 2001 From: Colin Walters Date: Tue, 15 May 2018 17:55:06 -0400 Subject: [PATCH 3/5] fixup! daemon: Add an 'id' param to RegisterClient, log it --- src/daemon/org.projectatomic.rpmostree1.xml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/daemon/org.projectatomic.rpmostree1.xml b/src/daemon/org.projectatomic.rpmostree1.xml index c321537a8e..949afb7b58 100644 --- a/src/daemon/org.projectatomic.rpmostree1.xml +++ b/src/daemon/org.projectatomic.rpmostree1.xml @@ -32,7 +32,7 @@ to either invoke methods on the daemon, or monitor status. If no clients are registered, the daemon may exit. - 'name' (type 's') - Package/component name (e.g. `cockpit`, `gnome-software`) + 'id (type 's') - Package/component name (e.g. `cockpit`, `gnome-software`) --> From 58cd1500f56a5cc58d5634d9fb8612b9484dd5e6 Mon Sep 17 00:00:00 2001 From: Colin Walters Date: Wed, 16 May 2018 13:00:21 -0400 Subject: [PATCH 4/5] fixup! daemon: Add an 'id' param to RegisterClient, log it --- tests/vmcheck/test-autoupdate-check.sh | 8 +++++++- 1 file changed, 7 insertions(+), 1 deletion(-) diff --git a/tests/vmcheck/test-autoupdate-check.sh b/tests/vmcheck/test-autoupdate-check.sh index b071a4f110..cf583a6f06 100755 --- a/tests/vmcheck/test-autoupdate-check.sh +++ b/tests/vmcheck/test-autoupdate-check.sh @@ -82,9 +82,15 @@ vm_rpmostree status | grep 'auto updates enabled (check' # build an *older version* and check that we don't report an update vm_build_rpm layered-cake version 2.1 release 2 -vm_rpmostree upgrade --trigger-automatic-update-policy +cursor=$(vm_get_journal_cursor) +vm_cmd systemctl start rpm-ostree-automatic.service +vm_wait_content_after_cursor $cursor 'Txn AutomaticUpdateTrigger.*successful' vm_rpmostree status -v > out.txt assert_not_file_has_content out.txt "Available update" +# And check the unit name https://github.com/projectatomic/rpm-ostree/pull/1368 +vm_cmd journalctl -u rpm-ostreed --after-cursor > journal.txt +assert_file_has_content journal.txt 'client(id:cli.*unit:rpm-ostreed-automatic.service' +rm -f journal.txt # build a *newer version* and check that we report an update vm_build_rpm layered-cake version 2.1 release 4 From 3eabc9690f1bf21341aa200d32628575b463915e Mon Sep 17 00:00:00 2001 From: Colin Walters Date: Wed, 16 May 2018 14:08:16 -0400 Subject: [PATCH 5/5] fixup! daemon: Add an 'id' param to RegisterClient, log it --- tests/vmcheck/test-autoupdate-check.sh | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/tests/vmcheck/test-autoupdate-check.sh b/tests/vmcheck/test-autoupdate-check.sh index cf583a6f06..8f6893fce5 100755 --- a/tests/vmcheck/test-autoupdate-check.sh +++ b/tests/vmcheck/test-autoupdate-check.sh @@ -88,7 +88,7 @@ vm_wait_content_after_cursor $cursor 'Txn AutomaticUpdateTrigger.*successful' vm_rpmostree status -v > out.txt assert_not_file_has_content out.txt "Available update" # And check the unit name https://github.com/projectatomic/rpm-ostree/pull/1368 -vm_cmd journalctl -u rpm-ostreed --after-cursor > journal.txt +vm_cmd journalctl -u rpm-ostreed --after-cursor ${cursor} > journal.txt assert_file_has_content journal.txt 'client(id:cli.*unit:rpm-ostreed-automatic.service' rm -f journal.txt