Merge pull request #13265 from keszybz/timedated-ntp-logging

Timedated logging and service priority
This commit is contained in:
Yu Watanabe
2019-08-07 08:07:57 +09:00
committed by GitHub
+80 -68
View File
@@ -61,6 +61,25 @@ typedef struct Context {
LIST_HEAD(UnitStatusInfo, units);
} Context;
#define log_unit_full(unit, level, error, ...) \
({ \
const UnitStatusInfo *_u = (unit); \
log_object_internal(level, error, PROJECT_FILE, __LINE__, __func__, \
"UNIT=", _u->name, NULL, NULL, ##__VA_ARGS__); \
})
#define log_unit_debug(unit, ...) log_unit_full(unit, LOG_DEBUG, 0, ##__VA_ARGS__)
#define log_unit_info(unit, ...) log_unit_full(unit, LOG_INFO, 0, ##__VA_ARGS__)
#define log_unit_notice(unit, ...) log_unit_full(unit, LOG_NOTICE, 0, ##__VA_ARGS__)
#define log_unit_warning(unit, ...) log_unit_full(unit, LOG_WARNING, 0, ##__VA_ARGS__)
#define log_unit_error(unit, ...) log_unit_full(unit, LOG_ERR, 0, ##__VA_ARGS__)
#define log_unit_debug_errno(unit, error, ...) log_unit_full(unit, LOG_DEBUG, error, ##__VA_ARGS__)
#define log_unit_info_errno(unit, error, ...) log_unit_full(unit, LOG_INFO, error, ##__VA_ARGS__)
#define log_unit_notice_errno(unit, error, ...) log_unit_full(unit, LOG_NOTICE, error, ##__VA_ARGS__)
#define log_unit_warning_errno(unit, error, ...) log_unit_full(unit, LOG_WARNING, error, ##__VA_ARGS__)
#define log_unit_error_errno(unit, error, ...) log_unit_full(unit, LOG_ERR, error, ##__VA_ARGS__)
static void unit_status_info_clear(UnitStatusInfo *p) {
assert(p);
@@ -95,7 +114,7 @@ static void context_clear(Context *c) {
}
}
static int context_add_ntp_service(Context *c, const char *s) {
static int context_add_ntp_service(Context *c, const char *s, const char *source) {
UnitStatusInfo *u;
if (!unit_name_is_valid(s, UNIT_NAME_PLAIN))
@@ -117,6 +136,7 @@ static int context_add_ntp_service(Context *c, const char *s) {
}
LIST_APPEND(units, c->units, u);
log_unit_debug(u, "added from %s.", source);
return 0;
}
@@ -131,7 +151,7 @@ static int context_parse_ntp_services_from_environment(Context *c) {
if (!env)
return 0;
log_debug("Using list of ntp services from environment variable $SYSTEMD_TIMEDATED_NTP_SERVICES.");
log_debug("Using list of ntp services from environment variable $SYSTEMD_TIMEDATED_NTP_SERVICES=%s.", env);
for (p = env;;) {
_cleanup_free_ char *word = NULL;
@@ -146,7 +166,7 @@ static int context_parse_ntp_services_from_environment(Context *c) {
break;
}
r = context_add_ntp_service(c, word);
r = context_add_ntp_service(c, word, "$SYSTEMD_TIMEDATED_NTP_SERVICES");
if (r < 0)
log_warning_errno(r, "Failed to add NTP service \"%s\", ignoring: %m", word);
}
@@ -190,7 +210,7 @@ static int context_parse_ntp_services_from_disk(Context *c) {
if (isempty(word) || startswith("#", word))
continue;
r = context_add_ntp_service(c, word);
r = context_add_ntp_service(c, word, *f);
if (r < 0)
log_warning_errno(r, "Failed to add NTP service \"%s\", ignoring: %m", word);
}
@@ -223,20 +243,6 @@ static int context_ntp_service_is_active(Context *c) {
return count;
}
static int context_ntp_service_is_enabled(Context *c) {
UnitStatusInfo *info;
int count = 0;
assert(c);
/* Call context_update_ntp_status() to update UnitStatusInfo before calling this. */
LIST_FOREACH(units, info, c->units)
count += !STRPTR_IN_SET(info->unit_file_state, "masked", "masked-runtime", "disabled", "bad");
return count;
}
static int context_ntp_service_exists(Context *c) {
UnitStatusInfo *info;
int count = 0;
@@ -272,31 +278,25 @@ static int context_read_data(Context *c) {
static int context_write_data_timezone(Context *c) {
_cleanup_free_ char *p = NULL;
int r = 0;
assert(c);
if (isempty(c->zone)) {
if (unlink("/etc/localtime") < 0 && errno != ENOENT)
r = -errno;
return r;
return -errno;
return 0;
}
p = path_join("../usr/share/zoneinfo", c->zone);
if (!p)
return log_oom();
r = symlink_atomic(p, "/etc/localtime");
if (r < 0)
return r;
return 0;
return symlink_atomic(p, "/etc/localtime");
}
static int context_write_data_local_rtc(Context *c) {
int r;
_cleanup_free_ char *s = NULL, *w = NULL;
int r;
assert(c);
@@ -406,7 +406,7 @@ static int context_update_ntp_status(Context *c, sd_bus *bus, sd_bus_message *m)
NULL,
u);
if (r < 0)
return log_error_errno(r, "Failed to get properties: %s", bus_error_message(&error, r));
return log_unit_error_errno(u, r, "Failed to get properties: %s", bus_error_message(&error, r));
}
return 0;
@@ -437,7 +437,9 @@ static int match_job_removed(sd_bus_message *m, void *userdata, sd_bus_error *er
if (n == 0) {
c->slot_job_removed = sd_bus_slot_unref(c->slot_job_removed);
(void) sd_bus_emit_properties_changed(sd_bus_message_get_bus(m), "/org/freedesktop/timedate1", "org.freedesktop.timedate1", "NTP", NULL);
(void) sd_bus_emit_properties_changed(sd_bus_message_get_bus(m),
"/org/freedesktop/timedate1", "org.freedesktop.timedate1", "NTP",
NULL);
}
return 0;
@@ -463,6 +465,8 @@ static int unit_start_or_stop(UnitStatusInfo *u, sd_bus *bus, sd_bus_error *erro
"ss",
u->name,
"replace");
log_unit_full(u, r < 0 ? LOG_WARNING : LOG_DEBUG, r,
"%s unit: %m", start ? "Starting" : "Stopping");
if (r < 0)
return r;
@@ -486,8 +490,12 @@ static int unit_enable_or_disable(UnitStatusInfo *u, sd_bus *bus, sd_bus_error *
/* Call context_update_ntp_status() to update UnitStatusInfo before calling this. */
if (streq(u->unit_file_state, "enabled") == enable)
if (streq(u->unit_file_state, "enabled") == enable) {
log_unit_debug(u, "already %sd.", enable_disable(enable));
return 0;
}
log_unit_info(u, "%s unit.", enable ? "Enabling" : "Disabling");
if (enable)
r = sd_bus_call_method(
@@ -543,19 +551,16 @@ static int property_get_rtc_time(
void *userdata,
sd_bus_error *error) {
struct tm tm;
usec_t t;
struct tm tm = {};
usec_t t = 0;
int r;
zero(tm);
r = clock_get_hwclock(&tm);
if (r == -EBUSY) {
if (r == -EBUSY)
log_warning("/dev/rtc is busy. Is somebody keeping it open continuously? That's not a good idea... Returning a bogus RTC timestamp.");
t = 0;
} else if (r == -ENOENT) {
else if (r == -ENOENT)
log_debug("/dev/rtc not found.");
t = 0; /* no RTC found */
} else if (r < 0)
else if (r < 0)
return sd_bus_error_set_errnof(error, r, "Failed to read RTC: %m");
else
t = (usec_t) timegm(&tm) * USEC_PER_SEC;
@@ -692,7 +697,9 @@ static int method_set_timezone(sd_bus_message *m, void *userdata, sd_bus_error *
"DAYLIGHT=%i", daylight,
LOG_MESSAGE("Changed time zone to '%s' (%s).", c->zone, tzname[daylight]));
(void) sd_bus_emit_properties_changed(sd_bus_message_get_bus(m), "/org/freedesktop/timedate1", "org.freedesktop.timedate1", "Timezone", NULL);
(void) sd_bus_emit_properties_changed(sd_bus_message_get_bus(m),
"/org/freedesktop/timedate1", "org.freedesktop.timedate1", "Timezone",
NULL);
return sd_bus_reply_method_return(m, NULL);
}
@@ -732,8 +739,8 @@ static int method_set_local_rtc(sd_bus_message *m, void *userdata, sd_bus_error
/* 1. Write new configuration file */
r = context_write_data_local_rtc(c);
if (r < 0) {
log_error_errno(r, "Failed to set RTC to local/UTC: %m");
return sd_bus_error_set_errnof(error, r, "Failed to set RTC to local/UTC: %m");
log_error_errno(r, "Failed to set RTC to %s: %m", lrtc ? "local" : "UTC");
return sd_bus_error_set_errnof(error, r, "Failed to set RTC to %s: %m", lrtc ? "local" : "UTC");
}
/* 2. Tell the kernel our timezone */
@@ -784,7 +791,9 @@ static int method_set_local_rtc(sd_bus_message *m, void *userdata, sd_bus_error
log_info("RTC configured to %s time.", c->local_rtc ? "local" : "UTC");
(void) sd_bus_emit_properties_changed(sd_bus_message_get_bus(m), "/org/freedesktop/timedate1", "org.freedesktop.timedate1", "LocalRTC", NULL);
(void) sd_bus_emit_properties_changed(sd_bus_message_get_bus(m),
"/org/freedesktop/timedate1", "org.freedesktop.timedate1", "LocalRTC",
NULL);
return sd_bus_reply_method_return(m, NULL);
}
@@ -889,6 +898,7 @@ static int method_set_ntp(sd_bus_message *m, void *userdata, sd_bus_error *error
sd_bus *bus = sd_bus_message_get_bus(m);
Context *c = userdata;
UnitStatusInfo *u;
const UnitStatusInfo *selected = NULL;
int enable, interactive, q, r;
assert(m);
@@ -937,50 +947,52 @@ static int method_set_ntp(sd_bus_message *m, void *userdata, sd_bus_error *error
return r;
}
if (!enable)
if (enable)
LIST_FOREACH(units, u, c->units) {
bool enable_this_one = !selected;
if (!streq(u->load_state, "loaded"))
continue;
q = unit_enable_or_disable(u, bus, error, enable);
if (q < 0)
r = q;
q = unit_start_or_stop(u, bus, error, enable);
if (q < 0)
r = q;
}
else if (context_ntp_service_is_enabled(c) <= 0)
LIST_FOREACH(units, u, c->units) {
if (!streq(u->load_state, "loaded"))
continue;
r = unit_enable_or_disable(u, bus, error, enable);
r = unit_enable_or_disable(u, bus, error, enable_this_one);
if (r < 0)
continue;
/* If enablement failed, don't start this unit. */
enable_this_one = false;
r = unit_start_or_stop(u, bus, error, enable);
break;
r = unit_start_or_stop(u, bus, error, enable_this_one);
if (r < 0)
log_unit_warning_errno(u, r, "Failed to %s %sd NTP unit, ignoring: %m",
enable_this_one ? "start" : "stop",
enable_disable(enable_this_one));
if (enable_this_one)
selected = u;
}
else
LIST_FOREACH(units, u, c->units) {
if (!streq(u->load_state, "loaded") ||
!streq(u->unit_file_state, "enabled"))
if (!streq(u->load_state, "loaded"))
continue;
r = unit_start_or_stop(u, bus, error, enable);
break;
q = unit_enable_or_disable(u, bus, error, false);
if (q < 0)
r = q;
q = unit_start_or_stop(u, bus, error, false);
if (q < 0)
r = q;
}
if (r < 0)
return r;
if (enable && !selected)
return log_error_errno(SYNTHETIC_ERRNO(ENOENT), "No NTP service found to enable.");
if (slot)
c->slot_job_removed = TAKE_PTR(slot);
log_info("Set NTP to %sd", enable_disable(enable));
if (selected)
log_info("Set NTP to enabled (%s).", selected->name);
else
log_info("Set NTP to disabled.");
return sd_bus_reply_method_return(m, NULL);
}