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