]>
Commit | Line | Data |
---|---|---|
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 | |
13 | static 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 |
22 | static 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 | ||
31 | int 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 = × | |
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 | ×); | |
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(×.finish_time, times.reverse_offset); | |
97 | subtract_timestamp(×.userspace_time, times.reverse_offset); | |
98 | ||
99 | subtract_timestamp(×.generators_start_time, times.reverse_offset); | |
100 | subtract_timestamp(×.generators_finish_time, times.reverse_offset); | |
101 | ||
102 | subtract_timestamp(×.unitsload_start_time, times.reverse_offset); | |
103 | subtract_timestamp(×.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(×.finish_time, times.reverse_offset); | |
113dd9cb LP |
122 | |
123 | subtract_timestamp(×.generators_start_time, times.reverse_offset); | |
124 | subtract_timestamp(×.generators_finish_time, times.reverse_offset); | |
125 | ||
126 | subtract_timestamp(×.unitsload_start_time, times.reverse_offset); | |
127 | subtract_timestamp(×.unitsload_finish_time, times.reverse_offset); | |
128 | } | |
129 | ||
130 | cached = true; | |
131 | ||
63d7632d YW |
132 | if (ret) |
133 | *ret = × | |
113dd9cb LP |
134 | return 0; |
135 | } | |
136 | ||
ba474dad LP |
137 | static 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 | ||
161 | int 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 |
248 | void 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 |
258 | UnitTimes* 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 |
268 | DEFINE_TRIVIAL_CLEANUP_FUNC_FULL(UnitTimes*, unit_times_clear, NULL); |
269 | ||
63d7632d | 270 | int 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 | } |