From c5bc2c01eef4d3defb58245960065a063f5f75cf Mon Sep 17 00:00:00 2001 From: Luca Boccassi Date: Tue, 21 Apr 2020 17:23:21 +0100 Subject: [PATCH 1/2] core: add log_get_max_level check optimization in log_unit_full Just as log_full already does, check if the log level would result in logging immediately in the macro in order to avoid doing unnecessary work that adds up in hot spots. --- src/core/unit.h | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/src/core/unit.h b/src/core/unit.h index 2e103f7ab2..e38871a97c 100644 --- a/src/core/unit.h +++ b/src/core/unit.h @@ -883,8 +883,9 @@ int unit_can_clean(Unit *u, ExecCleanMask *ret_mask); #define log_unit_full(unit, level, error, ...) \ ({ \ const Unit *_u = (unit); \ - _u ? log_object_internal(level, error, PROJECT_FILE, __LINE__, __func__, _u->manager->unit_log_field, _u->id, _u->manager->invocation_log_field, _u->invocation_id_string, ##__VA_ARGS__) : \ - log_internal(level, error, PROJECT_FILE, __LINE__, __func__, ##__VA_ARGS__); \ + (log_get_max_level() < LOG_PRI(level)) ? -ERRNO_VALUE(error) : \ + _u ? log_object_internal(level, error, PROJECT_FILE, __LINE__, __func__, _u->manager->unit_log_field, _u->id, _u->manager->invocation_log_field, _u->invocation_id_string, ##__VA_ARGS__) : \ + log_internal(level, error, PROJECT_FILE, __LINE__, __func__, ##__VA_ARGS__); \ }) #define log_unit_debug(unit, ...) log_unit_full(unit, LOG_DEBUG, 0, ##__VA_ARGS__) From c03fbd37d662a1cb8b63f505b1dd29389eba1d2e Mon Sep 17 00:00:00 2001 From: Luca Boccassi Date: Tue, 21 Apr 2020 17:28:01 +0100 Subject: [PATCH 2/2] core: add debug log when a job in the activation queue is not runnable When a job is skipped due its dependencies not being ready, log a debug message saying what is holding it back. This was very useful with transient units timing out to figure out where the problem was. --- src/core/job.c | 12 ++++++++++-- 1 file changed, 10 insertions(+), 2 deletions(-) diff --git a/src/core/job.c b/src/core/job.c index 2114889d32..cf3bca88d6 100644 --- a/src/core/job.c +++ b/src/core/job.c @@ -516,12 +516,20 @@ static bool job_is_runnable(Job *j) { return true; HASHMAP_FOREACH_KEY(v, other, j->unit->dependencies[UNIT_AFTER], i) - if (other->job && job_compare(j, other->job, UNIT_AFTER) > 0) + if (other->job && job_compare(j, other->job, UNIT_AFTER) > 0) { + log_unit_debug(j->unit, + "starting held back, waiting for: %s", + other->id); return false; + } HASHMAP_FOREACH_KEY(v, other, j->unit->dependencies[UNIT_BEFORE], i) - if (other->job && job_compare(j, other->job, UNIT_BEFORE) > 0) + if (other->job && job_compare(j, other->job, UNIT_BEFORE) > 0) { + log_unit_debug(j->unit, + "stopping held back, waiting for: %s", + other->id); return false; + } return true; }