system/systemd
system/systemd
1
0
Fork 0
mirror of https://github.com/systemd/systemd synced 2024-07-21 18:24:38 +00:00
Code Issues Actions 5 Packages Projects Releases Wiki Activity

Merge pull request #32320 from bluca/softreboot_serialize

Browse source 
Soft reboot timestamp follow-ups
This commit is contained in:
Lennart Poettering 2024-04-17 22:12:49 +02:00 committed by GitHub
parent aea6787f78 b3f548615f
commit 94c5c55e3e
No known key found for this signature in database
GPG key ID: B5690EEEBB952194
10 changed files with 58 additions and 34 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

17
man/org.freedesktop.systemd1.xml
View file

@ -340,9 +340,9 @@ node /org/freedesktop/systemd1 {
@org.freedesktop.DBus.Property.EmitsChangedSignal("const")
readonly t FinishTimestampMonotonic = ...;
@org.freedesktop.DBus.Property.EmitsChangedSignal("const")
readonly t SoftRebootStartTimestamp = ...;
readonly t ShutdownStartTimestamp = ...;
@org.freedesktop.DBus.Property.EmitsChangedSignal("const")
readonly t SoftRebootStartTimestampMonotonic = ...;
readonly t ShutdownStartTimestampMonotonic = ...;
@org.freedesktop.DBus.Property.EmitsChangedSignal("const")
readonly t SecurityStartTimestamp = ...;
@org.freedesktop.DBus.Property.EmitsChangedSignal("const")
@ -1039,9 +1039,9 @@ node /org/freedesktop/systemd1 {
<variablelist class="dbus-property" generated="True" extra-ref="FinishTimestampMonotonic"/>
<variablelist class="dbus-property" generated="True" extra-ref="SoftRebootStartTimestamp"/>
<variablelist class="dbus-property" generated="True" extra-ref="ShutdownStartTimestamp"/>
<variablelist class="dbus-property" generated="True" extra-ref="SoftRebootStartTimestampMonotonic"/>
<variablelist class="dbus-property" generated="True" extra-ref="ShutdownStartTimestampMonotonic"/>
<variablelist class="dbus-property" generated="True" extra-ref="SecurityStartTimestamp"/>
@ -1746,12 +1746,11 @@ node /org/freedesktop/systemd1 {
<varname>InitRDTimestamp</varname>, <varname>InitRDTimestampMonotonic</varname>,
<varname>UserspaceTimestamp</varname>, <varname>UserspaceTimestampMonotonic</varname>,
<varname>FinishTimestamp</varname>, <varname>FinishTimestampMonotonic</varname>,
<varname>SoftRebootStartTimestamp</varname> and <varname>SoftRebootStartTimestampMonotonic</varname>
<varname>ShutdownStartTimestamp</varname> and <varname>ShutdownStartTimestampMonotonic</varname>
encode <constant>CLOCK_REALTIME</constant> and <constant>CLOCK_MONOTONIC</constant> microsecond
timestamps taken when the firmware first began execution, when the boot loader first began execution,
when the kernel first began execution, when the initrd first began execution, when the main systemd
instance began execution, when all queued startup jobs finished execution and finally, when a
<citerefentry><refentrytitle>systemd-soft-reboot.service</refentrytitle><manvolnum>8</manvolnum></citerefentry>
instance began execution, when all queued startup jobs finished execution and finally, when a shutdown
operation first began execution. These values are useful for determining boot-time performance. Note
that as monotonic time begins with the kernel startup, the <varname>KernelTimestampMonotonic</varname>
timestamp will always be 0 and <varname>FirmwareTimestampMonotonic</varname> and
@ -12000,8 +11999,8 @@ $ gdbus introspect --system --dest org.freedesktop.systemd1 \
<function>SoftReboot()</function>, and
<function>DumpUnitFileDescriptorStore()</function> were added in version 254.</para>
<para><function>StartAuxiliaryScope()</function>,
<varname>SoftRebootStartTimestamp</varname>,
<varname>SoftRebootStartTimestampMonotonic</varname> and
<varname>ShutdownStartTimestamp</varname>,
<varname>ShutdownStartTimestampMonotonic</varname> and
<varname>SoftRebootsCount</varname> were added in version 256.</para>
</refsect2>
<refsect2>

4
src/analyze/analyze-plot.c
View file

@ -316,7 +316,7 @@ static int produce_plot_as_svg(
strempty(host->virtualization));
svg("<g transform=\"translate(%.3f,100)\">\n", 20.0 + (SCALE_X * boot->firmware_time));
if (timestamp_is_set(boot->softreboot_start_time))
if (boot->soft_reboots_count > 0)
svg_graph_box(m, 0, boot->finish_time);
else
svg_graph_box(m, -(double) boot->firmware_time, boot->finish_time);
@ -347,7 +347,7 @@ static int produce_plot_as_svg(
svg_text(true, boot->initrd_time, y, "initrd");
y++;
}
if (timestamp_is_set(boot->softreboot_start_time)) {
if (boot->soft_reboots_count > 0) {
svg_bar("soft-reboot", 0, boot->userspace_time, y);
svg_text(true, 0, y, "soft-reboot");
y++;

16
src/analyze/analyze-time-data.c
View file

@ -38,7 +38,7 @@ int acquire_boot_times(sd_bus *bus, bool require_finished, BootTimes **ret) {
{ "FinishTimestampMonotonic", "t", NULL, offsetof(BootTimes, finish_time) },
{ "SecurityStartTimestampMonotonic", "t", NULL, offsetof(BootTimes, security_start_time) },
{ "SecurityFinishTimestampMonotonic", "t", NULL, offsetof(BootTimes, security_finish_time) },
{ "SoftRebootStartTimestampMonotonic", "t", NULL, offsetof(BootTimes, softreboot_start_time) },
{ "ShutdownStartTimestampMonotonic", "t", NULL, offsetof(BootTimes, shutdown_start_time) },
{ "GeneratorsStartTimestampMonotonic", "t", NULL, offsetof(BootTimes, generators_start_time) },
{ "GeneratorsFinishTimestampMonotonic", "t", NULL, offsetof(BootTimes, generators_finish_time) },
{ "UnitsLoadStartTimestampMonotonic", "t", NULL, offsetof(BootTimes, unitsload_start_time) },
@ -83,13 +83,13 @@ int acquire_boot_times(sd_bus *bus, bool require_finished, BootTimes **ret) {
if (require_finished && times.finish_time <= 0)
return log_not_finished(times.finish_time);
if (arg_runtime_scope == RUNTIME_SCOPE_SYSTEM && timestamp_is_set(times.softreboot_start_time)) {
if (arg_runtime_scope == RUNTIME_SCOPE_SYSTEM && times.soft_reboots_count > 0) {
/* On soft-reboot ignore kernel/firmware/initrd times as they are from the previous boot */
times.firmware_time = times.loader_time = times.kernel_time = times.initrd_time =
times.initrd_security_start_time = times.initrd_security_finish_time =
times.initrd_generators_start_time = times.initrd_generators_finish_time =
times.initrd_unitsload_start_time = times.initrd_unitsload_finish_time = 0;
times.reverse_offset = times.softreboot_start_time;
times.reverse_offset = times.shutdown_start_time;
/* Clamp all timestamps to avoid showing huge graphs */
if (timestamp_is_set(times.finish_time))
@ -203,7 +203,7 @@ int pretty_boot_time(sd_bus *bus, char **ret) {
return log_oom();
if (timestamp_is_set(t->initrd_time) && !strextend(&text, FORMAT_TIMESPAN(t->userspace_time - t->initrd_time, USEC_PER_MSEC), " (initrd) + "))
return log_oom();
if (timestamp_is_set(t->softreboot_start_time) && strextendf(&text, "%s (soft reboot #%" PRIu64 ") + ", FORMAT_TIMESPAN(t->userspace_time, USEC_PER_MSEC), t->soft_reboots_count) < 0)
if (t->soft_reboots_count > 0 && strextendf(&text, "%s (soft reboot #%" PRIu64 ") + ", FORMAT_TIMESPAN(t->userspace_time, USEC_PER_MSEC), t->soft_reboots_count) < 0)
return log_oom();
if (!strextend(&text, FORMAT_TIMESPAN(t->finish_time - t->userspace_time, USEC_PER_MSEC), " (userspace) "))
@ -217,7 +217,7 @@ int pretty_boot_time(sd_bus *bus, char **ret) {
usec_t base;
/* On soft-reboot times are clamped to avoid showing huge graphs */
if (timestamp_is_set(t->softreboot_start_time) && timestamp_is_set(t->userspace_time))
if (t->soft_reboots_count > 0 && timestamp_is_set(t->userspace_time))
base = t->userspace_time + t->reverse_offset;
else
base = timestamp_is_set(t->userspace_time) ? t->userspace_time : t->reverse_offset;
@ -328,15 +328,15 @@ int acquire_time_data(sd_bus *bus, bool require_finished, UnitTimes **out) {
u.id, bus_error_message(&error, r));
/* Activated in the previous soft-reboot iteration? Ignore it, we want new activations */
if ((t->activated > 0 && t->activated < boot_times->softreboot_start_time) ||
(t->activating > 0 && t->activating < boot_times->softreboot_start_time))
if ((t->activated > 0 && t->activated < boot_times->shutdown_start_time) ||
(t->activating > 0 && t->activating < boot_times->shutdown_start_time))
continue;
subtract_timestamp(&t->activating, boot_times->reverse_offset);
subtract_timestamp(&t->activated, boot_times->reverse_offset);
/* If the last deactivation was in the previous soft-reboot, ignore it */
if (timestamp_is_set(boot_times->softreboot_start_time)) {
if (boot_times->soft_reboots_count > 0) {
if (t->deactivating < boot_times->reverse_offset)
t->deactivating = 0;
else

2
src/analyze/analyze-time-data.h
View file

@ -14,7 +14,7 @@ typedef struct BootTimes {
usec_t initrd_time;
usec_t userspace_time;
usec_t finish_time;
usec_t softreboot_start_time;
usec_t shutdown_start_time;
usec_t security_start_time;
usec_t security_finish_time;
usec_t generators_start_time;

2
src/core/dbus-manager.c
View file

@ -3052,7 +3052,7 @@ const sd_bus_vtable bus_manager_vtable[] = {
BUS_PROPERTY_DUAL_TIMESTAMP("InitRDTimestamp", offsetof(Manager, timestamps[MANAGER_TIMESTAMP_INITRD]), SD_BUS_VTABLE_PROPERTY_CONST),
BUS_PROPERTY_DUAL_TIMESTAMP("UserspaceTimestamp", offsetof(Manager, timestamps[MANAGER_TIMESTAMP_USERSPACE]), SD_BUS_VTABLE_PROPERTY_CONST),
BUS_PROPERTY_DUAL_TIMESTAMP("FinishTimestamp", offsetof(Manager, timestamps[MANAGER_TIMESTAMP_FINISH]), SD_BUS_VTABLE_PROPERTY_CONST),
BUS_PROPERTY_DUAL_TIMESTAMP("SoftRebootStartTimestamp", offsetof(Manager, timestamps[MANAGER_TIMESTAMP_SOFTREBOOT_START]), SD_BUS_VTABLE_PROPERTY_CONST),
BUS_PROPERTY_DUAL_TIMESTAMP("ShutdownStartTimestamp", offsetof(Manager, timestamps[MANAGER_TIMESTAMP_SHUTDOWN_START]), SD_BUS_VTABLE_PROPERTY_CONST),
BUS_PROPERTY_DUAL_TIMESTAMP("SecurityStartTimestamp", offsetof(Manager, timestamps[MANAGER_TIMESTAMP_SECURITY_START]), SD_BUS_VTABLE_PROPERTY_CONST),
BUS_PROPERTY_DUAL_TIMESTAMP("SecurityFinishTimestamp", offsetof(Manager, timestamps[MANAGER_TIMESTAMP_SECURITY_FINISH]), SD_BUS_VTABLE_PROPERTY_CONST),
BUS_PROPERTY_DUAL_TIMESTAMP("GeneratorsStartTimestamp", offsetof(Manager, timestamps[MANAGER_TIMESTAMP_GENERATORS_START]), SD_BUS_VTABLE_PROPERTY_CONST),

7
src/core/job.c
View file

@ -1387,10 +1387,13 @@ void job_shutdown_magic(Job *j) {
if (j->type != JOB_START)
return;
if (!MANAGER_IS_SYSTEM(j->unit->manager))
if (!unit_has_name(j->unit, SPECIAL_SHUTDOWN_TARGET))
return;
if (!unit_has_name(j->unit, SPECIAL_SHUTDOWN_TARGET))
/* This is the very beginning of the shutdown phase, so take the timestamp here */
dual_timestamp_now(ASSERT_PTR(j->manager)->timestamps + MANAGER_TIMESTAMP_SHUTDOWN_START);
if (!MANAGER_IS_SYSTEM(j->manager))
return;
/* In case messages on console has been disabled on boot */

17
src/core/main.c
View file

@ -2041,6 +2041,16 @@ static int invoke_main_loop(
"MESSAGE_ID=" SD_MESSAGE_CORE_MAINLOOP_FAILED_STR);
}
/* Ensure shutdown timestamp is taken even when bypassing the job engine */
if (IN_SET(objective,
MANAGER_SOFT_REBOOT,
MANAGER_REBOOT,
MANAGER_KEXEC,
MANAGER_HALT,
MANAGER_POWEROFF) &&
!dual_timestamp_is_set(m->timestamps + MANAGER_TIMESTAMP_SHUTDOWN_START))
dual_timestamp_now(m->timestamps + MANAGER_TIMESTAMP_SHUTDOWN_START);
switch (objective) {
case MANAGER_RELOAD: {
@ -2129,8 +2139,6 @@ static int invoke_main_loop(
manager_send_reloading(m);
manager_set_switching_root(m, true);
dual_timestamp_now(m->timestamps + MANAGER_TIMESTAMP_SOFTREBOOT_START);
r = prepare_reexecute(m, &arg_serialization, ret_fds, /* switching_root= */ true);
if (r < 0) {
*ret_error_message = "Failed to prepare for reexecution";
@ -3192,11 +3200,6 @@ int main(int argc, char *argv[]) {
goto finish;
}
/* If we got a SoftRebootStart timestamp during deserialization, then we are in a new soft-reboot
* iteration, so bump the counter now before starting units, so that they can reliably read it. */
if (dual_timestamp_is_set(&m->timestamps[MANAGER_TIMESTAMP_SOFTREBOOT_START]))
m->soft_reboots_count++;
/* This will close all file descriptors that were opened, but not claimed by any unit. */
fds = fdset_free(fds);
arg_serialization = safe_fclose(arg_serialization);

11
src/core/manager-serialize.c
View file

@ -158,6 +158,9 @@ int manager_serialize(
(void) serialize_ratelimit(f, "dump-ratelimit", &m->dump_ratelimit);
(void) serialize_ratelimit(f, "reload-reexec-ratelimit", &m->reload_reexec_ratelimit);
if (m->objective >= 0 && m->objective < _MANAGER_OBJECTIVE_MAX)
(void) serialize_item_format(f, "previous-objective", "%u", (unsigned) m->objective);
bus_track_serialize(m->subscribed, f, "subscribed");
r = dynamic_user_serialize(m, f, fds);
@ -529,6 +532,14 @@ int manager_deserialize(Manager *m, FILE *f, FDSet *fds) {
log_notice("Failed to parse soft reboots counter '%s', ignoring.", val);
else
m->soft_reboots_count = n;
} else if ((val = startswith(l, "previous-objective="))) {
unsigned n;
if (safe_atou(val, &n) < 0 || n >= _MANAGER_OBJECTIVE_MAX)
log_notice("Failed to parse objective '%s', ignoring.", val);
else
m->previous_objective = n;
} else {
ManagerTimestamp q;

12
src/core/manager.c
View file

@ -882,6 +882,7 @@ int manager_new(RuntimeScope runtime_scope, ManagerTestRunFlags test_run_flags,
*m = (Manager) {
.runtime_scope = runtime_scope,
.objective = _MANAGER_OBJECTIVE_INVALID,
.previous_objective = _MANAGER_OBJECTIVE_INVALID,
.status_unit_format = STATUS_UNIT_FORMAT_DEFAULT,
@ -1973,6 +1974,11 @@ int manager_startup(Manager *m, FILE *serialization, FDSet *fds, const char *roo
return log_error_errno(r, "Deserialization failed: %m");
}
/* If we are in a new soft-reboot iteration bump the counter now before starting units, so
* that they can reliably read it. We get the previous objective from serialized state. */
if (m->previous_objective == MANAGER_SOFT_REBOOT)
m->soft_reboots_count++;
/* Any fds left? Find some unit which wants them. This is useful to allow container managers to pass
* some file descriptors to us pre-initialized. This enables socket-based activation of entire
* containers. */
@ -3689,10 +3695,10 @@ static void manager_notify_finished(Manager *m) {
if (MANAGER_IS_TEST_RUN(m))
return;
if (MANAGER_IS_SYSTEM(m) && dual_timestamp_is_set(&m->timestamps[MANAGER_TIMESTAMP_SOFTREBOOT_START])) {
if (MANAGER_IS_SYSTEM(m) && m->soft_reboots_count > 0) {
/* The soft-reboot case, where we only report data for the last reboot */
firmware_usec = loader_usec = initrd_usec = kernel_usec = 0;
total_usec = userspace_usec = usec_sub_unsigned(m->timestamps[MANAGER_TIMESTAMP_FINISH].monotonic, m->timestamps[MANAGER_TIMESTAMP_SOFTREBOOT_START].monotonic);
total_usec = userspace_usec = usec_sub_unsigned(m->timestamps[MANAGER_TIMESTAMP_FINISH].monotonic, m->timestamps[MANAGER_TIMESTAMP_SHUTDOWN_START].monotonic);
log_struct(LOG_INFO,
"MESSAGE_ID=" SD_MESSAGE_STARTUP_FINISHED_STR,
@ -5046,7 +5052,6 @@ static const char *const manager_timestamp_table[_MANAGER_TIMESTAMP_MAX] = {
[MANAGER_TIMESTAMP_INITRD] = "initrd",
[MANAGER_TIMESTAMP_USERSPACE] = "userspace",
[MANAGER_TIMESTAMP_FINISH] = "finish",
[MANAGER_TIMESTAMP_SOFTREBOOT_START] = "softreboot-start",
[MANAGER_TIMESTAMP_SECURITY_START] = "security-start",
[MANAGER_TIMESTAMP_SECURITY_FINISH] = "security-finish",
[MANAGER_TIMESTAMP_GENERATORS_START] = "generators-start",
@ -5060,6 +5065,7 @@ static const char *const manager_timestamp_table[_MANAGER_TIMESTAMP_MAX] = {
[MANAGER_TIMESTAMP_INITRD_GENERATORS_FINISH] = "initrd-generators-finish",
[MANAGER_TIMESTAMP_INITRD_UNITS_LOAD_START] = "initrd-units-load-start",
[MANAGER_TIMESTAMP_INITRD_UNITS_LOAD_FINISH] = "initrd-units-load-finish",
[MANAGER_TIMESTAMP_SHUTDOWN_START] = "shutdown-start",
};
DEFINE_STRING_TABLE_LOOKUP(manager_timestamp, ManagerTimestamp);

4
src/core/manager.h
View file

@ -121,7 +121,7 @@ typedef enum ManagerTimestamp {
MANAGER_TIMESTAMP_INITRD_UNITS_LOAD_START,
MANAGER_TIMESTAMP_INITRD_UNITS_LOAD_FINISH,
MANAGER_TIMESTAMP_SOFTREBOOT_START,
MANAGER_TIMESTAMP_SHUTDOWN_START,
_MANAGER_TIMESTAMP_MAX,
_MANAGER_TIMESTAMP_INVALID = -EINVAL,
@ -379,6 +379,8 @@ struct Manager {
bool etc_localtime_accessible;
ManagerObjective objective;
/* Objective as it was before serialization, mostly to detect soft-reboots */
ManagerObjective previous_objective;
/* Flags */
bool dispatching_load_queue;