X-Git-Url: http://www.chiark.greenend.org.uk/ucgi/~ianmdlvl/git?p=elogind.git;a=blobdiff_plain;f=src%2Fcore%2Fjob.c;h=31ab11880ef0fa1a52b4d4c6a9c628c6d8a56928;hp=90091c298f343f332596f583452f1404664b7037;hb=38c888a4049438f2521edf38d55f937b53d17a9e;hpb=66aa6f7fbb16f441b28196c46a8c3fd60ed39d1b diff --git a/src/core/job.c b/src/core/job.c index 90091c298..31ab11880 100644 --- a/src/core/job.c +++ b/src/core/job.c @@ -24,6 +24,8 @@ #include #include +#include "systemd/sd-id128.h" +#include "systemd/sd-messages.h" #include "set.h" #include "unit.h" #include "macro.h" @@ -178,15 +180,16 @@ Job* job_install(Job *j) { if (uj) { if (j->type != JOB_NOP && job_type_is_conflicting(uj->type, j->type)) - job_finish_and_invalidate(uj, JOB_CANCELED, true); + job_finish_and_invalidate(uj, JOB_CANCELED, false); else { /* not conflicting, i.e. mergeable */ if (j->type == JOB_NOP || uj->state == JOB_WAITING || (job_type_allows_late_merge(j->type) && job_type_is_superset(uj->type, j->type))) { job_merge_into_installed(uj, j); - log_debug("Merged into installed job %s/%s as %u", - uj->unit->id, job_type_to_string(uj->type), (unsigned) uj->id); + log_debug_unit(uj->unit->id, + "Merged into installed job %s/%s as %u", + uj->unit->id, job_type_to_string(uj->type), (unsigned) uj->id); return uj; } else { /* already running and not safe to merge into */ @@ -194,8 +197,9 @@ Job* job_install(Job *j) { /* XXX It should be safer to queue j to run after uj finishes, but it is * not currently possible to have more than one installed job per unit. */ job_merge_into_installed(uj, j); - log_debug("Merged into running job, re-running: %s/%s as %u", - uj->unit->id, job_type_to_string(uj->type), (unsigned) uj->id); + log_debug_unit(uj->unit->id, + "Merged into running job, re-running: %s/%s as %u", + uj->unit->id, job_type_to_string(uj->type), (unsigned) uj->id); uj->state = JOB_WAITING; return uj; } @@ -206,7 +210,9 @@ Job* job_install(Job *j) { *pj = j; j->installed = true; j->manager->n_installed_jobs ++; - log_debug("Installed new job %s/%s as %u", j->unit->id, job_type_to_string(j->type), (unsigned) j->id); + log_debug_unit(j->unit->id, + "Installed new job %s/%s as %u", + j->unit->id, job_type_to_string(j->type), (unsigned) j->id); return j; } @@ -223,12 +229,16 @@ int job_install_deserialized(Job *j) { pj = (j->type == JOB_NOP) ? &j->unit->nop_job : &j->unit->job; if (*pj) { - log_debug("Unit %s already has a job installed. Not installing deserialized job.", j->unit->id); + log_debug_unit(j->unit->id, + "Unit %s already has a job installed. Not installing deserialized job.", + j->unit->id); return -EEXIST; } *pj = j; j->installed = true; - log_debug("Reinstalled deserialized job %s/%s as %u", j->unit->id, job_type_to_string(j->type), (unsigned) j->id); + log_debug_unit(j->unit->id, + "Reinstalled deserialized job %s/%s as %u", + j->unit->id, job_type_to_string(j->type), (unsigned) j->id); return 0; } @@ -455,9 +465,10 @@ bool job_is_runnable(Job *j) { } static void job_change_type(Job *j, JobType newtype) { - log_debug("Converting job %s/%s -> %s/%s", - j->unit->id, job_type_to_string(j->type), - j->unit->id, job_type_to_string(newtype)); + log_debug_unit(j->unit->id, + "Converting job %s/%s -> %s/%s", + j->unit->id, job_type_to_string(j->type), + j->unit->id, job_type_to_string(newtype)); j->type = newtype; } @@ -549,54 +560,184 @@ int job_run_and_invalidate(Job *j) { return r; } +static const char *job_get_status_message_format(Unit *u, JobType t, JobResult result) { + const UnitStatusMessageFormats *format_table; + + assert(u); + assert(t >= 0); + assert(t < _JOB_TYPE_MAX); + + format_table = &UNIT_VTABLE(u)->status_message_formats; + if (!format_table) + return NULL; + + if (t == JOB_START) + return format_table->finished_start_job[result]; + else if (t == JOB_STOP || t == JOB_RESTART) + return format_table->finished_stop_job[result]; + + return NULL; +} + +static const char *job_get_status_message_format_try_harder(Unit *u, JobType t, JobResult result) { + const char *format; + + assert(u); + assert(t >= 0); + assert(t < _JOB_TYPE_MAX); + + format = job_get_status_message_format(u, t, result); + if (format) + return format; + + /* Return generic strings */ + if (t == JOB_START) { + if (result == JOB_DONE) + return "Started %s."; + else if (result == JOB_FAILED) + return "Failed to start %s."; + else if (result == JOB_DEPENDENCY) + return "Dependency failed for %s."; + else if (result == JOB_TIMEOUT) + return "Timed out starting %s."; + } else if (t == JOB_STOP || t == JOB_RESTART) { + if (result == JOB_DONE) + return "Stopped %s."; + else if (result == JOB_FAILED) + return "Stopped (with error) %s."; + else if (result == JOB_TIMEOUT) + return "Timed out stoppping %s."; + } else if (t == JOB_RELOAD) { + if (result == JOB_DONE) + return "Reloaded %s."; + else if (result == JOB_FAILED) + return "Reload failed for %s."; + else if (result == JOB_TIMEOUT) + return "Timed out reloading %s."; + } + + return NULL; +} + static void job_print_status_message(Unit *u, JobType t, JobResult result) { + const char *format; + assert(u); + assert(t >= 0); + assert(t < _JOB_TYPE_MAX); if (t == JOB_START) { + format = job_get_status_message_format(u, t, result); + if (!format) + return; switch (result) { case JOB_DONE: if (u->condition_result) - unit_status_printf(u, ANSI_HIGHLIGHT_GREEN_ON " OK " ANSI_HIGHLIGHT_OFF, "Started %s.", unit_description(u)); + unit_status_printf(u, ANSI_HIGHLIGHT_GREEN_ON " OK " ANSI_HIGHLIGHT_OFF, format, unit_description(u)); break; case JOB_FAILED: - unit_status_printf(u, ANSI_HIGHLIGHT_RED_ON "FAILED" ANSI_HIGHLIGHT_OFF, "Failed to start %s.", unit_description(u)); + unit_status_printf(u, ANSI_HIGHLIGHT_RED_ON "FAILED" ANSI_HIGHLIGHT_OFF, format, unit_description(u)); unit_status_printf(u, NULL, "See 'systemctl status %s' for details.", u->id); break; case JOB_DEPENDENCY: - unit_status_printf(u, ANSI_HIGHLIGHT_RED_ON " ABORT" ANSI_HIGHLIGHT_OFF, "Dependency failed. Aborted start of %s.", unit_description(u)); + unit_status_printf(u, ANSI_HIGHLIGHT_YELLOW_ON "DEPEND" ANSI_HIGHLIGHT_OFF, format, unit_description(u)); break; case JOB_TIMEOUT: - unit_status_printf(u, ANSI_HIGHLIGHT_RED_ON " TIME " ANSI_HIGHLIGHT_OFF, "Timed out starting %s.", unit_description(u)); + unit_status_printf(u, ANSI_HIGHLIGHT_RED_ON " TIME " ANSI_HIGHLIGHT_OFF, format, unit_description(u)); break; default: ; } - } else if (t == JOB_STOP) { + } else if (t == JOB_STOP || t == JOB_RESTART) { + + format = job_get_status_message_format(u, t, result); + if (!format) + return; switch (result) { case JOB_TIMEOUT: - unit_status_printf(u, ANSI_HIGHLIGHT_RED_ON " TIME " ANSI_HIGHLIGHT_OFF, "Timed out stopping %s.", unit_description(u)); + unit_status_printf(u, ANSI_HIGHLIGHT_RED_ON " TIME " ANSI_HIGHLIGHT_OFF, format, unit_description(u)); break; case JOB_DONE: case JOB_FAILED: - unit_status_printf(u, ANSI_HIGHLIGHT_GREEN_ON " OK " ANSI_HIGHLIGHT_OFF, "Stopped %s.", unit_description(u)); + unit_status_printf(u, ANSI_HIGHLIGHT_GREEN_ON " OK " ANSI_HIGHLIGHT_OFF, format, unit_description(u)); break; default: ; } + + } else if (t == JOB_VERIFY_ACTIVE) { + + /* When verify-active detects the unit is inactive, report it. + * Most likely a DEPEND warning from a requisiting unit will + * occur next and it's nice to see what was requisited. */ + if (result == JOB_SKIPPED) + unit_status_printf(u, ANSI_HIGHLIGHT_ON " INFO " ANSI_HIGHLIGHT_OFF, "%s is not active.", unit_description(u)); } } +#pragma GCC diagnostic push +#pragma GCC diagnostic ignored "-Wformat-nonliteral" +static void job_log_status_message(Unit *u, JobType t, JobResult result) { + const char *format; + char buf[LINE_MAX]; + + assert(u); + assert(t >= 0); + assert(t < _JOB_TYPE_MAX); + + /* Skip this if it goes to the console. since we already print + * to the console anyway... */ + + if (log_on_console()) + return; + + format = job_get_status_message_format_try_harder(u, t, result); + if (!format) + return; + + snprintf(buf, sizeof(buf), format, unit_description(u)); + char_array_0(buf); + + if (t == JOB_START) { + sd_id128_t mid; + + mid = result == JOB_DONE ? SD_MESSAGE_UNIT_STARTED : SD_MESSAGE_UNIT_FAILED; + log_struct(result == JOB_DONE ? LOG_INFO : LOG_ERR, + MESSAGE_ID(mid), + "UNIT=%s", u->id, + "RESULT=%s", job_result_to_string(result), + "MESSAGE=%s", buf, + NULL); + + } else if (t == JOB_STOP) + log_struct(result == JOB_DONE ? LOG_INFO : LOG_ERR, + MESSAGE_ID(SD_MESSAGE_UNIT_STOPPED), + "UNIT=%s", u->id, + "RESULT=%s", job_result_to_string(result), + "MESSAGE=%s", buf, + NULL); + + else if (t == JOB_RELOAD) + log_struct(result == JOB_DONE ? LOG_INFO : LOG_ERR, + MESSAGE_ID(SD_MESSAGE_UNIT_RELOADED), + "UNIT=%s", u->id, + "RESULT=%s", job_result_to_string(result), + "MESSAGE=%s", buf, + NULL); +} +#pragma GCC diagnostic pop + int job_finish_and_invalidate(Job *j, JobResult result, bool recursive) { Unit *u; Unit *other; @@ -607,34 +748,36 @@ int job_finish_and_invalidate(Job *j, JobResult result, bool recursive) { assert(j->installed); assert(j->type < _JOB_TYPE_MAX_IN_TRANSACTION); + u = j->unit; + t = j->type; + + j->result = result; + + log_debug_unit(u->id, "Job %s/%s finished, result=%s", + u->id, job_type_to_string(t), job_result_to_string(result)); + + job_print_status_message(u, t, result); + job_log_status_message(u, t, result); + job_add_to_dbus_queue(j); /* Patch restart jobs so that they become normal start jobs */ - if (result == JOB_DONE && j->type == JOB_RESTART) { + if (result == JOB_DONE && t == JOB_RESTART) { job_change_type(j, JOB_START); j->state = JOB_WAITING; job_add_to_run_queue(j); - u = j->unit; goto finish; } - j->result = result; - - log_debug("Job %s/%s finished, result=%s", j->unit->id, job_type_to_string(j->type), job_result_to_string(result)); - if (result == JOB_FAILED) j->manager->n_failed_jobs ++; - u = j->unit; - t = j->type; job_uninstall(j); job_free(j); - job_print_status_message(u, t, result); - /* Fail depending jobs on failure */ if (result != JOB_DONE && recursive) { @@ -671,14 +814,19 @@ int job_finish_and_invalidate(Job *j, JobResult result, bool recursive) { } /* Trigger OnFailure dependencies that are not generated by - * the unit itself. We don't tread JOB_CANCELED as failure in + * the unit itself. We don't treat JOB_CANCELED as failure in * this context. And JOB_FAILURE is already handled by the * unit itself. */ if (result == JOB_TIMEOUT || result == JOB_DEPENDENCY) { - log_notice("Job %s/%s failed with result '%s'.", + log_struct(LOG_NOTICE, + "UNIT=%s", u->id, + "JOB_TYPE=%s", job_type_to_string(t), + "JOB_RESULT=%s", job_result_to_string(result), + "Job %s/%s failed with result '%s'.", u->id, job_type_to_string(t), - job_result_to_string(result)); + job_result_to_string(result), + NULL); unit_trigger_on_failure(u); } @@ -785,7 +933,8 @@ void job_timer_event(Job *j, uint64_t n_elapsed, Watch *w) { assert(j); assert(w == &j->timer_watch); - log_warning("Job %s/%s timed out.", j->unit->id, job_type_to_string(j->type)); + log_warning_unit(j->unit->id, "Job %s/%s timed out.", + j->unit->id, job_type_to_string(j->type)); job_finish_and_invalidate(j, JOB_TIMEOUT, true); }