Skip to content

Commit

Permalink
Merge pull request #1292 from ejoerns/log-events
Browse files Browse the repository at this point in the history 
Implement Actual Log Events for Configurable Event Logging
  • Loading branch information
@jluebbe
jluebbe committed Dec 20, 2023
2 parents fe2f0ec + dc210c2 commit ba09220
Show file tree
Hide file tree
Showing 4 changed files with 174 additions and 39 deletions.
127 changes: 90 additions & 37 deletions src/install.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -15,6 +15,7 @@
#include "bootchooser.h"
#include "bundle.h"
#include "context.h"
#include "event_log.h"
#include "install.h"
#include "manifest.h"
#include "mark.h"
Expand Down Expand Up @@ -840,20 +841,6 @@ static gboolean launch_and_wait_custom_handler(RaucInstallArgs *args, gchar* bun

r_context_begin_step_weighted("launch_and_wait_custom_handler", "Launching update handler", 0, 6);

/* Allow overriding compatible check by hook */
if (manifest->hooks.install_check) {
run_bundle_hook(manifest, bundledir, "install-check", &ierror);
if (ierror) {
g_propagate_error(error, ierror);
res = FALSE;
goto out;
}
} else if (!verify_compatible(args, manifest, &ierror)) {
g_propagate_error(error, ierror);
res = FALSE;
goto out;
}

handler_name = g_build_filename(bundledir, manifest->handler_name, NULL);
handler_args = g_ptr_array_new_full(0, g_free);
if (manifest->handler_args) {
Expand Down Expand Up @@ -1038,6 +1025,7 @@ static gboolean handle_slot_install_plan(const RaucManifest *manifest, const RIm
r_context_end_step("check_slot", TRUE);

install_args_update(args, "Updating slot %s", plan->target_slot->name);
r_event_log_message(R_EVENT_LOG_TYPE_WRITE_SLOT, "Updating slot %s", plan->target_slot->name);

/* update slot */
if (plan->image->hooks.install) {
Expand Down Expand Up @@ -1111,6 +1099,66 @@ static RaucSlot* get_boot_mark_slot(const GPtrArray *install_plans)
return bootslot;
}

#define MESSAGE_ID_INSTALLATION_STARTED "b05410e8-a933-4538-9cd0-61aab1e9516d"
#define MESSAGE_ID_INSTALLATION_SUCCEEDED "0163db54-68ac-4237-b090-d28490c301ed"
#define MESSAGE_ID_INSTALLATION_FAILED "c48141f7-fd49-443a-afff-862b4809168f"
#define MESSAGE_ID_INSTALLATION_REJECTED "60bea7e4-fea5-49cc-ad68-af457308b13a"

static void log_event_installation_started(RaucInstallArgs *args)
{
g_log_structured(R_EVENT_LOG_DOMAIN, G_LOG_LEVEL_MESSAGE,
"RAUC_EVENT_TYPE", "install",
"MESSAGE_ID", MESSAGE_ID_INSTALLATION_STARTED,
"TRANSACTION_ID", args->transaction,
"MESSAGE", "Installation %.8s started", args->transaction // truncate ID for readability
);
}

/**
* @param args RaucInstallArgs
* @param manifest Manifest
* @param GError Error or NULL
*/
static void log_event_installation_done(RaucInstallArgs *args, RaucManifest *manifest, const GError *error)
{
g_autofree gchar *formatted = NULL;
GLogField fields[] = {
{"MESSAGE", NULL, -1 },
{"MESSAGE_ID", NULL, -1 },
{"GLIB_DOMAIN", R_EVENT_LOG_DOMAIN, -1},
{"RAUC_EVENT_TYPE", "install", -1},
{"BUNDLE_HASH", "", -1},
{"BUNDLE_DESCRIPTION", "", -1},
{"BUNDLE_VERSION", "", -1},
{"TRANSACTION_ID", args->transaction, -1},
};

g_return_if_fail(args);

if (error) {
if (g_error_matches(error, R_INSTALL_ERROR, R_INSTALL_ERROR_REJECTED) ||
g_error_matches(error, R_INSTALL_ERROR, R_INSTALL_ERROR_COMPAT_MISMATCH)) {
formatted = g_strdup_printf("Installation %.8s rejected: %s", args->transaction, error->message);
fields[1].value = MESSAGE_ID_INSTALLATION_REJECTED;
} else {
formatted = g_strdup_printf("Installation %.8s failed: %s", args->transaction, error->message);
fields[1].value = MESSAGE_ID_INSTALLATION_FAILED;
}
} else {
formatted = g_strdup_printf("Installation %.8s succeeded", args->transaction);
fields[1].value = MESSAGE_ID_INSTALLATION_SUCCEEDED;
}

fields[0].value = formatted;
if (manifest) {
fields[4].value = manifest->hash ?: "";
fields[5].value = manifest->update_description ?: "";
fields[6].value = manifest->update_version ?: "";
}

g_log_structured_array(G_LOG_LEVEL_MESSAGE, fields, G_N_ELEMENTS(fields));
}

static gboolean launch_and_wait_default_handler(RaucInstallArgs *args, gchar* bundledir, RaucManifest *manifest, GHashTable *target_group, GError **error)
{
g_autofree gchar *hook_name = NULL;
Expand All @@ -1126,28 +1174,6 @@ static gboolean launch_and_wait_default_handler(RaucInstallArgs *args, gchar* bu

boot_mark_slot = get_boot_mark_slot(install_plans);

/* Allow overriding compatible check by hook */
if (manifest->hooks.install_check) {
run_bundle_hook(manifest, bundledir, "install-check", &ierror);
if (ierror) {
if (g_error_matches(ierror, R_INSTALL_ERROR, R_INSTALL_ERROR_REJECTED)) {
g_propagate_prefixed_error(
error,
ierror,
"Bundle rejected: ");
} else {
g_propagate_prefixed_error(
error,
ierror,
"Install-check hook failed: ");
}
return FALSE;
}
} else if (!verify_compatible(args, manifest, &ierror)) {
g_propagate_error(error, ierror);
return FALSE;
}

if (!pre_install_checks(bundledir, install_plans, target_group, &ierror)) {
g_propagate_error(error, ierror);
return FALSE;
Expand Down Expand Up @@ -1307,7 +1333,7 @@ gboolean do_install_bundle(RaucInstallArgs *args, GError **error)

r_context_begin_step("do_install_bundle", "Installing", 10);

g_message("Installation %s started", args->transaction);
log_event_installation_started(args);

r_context_begin_step("determine_slot_states", "Determining slot states", 0);
res = update_external_mount_points(&ierror);
Expand All @@ -1329,6 +1355,7 @@ gboolean do_install_bundle(RaucInstallArgs *args, GError **error)
}

if (bundle->manifest && bundle->manifest->bundle_format == R_MANIFEST_FORMAT_CRYPT && !bundle->was_encrypted) {
r_event_log_message(R_EVENT_LOG_TYPE_INSTALL, "Installation %.8s rejected: Refusing to install unencrypted crypt bundles", args->transaction);
g_set_error(error, R_INSTALL_ERROR, R_INSTALL_ERROR_REJECTED, "Refusing to install unencrypted crypt bundles");
res = FALSE;
goto out;
Expand Down Expand Up @@ -1364,6 +1391,30 @@ gboolean do_install_bundle(RaucInstallArgs *args, GError **error)
}
}

/* Allow overriding compatible check by hook */
if (bundle->manifest->hooks.install_check) {
run_bundle_hook(bundle->manifest, bundle->mount_point, "install-check", &ierror);
if (ierror) {
res = FALSE;
if (g_error_matches(ierror, R_INSTALL_ERROR, R_INSTALL_ERROR_REJECTED)) {
g_propagate_prefixed_error(
error,
ierror,
"Bundle rejected: ");
} else {
g_propagate_prefixed_error(
error,
ierror,
"Install-check hook failed: ");
}
goto umount;
}
} else if (!verify_compatible(args, bundle->manifest, &ierror)) {
res = FALSE;
g_propagate_error(error, ierror);
goto umount;
}

if (bundle->manifest->handler_name) {
g_message("Using custom handler: %s", bundle->manifest->handler_name);
res = launch_and_wait_custom_handler(args, bundle->mount_point, bundle->manifest, target_group, &ierror);
Expand Down Expand Up @@ -1396,6 +1447,8 @@ gboolean do_install_bundle(RaucInstallArgs *args, GError **error)
r_context()->install_info->mounted_bundle = NULL;

out:
log_event_installation_done(args, bundle ? bundle->manifest : NULL, error ? *error : NULL);

r_context_end_step("do_install_bundle", res);

return res;
Expand Down
33 changes: 32 additions & 1 deletion src/main.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -2003,6 +2003,33 @@ static gboolean status_start(int argc, char **argv)
return TRUE;
}

#define MESSAGE_ID_BOOTED "e60e0add-d345-4cb8-b796-eae0d497af96"

static void r_event_log_booted(const RaucSlot *booted_slot)
{
g_autofree gchar *message = NULL;
GLogField fields[] = {
{"MESSAGE", NULL, -1 },
{"MESSAGE_ID", MESSAGE_ID_BOOTED, -1 },
{"GLIB_DOMAIN", R_EVENT_LOG_DOMAIN, -1},
{"RAUC_EVENT_TYPE", "boot", -1},
{"BOOT_ID", NULL, -1},
{"BUNDLE_HASH", NULL, -1},
};

g_return_if_fail(booted_slot);

message = g_strdup_printf("Booted into %s (%s)", booted_slot->name, booted_slot->bootname);
fields[0].value = message;
fields[4].value = r_context()->boot_id;
if (booted_slot->status && booted_slot->status->bundle_hash) {
fields[5].value = booted_slot->status->bundle_hash;
} else {
fields[5].value = "unknown";
}
g_log_structured_array(G_LOG_LEVEL_INFO, fields, G_N_ELEMENTS(fields));
}

G_GNUC_UNUSED
static void create_run_links(void)
{
Expand Down Expand Up @@ -2049,11 +2076,14 @@ static gboolean service_start(int argc, char **argv)
/* Boot ID-based system reboot vs service restart detection */
if (g_strcmp0(r_context()->system_status->boot_id, r_context()->boot_id) == 0) {
g_message("Restarted RAUC service");
r_event_log_message(R_EVENT_LOG_TYPE_SERVICE, "Service restarted");
} else {
RaucSlot *booted_slot = r_slot_find_by_device(r_context()->config->slots, r_context()->bootslot);
if (!booted_slot)
booted_slot = r_slot_find_by_bootname(r_context()->config->slots, r_context()->bootslot);
g_message("Booted into %s (%s)", booted_slot->name, booted_slot->bootname);
r_slot_status_load(booted_slot);

r_event_log_booted(booted_slot);

/* update boot ID */
g_free(r_context()->system_status->boot_id);
Expand All @@ -2066,6 +2096,7 @@ static gboolean service_start(int argc, char **argv)
}
} else {
g_message("Started RAUC service");
r_event_log_message(R_EVENT_LOG_TYPE_SERVICE, "Service started");
}

r_exit_status = r_service_run() ? 0 : 1;
Expand Down
51 changes: 51 additions & 0 deletions src/mark.c
View file
Original file line number Diff line number Diff line change
@@ -1,4 +1,5 @@
#include "bootchooser.h"
#include "event_log.h"
#include "context.h"
#include "install.h"
#include "mark.h"
Expand Down Expand Up @@ -75,6 +76,50 @@ static RaucSlot* get_slot_by_identifier(const gchar *identifier, GError **error)
return slot;
}

#define MESSAGE_ID_MARKED_ACTIVE "8b5e7435-e105-4d86-8582-78e7544fe6da"
#define MESSAGE_ID_MARKED_GOOD "3304e15a-7a9a-4478-85eb-208ba7ae3a05"
#define MESSAGE_ID_MARKED_BAD "ccb0e584-a470-43d7-a531-6994bce77ae5"

static void r_event_log_mark_active(RaucSlot *slot)
{
g_return_if_fail(slot);

g_log_structured(R_EVENT_LOG_DOMAIN, G_LOG_LEVEL_MESSAGE,
"RAUC_EVENT_TYPE", "mark",
"MESSAGE_ID", MESSAGE_ID_MARKED_ACTIVE,
"SLOT_NAME", slot->name,
"SLOT_BOOTNAME", slot->bootname ?: "",
"BUNDLE_HASH", slot->status->bundle_hash ?: "",
"MESSAGE", "Marked slot %s as active", slot->name
);
}

static void r_event_log_mark_good(RaucSlot *slot)
{
g_return_if_fail(slot);

g_log_structured(R_EVENT_LOG_DOMAIN, G_LOG_LEVEL_MESSAGE,
"RAUC_EVENT_TYPE", "mark",
"MESSAGE_ID", MESSAGE_ID_MARKED_GOOD,
"SLOT_NAME", slot->name,
"SLOT_BOOTNAME", slot->bootname ?: "",
"MESSAGE", "Marked slot %s as good", slot->name
);
}

static void r_event_log_mark_bad(RaucSlot *slot)
{
g_return_if_fail(slot);

g_log_structured(R_EVENT_LOG_DOMAIN, G_LOG_LEVEL_MESSAGE,
"RAUC_EVENT_TYPE", "mark",
"MESSAGE_ID", MESSAGE_ID_MARKED_BAD,
"SLOT_NAME", slot->name,
"SLOT_BOOTNAME", slot->bootname ?: "",
"MESSAGE", "Marked slot %s as bad", slot->name
);
}

gboolean r_mark_active(RaucSlot *slot, GError **error)
{
RaucSlotStatus *slot_state;
Expand All @@ -94,6 +139,8 @@ gboolean r_mark_active(RaucSlot *slot, GError **error)
return FALSE;
}

r_event_log_mark_active(slot);

g_free(slot_state->activated_timestamp);
now = g_date_time_new_now_utc();
slot_state->activated_timestamp = g_date_time_format(now, "%Y-%m-%dT%H:%M:%SZ");
Expand Down Expand Up @@ -121,6 +168,8 @@ gboolean r_mark_good(RaucSlot *slot, GError **error)
return FALSE;
}

r_event_log_mark_good(slot);

return TRUE;
}

Expand All @@ -138,6 +187,8 @@ gboolean r_mark_bad(RaucSlot *slot, GError **error)
return FALSE;
}

r_event_log_mark_bad(slot);

return TRUE;
}

Expand Down
2 changes: 1 addition & 1 deletion test/install.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -1185,7 +1185,7 @@ static void install_test_bundle_hook_install_check(InstallFixture *fixture,
args->notify = install_notify;
args->cleanup = install_cleanup;
g_assert_false(do_install_bundle(args, &ierror));
g_assert_cmpstr(ierror->message, ==, "Installation error: Bundle rejected: Hook returned: No, I won't install this!");
g_assert_cmpstr(ierror->message, ==, "Bundle rejected: Hook returned: No, I won't install this!");

args->status_result = 0;
args->cleanup(args);
Expand Down

0 comments on commit ba09220

Please sign in to comment.