]> git.ipfire.org Git - thirdparty/systemd.git/blame - src/analyze/analyze-time-data.c
analyze: show soft-reboot counter next to time deltas
[thirdparty/systemd.git] / src / analyze / analyze-time-data.c
CommitLineData
113dd9cb
LP
1/* SPDX-License-Identifier: LGPL-2.1-or-later */
2
113dd9cb 3#include "analyze-time-data.h"
ebaf5549 4#include "analyze.h"
113dd9cb
LP
5#include "bus-error.h"
6#include "bus-locator.h"
7#include "bus-map-properties.h"
8#include "bus-unit-util.h"
ebaf5549 9#include "memory-util.h"
ba474dad 10#include "special.h"
ebaf5549 11#include "strv.h"
113dd9cb
LP
12
13static void subtract_timestamp(usec_t *a, usec_t b) {
14 assert(a);
15
16 if (*a > 0) {
17 assert(*a >= b);
18 *a -= b;
19 }
20}
21
63d7632d
YW
22static int log_not_finished(usec_t finish_time) {
23 return log_error_errno(SYNTHETIC_ERRNO(EINPROGRESS),
24 "Bootup is not yet finished (org.freedesktop.systemd1.Manager.FinishTimestampMonotonic=%"PRIu64").\n"
25 "Please try again later.\n"
26 "Hint: Use 'systemctl%s list-jobs' to see active jobs",
27 finish_time,
28 arg_runtime_scope == RUNTIME_SCOPE_SYSTEM ? "" : " --user");
29}
30
31int acquire_boot_times(sd_bus *bus, bool require_finished, BootTimes **ret) {
113dd9cb
LP
32 static const struct bus_properties_map property_map[] = {
33 { "FirmwareTimestampMonotonic", "t", NULL, offsetof(BootTimes, firmware_time) },
34 { "LoaderTimestampMonotonic", "t", NULL, offsetof(BootTimes, loader_time) },
35 { "KernelTimestamp", "t", NULL, offsetof(BootTimes, kernel_time) },
36 { "InitRDTimestampMonotonic", "t", NULL, offsetof(BootTimes, initrd_time) },
37 { "UserspaceTimestampMonotonic", "t", NULL, offsetof(BootTimes, userspace_time) },
38 { "FinishTimestampMonotonic", "t", NULL, offsetof(BootTimes, finish_time) },
39 { "SecurityStartTimestampMonotonic", "t", NULL, offsetof(BootTimes, security_start_time) },
40 { "SecurityFinishTimestampMonotonic", "t", NULL, offsetof(BootTimes, security_finish_time) },
7addfba9 41 { "SoftRebootStartTimestampMonotonic", "t", NULL, offsetof(BootTimes, softreboot_start_time) },
113dd9cb
LP
42 { "GeneratorsStartTimestampMonotonic", "t", NULL, offsetof(BootTimes, generators_start_time) },
43 { "GeneratorsFinishTimestampMonotonic", "t", NULL, offsetof(BootTimes, generators_finish_time) },
44 { "UnitsLoadStartTimestampMonotonic", "t", NULL, offsetof(BootTimes, unitsload_start_time) },
45 { "UnitsLoadFinishTimestampMonotonic", "t", NULL, offsetof(BootTimes, unitsload_finish_time) },
46 { "InitRDSecurityStartTimestampMonotonic", "t", NULL, offsetof(BootTimes, initrd_security_start_time) },
47 { "InitRDSecurityFinishTimestampMonotonic", "t", NULL, offsetof(BootTimes, initrd_security_finish_time) },
48 { "InitRDGeneratorsStartTimestampMonotonic", "t", NULL, offsetof(BootTimes, initrd_generators_start_time) },
49 { "InitRDGeneratorsFinishTimestampMonotonic", "t", NULL, offsetof(BootTimes, initrd_generators_finish_time) },
50 { "InitRDUnitsLoadStartTimestampMonotonic", "t", NULL, offsetof(BootTimes, initrd_unitsload_start_time) },
51 { "InitRDUnitsLoadFinishTimestampMonotonic", "t", NULL, offsetof(BootTimes, initrd_unitsload_finish_time) },
259046cf 52 { "SoftRebootsCount", "t", NULL, offsetof(BootTimes, soft_reboots_count) },
113dd9cb
LP
53 {},
54 };
55 _cleanup_(sd_bus_error_free) sd_bus_error error = SD_BUS_ERROR_NULL;
56 static BootTimes times;
57 static bool cached = false;
58 int r;
59
63d7632d
YW
60 if (cached) {
61 if (require_finished && times.finish_time <= 0)
62 return log_not_finished(times.finish_time);
63
64 if (ret)
65 *ret = &times;
66 return 0;
67 }
113dd9cb
LP
68
69 assert_cc(sizeof(usec_t) == sizeof(uint64_t));
70
71 r = bus_map_all_properties(
72 bus,
73 "org.freedesktop.systemd1",
74 "/org/freedesktop/systemd1",
75 property_map,
76 BUS_MAP_STRDUP,
77 &error,
78 NULL,
79 &times);
80 if (r < 0)
81 return log_error_errno(r, "Failed to get timestamp properties: %s", bus_error_message(&error, r));
82
63d7632d
YW
83 if (require_finished && times.finish_time <= 0)
84 return log_not_finished(times.finish_time);
113dd9cb 85
e6bd341e 86 if (arg_runtime_scope == RUNTIME_SCOPE_SYSTEM && timestamp_is_set(times.softreboot_start_time)) {
7addfba9 87 /* On soft-reboot ignore kernel/firmware/initrd times as they are from the previous boot */
05626b27 88 times.firmware_time = times.loader_time = times.kernel_time = times.initrd_time =
259046cf
LB
89 times.initrd_security_start_time = times.initrd_security_finish_time =
90 times.initrd_generators_start_time = times.initrd_generators_finish_time =
91 times.initrd_unitsload_start_time = times.initrd_unitsload_finish_time = 0;
e6bd341e
LB
92 times.reverse_offset = times.softreboot_start_time;
93
94 /* Clamp all timestamps to avoid showing huge graphs */
95 if (timestamp_is_set(times.finish_time))
96 subtract_timestamp(&times.finish_time, times.reverse_offset);
97 subtract_timestamp(&times.userspace_time, times.reverse_offset);
98
99 subtract_timestamp(&times.generators_start_time, times.reverse_offset);
100 subtract_timestamp(&times.generators_finish_time, times.reverse_offset);
101
102 subtract_timestamp(&times.unitsload_start_time, times.reverse_offset);
103 subtract_timestamp(&times.unitsload_finish_time, times.reverse_offset);
104 } else if (arg_runtime_scope == RUNTIME_SCOPE_SYSTEM && timestamp_is_set(times.security_start_time)) {
113dd9cb
LP
105 /* security_start_time is set when systemd is not running under container environment. */
106 if (times.initrd_time > 0)
107 times.kernel_done_time = times.initrd_time;
108 else
109 times.kernel_done_time = times.userspace_time;
110 } else {
111 /*
112 * User-instance-specific or container-system-specific timestamps processing
113 * (see comment to reverse_offset in BootTimes).
114 */
115 times.reverse_offset = times.userspace_time;
116
117 times.firmware_time = times.loader_time = times.kernel_time = times.initrd_time =
118 times.userspace_time = times.security_start_time = times.security_finish_time = 0;
119
63d7632d
YW
120 if (times.finish_time > 0)
121 subtract_timestamp(&times.finish_time, times.reverse_offset);
113dd9cb
LP
122
123 subtract_timestamp(&times.generators_start_time, times.reverse_offset);
124 subtract_timestamp(&times.generators_finish_time, times.reverse_offset);
125
126 subtract_timestamp(&times.unitsload_start_time, times.reverse_offset);
127 subtract_timestamp(&times.unitsload_finish_time, times.reverse_offset);
128 }
129
130 cached = true;
131
63d7632d
YW
132 if (ret)
133 *ret = &times;
113dd9cb
LP
134 return 0;
135}
136
ba474dad
LP
137static int bus_get_uint64_property(sd_bus *bus, const char *path, const char *interface, const char *property, uint64_t *val) {
138 _cleanup_(sd_bus_error_free) sd_bus_error error = SD_BUS_ERROR_NULL;
139 int r;
140
141 assert(bus);
142 assert(path);
143 assert(interface);
144 assert(property);
145 assert(val);
146
147 r = sd_bus_get_property_trivial(
148 bus,
149 "org.freedesktop.systemd1",
150 path,
151 interface,
152 property,
153 &error,
154 't', val);
155 if (r < 0)
156 return log_error_errno(r, "Failed to parse reply: %s", bus_error_message(&error, r));
157
158 return 0;
159}
160
161int pretty_boot_time(sd_bus *bus, char **ret) {
dc4864dd
LP
162 _cleanup_(sd_bus_error_free) sd_bus_error error = SD_BUS_ERROR_NULL;
163 _cleanup_free_ char *path = NULL, *unit_id = NULL, *text = NULL;
164 usec_t activated_time = USEC_INFINITY;
ba474dad 165 BootTimes *t;
ba474dad 166 int r;
ba474dad 167
63d7632d 168 r = acquire_boot_times(bus, /* require_finished = */ true, &t);
ba474dad
LP
169 if (r < 0)
170 return r;
171
172 path = unit_dbus_path_from_name(SPECIAL_DEFAULT_TARGET);
173 if (!path)
174 return log_oom();
175
176 r = sd_bus_get_property_string(
177 bus,
178 "org.freedesktop.systemd1",
179 path,
180 "org.freedesktop.systemd1.Unit",
181 "Id",
182 &error,
183 &unit_id);
dc4864dd
LP
184 if (r < 0)
185 log_warning_errno(r, "default.target doesn't seem to exist, ignoring: %s", bus_error_message(&error, r));
ba474dad
LP
186
187 r = bus_get_uint64_property(bus, path,
188 "org.freedesktop.systemd1.Unit",
189 "ActiveEnterTimestampMonotonic",
190 &activated_time);
dc4864dd
LP
191 if (r < 0)
192 log_warning_errno(r, "Could not get time to reach default.target, ignoring: %m");
ba474dad 193
dc4864dd
LP
194 text = strdup("Startup finished in ");
195 if (!text)
196 return log_oom();
ba474dad 197
7bbfcf64 198 if (timestamp_is_set(t->firmware_time) && !strextend(&text, FORMAT_TIMESPAN(t->firmware_time - t->loader_time, USEC_PER_MSEC), " (firmware) + "))
dc4864dd 199 return log_oom();
7bbfcf64 200 if (timestamp_is_set(t->loader_time) && !strextend(&text, FORMAT_TIMESPAN(t->loader_time, USEC_PER_MSEC), " (loader) + "))
dc4864dd 201 return log_oom();
7bbfcf64 202 if (timestamp_is_set(t->kernel_done_time) && !strextend(&text, FORMAT_TIMESPAN(t->kernel_done_time, USEC_PER_MSEC), " (kernel) + "))
dc4864dd 203 return log_oom();
7bbfcf64 204 if (timestamp_is_set(t->initrd_time) && !strextend(&text, FORMAT_TIMESPAN(t->userspace_time - t->initrd_time, USEC_PER_MSEC), " (initrd) + "))
dc4864dd 205 return log_oom();
259046cf 206 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)
7addfba9 207 return log_oom();
dc4864dd
LP
208
209 if (!strextend(&text, FORMAT_TIMESPAN(t->finish_time - t->userspace_time, USEC_PER_MSEC), " (userspace) "))
210 return log_oom();
ba474dad 211
7bbfcf64 212 if (timestamp_is_set(t->kernel_done_time))
dc4864dd
LP
213 if (!strextend(&text, "= ", FORMAT_TIMESPAN(t->firmware_time + t->finish_time, USEC_PER_MSEC), " "))
214 return log_oom();
ba474dad
LP
215
216 if (unit_id && timestamp_is_set(activated_time)) {
e6bd341e
LB
217 usec_t base;
218
219 /* On soft-reboot times are clamped to avoid showing huge graphs */
220 if (timestamp_is_set(t->softreboot_start_time) && timestamp_is_set(t->userspace_time))
221 base = t->userspace_time + t->reverse_offset;
222 else
223 base = timestamp_is_set(t->userspace_time) ? t->userspace_time : t->reverse_offset;
ba474dad 224
dc4864dd
LP
225 if (!strextend(&text, "\n", unit_id, " reached after ", FORMAT_TIMESPAN(activated_time - base, USEC_PER_MSEC), " in userspace."))
226 return log_oom();
227
228 } else if (unit_id && activated_time == 0) {
229
230 if (!strextend(&text, "\n", unit_id, " was never reached."))
231 return log_oom();
232
233 } else if (unit_id && activated_time == USEC_INFINITY) {
234
235 if (!strextend(&text, "\nCould not get time to reach ", unit_id, "."))
236 return log_oom();
237
238 } else if (!unit_id) {
239
240 if (!strextend(&text, "\ncould not find default.target."))
241 return log_oom();
242 }
ba474dad 243
dc4864dd 244 *ret = TAKE_PTR(text);
ba474dad
LP
245 return 0;
246}
247
ebaf5549
JL
248void unit_times_clear(UnitTimes *t) {
249 if (!t)
250 return;
251
252 FOREACH_ARRAY(d, t->deps, ELEMENTSOF(t->deps))
253 *d = strv_free(*d);
254
255 t->name = mfree(t->name);
256}
257
113dd9cb
LP
258UnitTimes* unit_times_free_array(UnitTimes *t) {
259 if (!t)
260 return NULL;
261
262 for (UnitTimes *p = t; p->has_data; p++)
ebaf5549 263 unit_times_clear(p);
113dd9cb
LP
264
265 return mfree(t);
266}
267
ebaf5549
JL
268DEFINE_TRIVIAL_CLEANUP_FUNC_FULL(UnitTimes*, unit_times_clear, NULL);
269
63d7632d 270int acquire_time_data(sd_bus *bus, bool require_finished, UnitTimes **out) {
113dd9cb 271 static const struct bus_properties_map property_map[] = {
ebaf5549
JL
272 { "InactiveExitTimestampMonotonic", "t", NULL, offsetof(UnitTimes, activating) },
273 { "ActiveEnterTimestampMonotonic", "t", NULL, offsetof(UnitTimes, activated) },
274 { "ActiveExitTimestampMonotonic", "t", NULL, offsetof(UnitTimes, deactivating) },
275 { "InactiveEnterTimestampMonotonic", "t", NULL, offsetof(UnitTimes, deactivated) },
276 { "After", "as", NULL, offsetof(UnitTimes, deps[UNIT_AFTER]) },
277 { "Before", "as", NULL, offsetof(UnitTimes, deps[UNIT_BEFORE]) },
278 { "Requires", "as", NULL, offsetof(UnitTimes, deps[UNIT_REQUIRES]) },
279 { "Requisite", "as", NULL, offsetof(UnitTimes, deps[UNIT_REQUISITE]) },
280 { "Wants", "as", NULL, offsetof(UnitTimes, deps[UNIT_WANTS]) },
281 { "Conflicts", "as", NULL, offsetof(UnitTimes, deps[UNIT_CONFLICTS]) },
282 { "Upholds", "as", NULL, offsetof(UnitTimes, deps[UNIT_UPHOLDS]) },
113dd9cb
LP
283 {},
284 };
285 _cleanup_(sd_bus_message_unrefp) sd_bus_message *reply = NULL;
286 _cleanup_(sd_bus_error_free) sd_bus_error error = SD_BUS_ERROR_NULL;
287 _cleanup_(unit_times_free_arrayp) UnitTimes *unit_times = NULL;
63d7632d 288 BootTimes *boot_times;
113dd9cb
LP
289 size_t c = 0;
290 UnitInfo u;
291 int r;
292
63d7632d 293 r = acquire_boot_times(bus, require_finished, &boot_times);
113dd9cb
LP
294 if (r < 0)
295 return r;
296
297 r = bus_call_method(bus, bus_systemd_mgr, "ListUnits", &error, &reply, NULL);
298 if (r < 0)
299 return log_error_errno(r, "Failed to list units: %s", bus_error_message(&error, r));
300
301 r = sd_bus_message_enter_container(reply, SD_BUS_TYPE_ARRAY, "(ssssssouso)");
302 if (r < 0)
303 return bus_log_parse_error(r);
304
305 while ((r = bus_parse_unit_info(reply, &u)) > 0) {
ebaf5549 306 _cleanup_(unit_times_clearp) UnitTimes *t = NULL;
113dd9cb 307
ebaf5549 308 if (!GREEDY_REALLOC0(unit_times, c + 2))
113dd9cb
LP
309 return log_oom();
310
ebaf5549
JL
311 /* t initially has pointers zeroed by the allocation, and unit_times_clearp will have zeroed
312 * them if the entry is being reused. */
113dd9cb 313 t = &unit_times[c];
113dd9cb
LP
314
315 assert_cc(sizeof(usec_t) == sizeof(uint64_t));
316
317 r = bus_map_all_properties(
318 bus,
319 "org.freedesktop.systemd1",
320 u.unit_path,
321 property_map,
322 BUS_MAP_STRDUP,
323 &error,
324 NULL,
325 t);
326 if (r < 0)
327 return log_error_errno(r, "Failed to get timestamp properties of unit %s: %s",
328 u.id, bus_error_message(&error, r));
329
e6bd341e
LB
330 /* Activated in the previous soft-reboot iteration? Ignore it, we want new activations */
331 if ((t->activated > 0 && t->activated < boot_times->softreboot_start_time) ||
332 (t->activating > 0 && t->activating < boot_times->softreboot_start_time))
333 continue;
334
113dd9cb
LP
335 subtract_timestamp(&t->activating, boot_times->reverse_offset);
336 subtract_timestamp(&t->activated, boot_times->reverse_offset);
e6bd341e
LB
337
338 /* If the last deactivation was in the previous soft-reboot, ignore it */
339 if (timestamp_is_set(boot_times->softreboot_start_time)) {
340 if (t->deactivating < boot_times->reverse_offset)
341 t->deactivating = 0;
342 else
343 subtract_timestamp(&t->deactivating, boot_times->reverse_offset);
344 if (t->deactivated < boot_times->reverse_offset)
345 t->deactivated = 0;
346 else
347 subtract_timestamp(&t->deactivated, boot_times->reverse_offset);
348 } else {
349 subtract_timestamp(&t->deactivating, boot_times->reverse_offset);
350 subtract_timestamp(&t->deactivated, boot_times->reverse_offset);
351 }
113dd9cb
LP
352
353 if (t->activated >= t->activating)
354 t->time = t->activated - t->activating;
355 else if (t->deactivated >= t->activating)
356 t->time = t->deactivated - t->activating;
357 else
358 t->time = 0;
359
360 if (t->activating == 0)
361 continue;
362
363 t->name = strdup(u.id);
364 if (!t->name)
365 return log_oom();
366
367 t->has_data = true;
ebaf5549
JL
368 /* Prevent destructor from running on t reference. */
369 TAKE_PTR(t);
113dd9cb
LP
370 c++;
371 }
372 if (r < 0)
373 return bus_log_parse_error(r);
374
375 *out = TAKE_PTR(unit_times);
376 return c;
377}