1 /*
2 * Copyright (C) 2016 The Android Open Source Project
3 *
4 * Licensed under the Apache License, Version 2.0 (the "License");
5 * you may not use this file except in compliance with the License.
6 * You may obtain a copy of the License at
7 *
8 * http://www.apache.org/licenses/LICENSE-2.0
9 *
10 * Unless required by applicable law or agreed to in writing, software
11 * distributed under the License is distributed on an "AS IS" BASIS,
12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13 * See the License for the specific language governing permissions and
14 * limitations under the License.
15 */
16
17 // The bootstat command provides options to persist boot events with the current
18 // timestamp, dump the persisted events, and log all events to EventLog to be
19 // uploaded to Android log storage via Tron.
20
21 #include <getopt.h>
22 #include <sys/klog.h>
23 #include <unistd.h>
24
25 #include <chrono>
26 #include <cmath>
27 #include <cstddef>
28 #include <cstdio>
29 #include <ctime>
30 #include <iterator>
31 #include <map>
32 #include <memory>
33 #include <regex>
34 #include <string>
35 #include <string_view>
36 #include <unordered_map>
37 #include <utility>
38 #include <vector>
39
40 #include <android-base/chrono_utils.h>
41 #include <android-base/file.h>
42 #include <android-base/logging.h>
43 #include <android-base/parseint.h>
44 #include <android-base/properties.h>
45 #include <android-base/strings.h>
46 #include <android/log.h>
47 #include <cutils/android_reboot.h>
48 #include <cutils/properties.h>
49 #include <statslog.h>
50
51 #include "boot_event_record_store.h"
52
53 namespace {
54
55 struct AtomInfo {
56 int32_t atom;
57 int32_t event;
58 };
59
60 // Maps BootEvent used inside bootstat into statsd atom defined in
61 // frameworks/proto_logging/stats/atoms.proto.
62 const std::unordered_map<std::string_view, AtomInfo> kBootEventToAtomInfo = {
63 // ELAPSED_TIME
64 {"ro.boottime.init",
65 {android::util::BOOT_TIME_EVENT_ELAPSED_TIME_REPORTED,
66 android::util::BOOT_TIME_EVENT_ELAPSED_TIME__EVENT__ANDROID_INIT_STAGE_1}},
67 {"boot_complete",
68 {android::util::BOOT_TIME_EVENT_ELAPSED_TIME_REPORTED,
69 android::util::BOOT_TIME_EVENT_ELAPSED_TIME__EVENT__BOOT_COMPLETE}},
70 {"boot_complete_no_encryption",
71 {android::util::BOOT_TIME_EVENT_ELAPSED_TIME_REPORTED,
72 android::util::BOOT_TIME_EVENT_ELAPSED_TIME__EVENT__BOOT_COMPLETE_NO_ENCRYPTION}},
73 {"factory_reset_boot_complete",
74 {android::util::BOOT_TIME_EVENT_ELAPSED_TIME_REPORTED,
75 android::util::BOOT_TIME_EVENT_ELAPSED_TIME__EVENT__FACTORY_RESET_BOOT_COMPLETE}},
76 {"factory_reset_boot_complete_no_encryption",
77 {android::util::BOOT_TIME_EVENT_ELAPSED_TIME_REPORTED,
78 android::util::
79 BOOT_TIME_EVENT_ELAPSED_TIME__EVENT__FACTORY_RESET_BOOT_COMPLETE_NO_ENCRYPTION}},
80 {"ota_boot_complete",
81 {android::util::BOOT_TIME_EVENT_ELAPSED_TIME_REPORTED,
82 android::util::BOOT_TIME_EVENT_ELAPSED_TIME__EVENT__OTA_BOOT_COMPLETE}},
83 {"ota_boot_complete_no_encryption",
84 {android::util::BOOT_TIME_EVENT_ELAPSED_TIME_REPORTED,
85 android::util::BOOT_TIME_EVENT_ELAPSED_TIME__EVENT__OTA_BOOT_COMPLETE_NO_ENCRYPTION}},
86 // DURATION
87 {"absolute_boot_time",
88 {android::util::BOOT_TIME_EVENT_DURATION_REPORTED,
89 android::util::BOOT_TIME_EVENT_DURATION__EVENT__ABSOLUTE_BOOT_TIME}},
90 {"boottime.bootloader.1BLE",
91 {android::util::BOOT_TIME_EVENT_DURATION_REPORTED,
92 android::util::BOOT_TIME_EVENT_DURATION__EVENT__BOOTLOADER_FIRST_STAGE_EXEC}},
93 {"boottime.bootloader.1BLL",
94 {android::util::BOOT_TIME_EVENT_DURATION_REPORTED,
95 android::util::BOOT_TIME_EVENT_DURATION__EVENT__BOOTLOADER_FIRST_STAGE_LOAD}},
96 {"boottime.bootloader.KL",
97 {android::util::BOOT_TIME_EVENT_DURATION_REPORTED,
98 android::util::BOOT_TIME_EVENT_DURATION__EVENT__BOOTLOADER_KERNEL_LOAD}},
99 {"boottime.bootloader.2BLE",
100 {android::util::BOOT_TIME_EVENT_DURATION_REPORTED,
101 android::util::BOOT_TIME_EVENT_DURATION__EVENT__BOOTLOADER_SECOND_STAGE_EXEC}},
102 {"boottime.bootloader.2BLL",
103 {android::util::BOOT_TIME_EVENT_DURATION_REPORTED,
104 android::util::BOOT_TIME_EVENT_DURATION__EVENT__BOOTLOADER_SECOND_STAGE_LOAD}},
105 {"boottime.bootloader.SW",
106 {android::util::BOOT_TIME_EVENT_DURATION_REPORTED,
107 android::util::BOOT_TIME_EVENT_DURATION__EVENT__BOOTLOADER_UI_WAIT}},
108 {"boottime.bootloader.total",
109 {android::util::BOOT_TIME_EVENT_DURATION_REPORTED,
110 android::util::BOOT_TIME_EVENT_DURATION__EVENT__BOOTLOADER_TOTAL}},
111 {"boottime.init.cold_boot_wait",
112 {android::util::BOOT_TIME_EVENT_DURATION_REPORTED,
113 android::util::BOOT_TIME_EVENT_DURATION__EVENT__COLDBOOT_WAIT}},
114 {"time_since_factory_reset",
115 {android::util::BOOT_TIME_EVENT_DURATION_REPORTED,
116 android::util::BOOT_TIME_EVENT_DURATION__EVENT__FACTORY_RESET_TIME_SINCE_RESET}},
117 {"ro.boottime.init.first_stage",
118 {android::util::BOOT_TIME_EVENT_DURATION_REPORTED,
119 android::util::BOOT_TIME_EVENT_DURATION__EVENT__ANDROID_INIT_STAGE_1}},
120 {"ro.boottime.init.selinux",
121 {android::util::BOOT_TIME_EVENT_DURATION_REPORTED,
122 android::util::BOOT_TIME_EVENT_DURATION__EVENT__SELINUX_INIT}},
123 // UTC_TIME
124 {"factory_reset",
125 {android::util::BOOT_TIME_EVENT_UTC_TIME_REPORTED,
126 android::util::BOOT_TIME_EVENT_UTC_TIME__EVENT__FACTORY_RESET_RESET_TIME}},
127 {"factory_reset_current_time",
128 {android::util::BOOT_TIME_EVENT_UTC_TIME_REPORTED,
129 android::util::BOOT_TIME_EVENT_UTC_TIME__EVENT__FACTORY_RESET_CURRENT_TIME}},
130 {"factory_reset_record_value",
131 {android::util::BOOT_TIME_EVENT_UTC_TIME_REPORTED,
132 android::util::BOOT_TIME_EVENT_UTC_TIME__EVENT__FACTORY_RESET_RECORD_VALUE}},
133 // ERROR_CODE
134 {"factory_reset_current_time_failure",
135 {android::util::BOOT_TIME_EVENT_ERROR_CODE_REPORTED,
136 android::util::BOOT_TIME_EVENT_ERROR_CODE__EVENT__FACTORY_RESET_CURRENT_TIME_FAILURE}},
137 };
138
139 // Scans the boot event record store for record files and logs each boot event
140 // via EventLog.
LogBootEvents()141 void LogBootEvents() {
142 BootEventRecordStore boot_event_store;
143 auto events = boot_event_store.GetAllBootEvents();
144 std::vector<std::string_view> notSupportedEvents;
145 for (const auto& event : events) {
146 const auto& name = event.first;
147 const auto& info = kBootEventToAtomInfo.find(name);
148 if (info != kBootEventToAtomInfo.end()) {
149 if (info->second.atom == android::util::BOOT_TIME_EVENT_ERROR_CODE_REPORTED) {
150 android::util::stats_write(static_cast<int32_t>(info->second.atom),
151 static_cast<int32_t>(info->second.event),
152 static_cast<int32_t>(event.second));
153 } else {
154 android::util::stats_write(static_cast<int32_t>(info->second.atom),
155 static_cast<int32_t>(info->second.event),
156 static_cast<int64_t>(event.second));
157 }
158 } else {
159 notSupportedEvents.push_back(name);
160 }
161 }
162 if (!notSupportedEvents.empty()) {
163 LOG(WARNING) << "LogBootEvents, atomInfo not defined for events:"
164 << android::base::Join(notSupportedEvents, ',');
165 }
166 }
167
168 // Records the named boot |event| to the record store. If |value| is non-empty
169 // and is a proper string representation of an integer value, the converted
170 // integer value is associated with the boot event.
RecordBootEventFromCommandLine(const std::string & event,const std::string & value_str)171 void RecordBootEventFromCommandLine(const std::string& event, const std::string& value_str) {
172 BootEventRecordStore boot_event_store;
173 if (!value_str.empty()) {
174 int32_t value = 0;
175 if (android::base::ParseInt(value_str, &value)) {
176 boot_event_store.AddBootEventWithValue(event, value);
177 }
178 } else {
179 boot_event_store.AddBootEvent(event);
180 }
181 }
182
PrintBootEvents()183 void PrintBootEvents() {
184 printf("Boot events:\n");
185 printf("------------\n");
186
187 BootEventRecordStore boot_event_store;
188 auto events = boot_event_store.GetAllBootEvents();
189 for (auto i = events.cbegin(); i != events.cend(); ++i) {
190 printf("%s\t%d\n", i->first.c_str(), i->second);
191 }
192 }
193
ShowHelp(const char * cmd)194 void ShowHelp(const char* cmd) {
195 fprintf(stderr, "Usage: %s [options]...\n", cmd);
196 fprintf(stderr,
197 "options include:\n"
198 " -h, --help Show this help\n"
199 " -l, --log Log all metrics to logstorage\n"
200 " -p, --print Dump the boot event records to the console\n"
201 " -r, --record Record the timestamp of a named boot event\n"
202 " --value Optional value to associate with the boot event\n"
203 " --record_boot_complete Record metrics related to the time for the device boot\n"
204 " --record_boot_reason Record the reason why the device booted\n"
205 " --record_time_since_factory_reset Record the time since the device was reset\n"
206 " --boot_reason_enum=<reason> Report the match to the kBootReasonMap table\n");
207 }
208
209 // Constructs a readable, printable string from the givencommand line
210 // arguments.
GetCommandLine(int argc,char ** argv)211 std::string GetCommandLine(int argc, char** argv) {
212 std::string cmd;
213 for (int i = 0; i < argc; ++i) {
214 cmd += argv[i];
215 cmd += " ";
216 }
217
218 return cmd;
219 }
220
221 constexpr int32_t kEmptyBootReason = 0;
222 constexpr int32_t kUnknownBootReason = 1;
223
224 // A mapping from boot reason string, as read from the ro.boot.bootreason
225 // system property, to a unique integer ID. Viewers of log data dashboards for
226 // the boot_reason metric may refer to this mapping to discern the histogram
227 // values. Regex matching, to manage the scale, as a minimum require either
228 // [, \ or * to be present in the string to switch to checking.
229 const std::map<std::string, int32_t> kBootReasonMap = {
230 {"reboot,[empty]", kEmptyBootReason},
231 {"__BOOTSTAT_UNKNOWN__", kUnknownBootReason},
232 {"normal", 2},
233 {"recovery", 3},
234 {"reboot", 4},
235 {"PowerKey", 5},
236 {"hard_reset", 6},
237 {"kernel_panic", 7},
238 {"rpm_err", 8},
239 {"hw_reset", 9},
240 {"tz_err", 10},
241 {"adsp_err", 11},
242 {"modem_err", 12},
243 {"mba_err", 13},
244 {"Watchdog", 14},
245 {"Panic", 15},
246 {"power_key", 16}, // aliasReasons to cold,powerkey (Mediatek)
247 {"power_on", 17}, // aliasReasons to cold,powerkey
248 {"Reboot", 18},
249 {"rtc", 19},
250 {"edl", 20},
251 {"oem_pon1", 21},
252 {"oem_powerkey", 22}, // aliasReasons to cold,powerkey
253 {"oem_unknown_reset", 23},
254 {"srto: HWWDT reset SC", 24},
255 {"srto: HWWDT reset platform", 25},
256 {"srto: bootloader", 26},
257 {"srto: kernel panic", 27},
258 {"srto: kernel watchdog reset", 28},
259 {"srto: normal", 29},
260 {"srto: reboot", 30},
261 {"srto: reboot-bootloader", 31},
262 {"srto: security watchdog reset", 32},
263 {"srto: wakesrc", 33},
264 {"srto: watchdog", 34},
265 {"srto:1-1", 35},
266 {"srto:omap_hsmm", 36},
267 {"srto:phy0", 37},
268 {"srto:rtc0", 38},
269 {"srto:touchpad", 39},
270 {"watchdog", 40},
271 {"watchdogr", 41},
272 {"wdog_bark", 42},
273 {"wdog_bite", 43},
274 {"wdog_reset", 44},
275 {"shutdown,", 45}, // Trailing comma is intentional. Do NOT use.
276 {"shutdown,userrequested", 46},
277 {"reboot,bootloader", 47},
278 {"reboot,cold", 48},
279 {"reboot,recovery", 49},
280 {"thermal_shutdown", 50},
281 {"s3_wakeup", 51},
282 {"kernel_panic,sysrq", 52},
283 {"kernel_panic,NULL", 53},
284 {"kernel_panic,null", 53},
285 {"kernel_panic,BUG", 54},
286 {"kernel_panic,bug", 54},
287 {"bootloader", 55},
288 {"cold", 56},
289 {"hard", 57},
290 {"warm", 58},
291 {"reboot,kernel_power_off_charging__reboot_system", 59}, // Can not happen
292 {"thermal-shutdown", 60},
293 {"shutdown,thermal", 61},
294 {"shutdown,battery", 62},
295 {"reboot,ota", 63},
296 {"reboot,factory_reset", 64},
297 {"reboot,", 65},
298 {"reboot,shell", 66},
299 {"reboot,adb", 67},
300 {"reboot,userrequested", 68},
301 {"shutdown,container", 69}, // Host OS asking Android Container to shutdown
302 {"cold,powerkey", 70},
303 {"warm,s3_wakeup", 71},
304 {"hard,hw_reset", 72},
305 {"shutdown,suspend", 73}, // Suspend to RAM
306 {"shutdown,hibernate", 74}, // Suspend to DISK
307 {"power_on_key", 75}, // aliasReasons to cold,powerkey
308 {"reboot_by_key", 76}, // translated to reboot,by_key
309 {"wdt_by_pass_pwk", 77}, // Mediatek
310 {"reboot_longkey", 78}, // translated to reboot,longkey
311 {"powerkey", 79}, // aliasReasons to cold,powerkey
312 {"usb", 80}, // aliasReasons to cold,charger (Mediatek)
313 {"wdt", 81}, // Mediatek
314 {"tool_by_pass_pwk", 82}, // aliasReasons to reboot,tool (Mediatek)
315 {"2sec_reboot", 83}, // aliasReasons to cold,rtc,2sec (Mediatek)
316 {"reboot,by_key", 84},
317 {"reboot,longkey", 85},
318 {"reboot,2sec", 86}, // Deprecate in two years, replaced with cold,rtc,2sec
319 {"shutdown,thermal,battery", 87},
320 {"reboot,its_just_so_hard", 88}, // produced by boot_reason_test
321 {"reboot,Its Just So Hard", 89}, // produced by boot_reason_test
322 {"reboot,rescueparty", 90},
323 {"charge", 91},
324 {"oem_tz_crash", 92},
325 {"uvlo", 93}, // aliasReasons to reboot,undervoltage
326 {"oem_ps_hold", 94},
327 {"abnormal_reset", 95},
328 {"oemerr_unknown", 96},
329 {"reboot_fastboot_mode", 97},
330 {"watchdog_apps_bite", 98},
331 {"xpu_err", 99},
332 {"power_on_usb", 100}, // aliasReasons to cold,charger
333 {"watchdog_rpm", 101},
334 {"watchdog_nonsec", 102},
335 {"watchdog_apps_bark", 103},
336 {"reboot_dmverity_corrupted", 104},
337 {"reboot_smpl", 105}, // aliasReasons to reboot,powerloss
338 {"watchdog_sdi_apps_reset", 106},
339 {"smpl", 107}, // aliasReasons to reboot,powerloss
340 {"oem_modem_failed_to_powerup", 108},
341 {"reboot_normal", 109},
342 {"oem_lpass_cfg", 110},
343 {"oem_xpu_ns_error", 111},
344 {"power_key_press", 112}, // aliasReasons to cold,powerkey
345 {"hardware_reset", 113},
346 {"reboot_by_powerkey", 114}, // aliasReasons to cold,powerkey (is this correct?)
347 {"reboot_verity", 115},
348 {"oem_rpm_undef_error", 116},
349 {"oem_crash_on_the_lk", 117},
350 {"oem_rpm_reset", 118},
351 {"reboot,powerloss", 119},
352 {"reboot,undervoltage", 120},
353 {"factory_cable", 121},
354 {"oem_ar6320_failed_to_powerup", 122},
355 {"watchdog_rpm_bite", 123},
356 {"power_on_cable", 124}, // aliasReasons to cold,charger
357 {"reboot_unknown", 125},
358 {"wireless_charger", 126},
359 {"0x776655ff", 127},
360 {"oem_thermal_bite_reset", 128},
361 {"charger", 129},
362 {"pon1", 130},
363 {"unknown", 131},
364 {"reboot_rtc", 132},
365 {"cold_boot", 133},
366 {"hard_rst", 134},
367 {"power-on", 135},
368 {"oem_adsp_resetting_the_soc", 136},
369 {"kpdpwr", 137},
370 {"oem_modem_timeout_waiting", 138},
371 {"usb_chg", 139},
372 {"warm_reset_0x02", 140},
373 {"warm_reset_0x80", 141},
374 {"pon_reason_0xb0", 142},
375 {"reboot_download", 143},
376 {"reboot_recovery_mode", 144},
377 {"oem_sdi_err_fatal", 145},
378 {"pmic_watchdog", 146},
379 {"software_master", 147},
380 {"cold,charger", 148},
381 {"cold,rtc", 149},
382 {"cold,rtc,2sec", 150}, // Mediatek
383 {"reboot,tool", 151}, // Mediatek
384 {"reboot,wdt", 152}, // Mediatek
385 {"reboot,unknown", 153}, // Mediatek
386 {"kernel_panic,audit", 154},
387 {"kernel_panic,atomic", 155},
388 {"kernel_panic,hung", 156},
389 {"kernel_panic,hung,rcu", 157},
390 {"kernel_panic,init", 158},
391 {"kernel_panic,oom", 159},
392 {"kernel_panic,stack", 160},
393 {"kernel_panic,sysrq,livelock,alarm", 161}, // llkd
394 {"kernel_panic,sysrq,livelock,driver", 162}, // llkd
395 {"kernel_panic,sysrq,livelock,zombie", 163}, // llkd
396 {"kernel_panic,modem", 164},
397 {"kernel_panic,adsp", 165},
398 {"kernel_panic,dsps", 166},
399 {"kernel_panic,wcnss", 167},
400 {"kernel_panic,_sde_encoder_phys_cmd_handle_ppdone_timeout", 168},
401 {"recovery,quiescent", 169},
402 {"reboot,quiescent", 170},
403 {"reboot,rtc", 171},
404 {"reboot,dm-verity_device_corrupted", 172},
405 {"reboot,dm-verity_enforcing", 173},
406 {"reboot,keys_clear", 174},
407 {"reboot,pmic_off_fault,.*", 175},
408 {"reboot,pmic_off_s3rst,.*", 176},
409 {"reboot,pmic_off_other,.*", 177},
410 {"reboot,userrequested,fastboot", 178},
411 {"reboot,userrequested,recovery", 179},
412 {"reboot,userrequested,recovery,ui", 180},
413 {"shutdown,userrequested,fastboot", 181},
414 {"shutdown,userrequested,recovery", 182},
415 {"reboot,unknown[0-9]*", 183},
416 {"reboot,longkey,.*", 184},
417 {"reboot,boringssl-self-check-failed", 185},
418 {"reboot,userspace_failed,shutdown_aborted", 186},
419 {"reboot,userspace_failed,watchdog_triggered", 187},
420 {"reboot,userspace_failed,watchdog_fork", 188},
421 {"reboot,userspace_failed,*", 189},
422 {"reboot,mount_userdata_failed", 190},
423 {"reboot,forcedsilent", 191},
424 {"reboot,forcednonsilent", 192},
425 {"reboot,thermal,tj", 193},
426 {"reboot,emergency", 194},
427 {"reboot,factory", 195},
428 {"reboot,fastboot", 196},
429 {"reboot,gsa,hard", 197},
430 {"reboot,gsa,soft", 198},
431 {"reboot,master_dc,fault_n", 199},
432 {"reboot,master_dc,reset", 200},
433 {"reboot,ocp", 201},
434 {"reboot,pin", 202},
435 {"reboot,rom_recovery", 203},
436 {"reboot,uvlo", 204},
437 {"reboot,uvlo,pmic,if", 205},
438 {"reboot,uvlo,pmic,main", 206},
439 {"reboot,uvlo,pmic,sub", 207},
440 {"reboot,warm", 208},
441 {"watchdog,aoc", 209},
442 {"watchdog,apc", 210},
443 {"watchdog,apc,bl,debug,early", 211},
444 {"watchdog,apc,bl,early", 212},
445 {"watchdog,apc,early", 213},
446 {"watchdog,apm", 214},
447 {"watchdog,gsa,hard", 215},
448 {"watchdog,gsa,soft", 216},
449 {"watchdog,pmucal", 217},
450 {"reboot,early,bl", 218},
451 {"watchdog,apc,gsa,crashed", 219},
452 {"watchdog,apc,bl31,crashed", 220},
453 {"watchdog,apc,pbl,crashed", 221},
454 {"reboot,memory_protect,hyp", 222},
455 {"reboot,tsd,pmic,main", 223},
456 {"reboot,tsd,pmic,sub", 224},
457 {"reboot,ocp,pmic,main", 225},
458 {"reboot,ocp,pmic,sub", 226},
459 {"reboot,sys_ldo_ok,pmic,main", 227},
460 {"reboot,sys_ldo_ok,pmic,sub", 228},
461 {"reboot,smpl_timeout,pmic,main", 229},
462 {"reboot,ota,.*", 230},
463 {"reboot,periodic,.*", 231},
464 {"reboot,early,abl", 232},
465 {"reboot,early,bl2", 233},
466 {"reboot,longkey,pmic_cold", 234},
467 {"reboot,longkey,master_dc", 235},
468 {"reboot,ocp2,pmic,if", 236},
469 {"reboot,ocp,pmic,if", 237},
470 {"reboot,fship.*", 238},
471 {"reboot,ocp,.*", 239},
472 {"reboot,ntc,pmic,sub", 240},
473 };
474
475 // Converts a string value representing the reason the system booted to an
476 // integer representation. This is necessary for logging the boot_reason metric
477 // via Tron, which does not accept non-integer buckets in histograms.
BootReasonStrToEnum(const std::string & boot_reason)478 int32_t BootReasonStrToEnum(const std::string& boot_reason) {
479 auto mapping = kBootReasonMap.find(boot_reason);
480 if (mapping != kBootReasonMap.end()) {
481 return mapping->second;
482 }
483
484 if (boot_reason.empty()) {
485 return kEmptyBootReason;
486 }
487
488 for (const auto& [match, id] : kBootReasonMap) {
489 // Regex matches as a minimum require either [, \ or * to be present.
490 if (match.find_first_of("[\\*") == match.npos) continue;
491 // enforce match from beginning to end
492 auto exact = match;
493 if (exact[0] != '^') exact = "^" + exact;
494 if (exact[exact.size() - 1] != '$') exact = exact + "$";
495 if (std::regex_search(boot_reason, std::regex(exact))) return id;
496 }
497
498 LOG(INFO) << "Unknown boot reason: " << boot_reason;
499 return kUnknownBootReason;
500 }
501
502 // Canonical list of supported primary reboot reasons.
503 const std::vector<std::string> knownReasons = {
504 // clang-format off
505 // kernel
506 "watchdog",
507 "kernel_panic",
508 // strong
509 "recovery", // Should not happen from ro.boot.bootreason
510 "bootloader", // Should not happen from ro.boot.bootreason
511 // blunt
512 "cold",
513 "hard",
514 "warm",
515 // super blunt
516 "shutdown", // Can not happen from ro.boot.bootreason
517 "reboot", // Default catch-all for anything unknown
518 // clang-format on
519 };
520
521 // Returns true if the supplied reason prefix is considered detailed enough.
isStrongRebootReason(const std::string & r)522 bool isStrongRebootReason(const std::string& r) {
523 for (auto& s : knownReasons) {
524 if (s == "cold") break;
525 // Prefix defined as terminated by a nul or comma (,).
526 if (android::base::StartsWith(r, s) && ((r.length() == s.length()) || (r[s.length()] == ','))) {
527 return true;
528 }
529 }
530 return false;
531 }
532
533 // Returns true if the supplied reason prefix is associated with the kernel.
isKernelRebootReason(const std::string & r)534 bool isKernelRebootReason(const std::string& r) {
535 for (auto& s : knownReasons) {
536 if (s == "recovery") break;
537 // Prefix defined as terminated by a nul or comma (,).
538 if (android::base::StartsWith(r, s) && ((r.length() == s.length()) || (r[s.length()] == ','))) {
539 return true;
540 }
541 }
542 return false;
543 }
544
545 // Returns true if the supplied reason prefix is considered known.
isKnownRebootReason(const std::string & r)546 bool isKnownRebootReason(const std::string& r) {
547 for (auto& s : knownReasons) {
548 // Prefix defined as terminated by a nul or comma (,).
549 if (android::base::StartsWith(r, s) && ((r.length() == s.length()) || (r[s.length()] == ','))) {
550 return true;
551 }
552 }
553 return false;
554 }
555
556 // If the reboot reason should be improved, report true if is too blunt.
isBluntRebootReason(const std::string & r)557 bool isBluntRebootReason(const std::string& r) {
558 if (isStrongRebootReason(r)) return false;
559
560 if (!isKnownRebootReason(r)) return true; // Can not support unknown as detail
561
562 size_t pos = 0;
563 while ((pos = r.find(',', pos)) != std::string::npos) {
564 ++pos;
565 std::string next(r.substr(pos));
566 if (next.length() == 0) break;
567 if (next[0] == ',') continue;
568 if (!isKnownRebootReason(next)) return false; // Unknown subreason is good.
569 if (isStrongRebootReason(next)) return false; // eg: reboot,reboot
570 }
571 return true;
572 }
573
readPstoreConsole(std::string & console)574 bool readPstoreConsole(std::string& console) {
575 if (android::base::ReadFileToString("/sys/fs/pstore/console-ramoops-0", &console)) {
576 return true;
577 }
578 return android::base::ReadFileToString("/sys/fs/pstore/console-ramoops", &console);
579 }
580
581 // Implement a variant of std::string::rfind that is resilient to errors in
582 // the data stream being inspected.
583 class pstoreConsole {
584 private:
585 const size_t kBitErrorRate = 8; // number of bits per error
586 const std::string& console;
587
588 // Number of bits that differ between the two arguments l and r.
589 // Returns zero if the values for l and r are identical.
numError(uint8_t l,uint8_t r) const590 size_t numError(uint8_t l, uint8_t r) const { return std::bitset<8>(l ^ r).count(); }
591
592 // A string comparison function, reports the number of errors discovered
593 // in the match to a maximum of the bitLength / kBitErrorRate, at that
594 // point returning npos to indicate match is too poor.
595 //
596 // Since called in rfind which works backwards, expect cache locality will
597 // help if we check in reverse here as well for performance.
598 //
599 // Assumption: l (from console.c_str() + pos) is long enough to house
600 // _r.length(), checked in rfind caller below.
601 //
numError(size_t pos,const std::string & _r) const602 size_t numError(size_t pos, const std::string& _r) const {
603 const char* l = console.c_str() + pos;
604 const char* r = _r.c_str();
605 size_t n = _r.length();
606 const uint8_t* le = reinterpret_cast<const uint8_t*>(l) + n;
607 const uint8_t* re = reinterpret_cast<const uint8_t*>(r) + n;
608 size_t count = 0;
609 n = 0;
610 do {
611 // individual character bit error rate > threshold + slop
612 size_t num = numError(*--le, *--re);
613 if (num > ((8 + kBitErrorRate) / kBitErrorRate)) return std::string::npos;
614 // total bit error rate > threshold + slop
615 count += num;
616 ++n;
617 if (count > ((n * 8 + kBitErrorRate - (n > 2)) / kBitErrorRate)) {
618 return std::string::npos;
619 }
620 } while (le != reinterpret_cast<const uint8_t*>(l));
621 return count;
622 }
623
624 public:
pstoreConsole(const std::string & console)625 explicit pstoreConsole(const std::string& console) : console(console) {}
626 // scope of argument must be equal to or greater than scope of pstoreConsole
627 explicit pstoreConsole(const std::string&& console) = delete;
628 explicit pstoreConsole(std::string&& console) = delete;
629
630 // Our implementation of rfind, use exact match first, then resort to fuzzy.
rfind(const std::string & needle) const631 size_t rfind(const std::string& needle) const {
632 size_t pos = console.rfind(needle); // exact match?
633 if (pos != std::string::npos) return pos;
634
635 // Check to make sure needle fits in console string.
636 pos = console.length();
637 if (needle.length() > pos) return std::string::npos;
638 pos -= needle.length();
639 // fuzzy match to maximum kBitErrorRate
640 for (;;) {
641 if (numError(pos, needle) != std::string::npos) return pos;
642 if (pos == 0) break;
643 --pos;
644 }
645 return std::string::npos;
646 }
647
648 // Our implementation of find, use only fuzzy match.
find(const std::string & needle,size_t start=0) const649 size_t find(const std::string& needle, size_t start = 0) const {
650 // Check to make sure needle fits in console string.
651 if (needle.length() > console.length()) return std::string::npos;
652 const size_t last_pos = console.length() - needle.length();
653 // fuzzy match to maximum kBitErrorRate
654 for (size_t pos = start; pos <= last_pos; ++pos) {
655 if (numError(pos, needle) != std::string::npos) return pos;
656 }
657 return std::string::npos;
658 }
659
operator const std::string&() const660 operator const std::string&() const { return console; }
661 };
662
663 // If bit error match to needle, correct it.
664 // Return true if any corrections were discovered and applied.
correctForBitError(std::string & reason,const std::string & needle)665 bool correctForBitError(std::string& reason, const std::string& needle) {
666 bool corrected = false;
667 if (reason.length() < needle.length()) return corrected;
668 const pstoreConsole console(reason);
669 const size_t last_pos = reason.length() - needle.length();
670 for (size_t pos = 0; pos <= last_pos; pos += needle.length()) {
671 pos = console.find(needle, pos);
672 if (pos == std::string::npos) break;
673
674 // exact match has no malice
675 if (needle == reason.substr(pos, needle.length())) continue;
676
677 corrected = true;
678 reason = reason.substr(0, pos) + needle + reason.substr(pos + needle.length());
679 }
680 return corrected;
681 }
682
683 // If bit error match to needle, correct it.
684 // Return true if any corrections were discovered and applied.
685 // Try again if we can replace underline with spaces.
correctForBitErrorOrUnderline(std::string & reason,const std::string & needle)686 bool correctForBitErrorOrUnderline(std::string& reason, const std::string& needle) {
687 bool corrected = correctForBitError(reason, needle);
688 std::string _needle(needle);
689 std::transform(_needle.begin(), _needle.end(), _needle.begin(),
690 [](char c) { return (c == '_') ? ' ' : c; });
691 if (needle != _needle) {
692 corrected |= correctForBitError(reason, _needle);
693 }
694 return corrected;
695 }
696
697 // Converts a string value representing the reason the system booted to a
698 // string complying with Android system standard reason.
transformReason(std::string & reason)699 void transformReason(std::string& reason) {
700 std::transform(reason.begin(), reason.end(), reason.begin(), ::tolower);
701 std::transform(reason.begin(), reason.end(), reason.begin(),
702 [](char c) { return ::isblank(c) ? '_' : c; });
703 std::transform(reason.begin(), reason.end(), reason.begin(),
704 [](char c) { return ::isprint(c) ? c : '?'; });
705 }
706
707 // Check subreasons for reboot,<subreason> kernel_panic,sysrq,<subreason> or
708 // kernel_panic,<subreason>.
709 //
710 // If quoted flag is set, pull out and correct single quoted ('), newline (\n)
711 // or unprintable character terminated subreason, pos is supplied just beyond
712 // first quote. if quoted false, pull out and correct newline (\n) or
713 // unprintable character terminated subreason.
714 //
715 // Heuristics to find termination is painted into a corner:
716
717 // single bit error for quote ' that we can block. It is acceptable for
718 // the others 7, g in reason. 2/9 chance will miss the terminating quote,
719 // but there is always the terminating newline that usually immediately
720 // follows to fortify our chances.
likely_single_quote(char c)721 bool likely_single_quote(char c) {
722 switch (static_cast<uint8_t>(c)) {
723 case '\'': // '\''
724 case '\'' ^ 0x01: // '&'
725 case '\'' ^ 0x02: // '%'
726 case '\'' ^ 0x04: // '#'
727 case '\'' ^ 0x08: // '/'
728 return true;
729 case '\'' ^ 0x10: // '7'
730 break;
731 case '\'' ^ 0x20: // '\a' (unprintable)
732 return true;
733 case '\'' ^ 0x40: // 'g'
734 break;
735 case '\'' ^ 0x80: // 0xA7 (unprintable)
736 return true;
737 }
738 return false;
739 }
740
741 // ::isprint(c) and likely_space() will prevent us from being called for
742 // fundamentally printable entries, except for '\r' and '\b'.
743 //
744 // Except for * and J, single bit errors for \n, all others are non-
745 // printable so easy catch. It is _acceptable_ for *, J or j to exist in
746 // the reason string, so 2/9 chance we will miss the terminating newline.
747 //
748 // NB: J might not be acceptable, except if at the beginning or preceded
749 // with a space, '(' or any of the quotes and their BER aliases.
750 // NB: * might not be acceptable, except if at the beginning or preceded
751 // with a space, another *, or any of the quotes or their BER aliases.
752 //
753 // To reduce the chances to closer to 1/9 is too complicated for the gain.
likely_newline(char c)754 bool likely_newline(char c) {
755 switch (static_cast<uint8_t>(c)) {
756 case '\n': // '\n' (unprintable)
757 case '\n' ^ 0x01: // '\r' (unprintable)
758 case '\n' ^ 0x02: // '\b' (unprintable)
759 case '\n' ^ 0x04: // 0x0E (unprintable)
760 case '\n' ^ 0x08: // 0x02 (unprintable)
761 case '\n' ^ 0x10: // 0x1A (unprintable)
762 return true;
763 case '\n' ^ 0x20: // '*'
764 case '\n' ^ 0x40: // 'J'
765 break;
766 case '\n' ^ 0x80: // 0x8A (unprintable)
767 return true;
768 }
769 return false;
770 }
771
772 // ::isprint(c) will prevent us from being called for all the printable
773 // matches below. If we let unprintables through because of this, they
774 // get converted to underscore (_) by the validation phase.
likely_space(char c)775 bool likely_space(char c) {
776 switch (static_cast<uint8_t>(c)) {
777 case ' ': // ' '
778 case ' ' ^ 0x01: // '!'
779 case ' ' ^ 0x02: // '"'
780 case ' ' ^ 0x04: // '$'
781 case ' ' ^ 0x08: // '('
782 case ' ' ^ 0x10: // '0'
783 case ' ' ^ 0x20: // '\0' (unprintable)
784 case ' ' ^ 0x40: // 'P'
785 case ' ' ^ 0x80: // 0xA0 (unprintable)
786 case '\t': // '\t'
787 case '\t' ^ 0x01: // '\b' (unprintable) (likely_newline counters)
788 case '\t' ^ 0x02: // '\v' (unprintable)
789 case '\t' ^ 0x04: // '\r' (unprintable) (likely_newline counters)
790 case '\t' ^ 0x08: // 0x01 (unprintable)
791 case '\t' ^ 0x10: // 0x19 (unprintable)
792 case '\t' ^ 0x20: // ')'
793 case '\t' ^ 0x40: // '1'
794 case '\t' ^ 0x80: // 0x89 (unprintable)
795 return true;
796 }
797 return false;
798 }
799
getSubreason(const std::string & content,size_t pos,bool quoted)800 std::string getSubreason(const std::string& content, size_t pos, bool quoted) {
801 static constexpr size_t max_reason_length = 256;
802
803 std::string subReason(content.substr(pos, max_reason_length));
804 // Correct against any known strings that Bit Error Match
805 for (const auto& s : knownReasons) {
806 correctForBitErrorOrUnderline(subReason, s);
807 }
808 std::string terminator(quoted ? "'" : "");
809 for (const auto& m : kBootReasonMap) {
810 if (m.first.length() <= strlen("cold")) continue; // too short?
811 if (correctForBitErrorOrUnderline(subReason, m.first + terminator)) continue;
812 if (m.first.length() <= strlen("reboot,cold")) continue; // short?
813 if (android::base::StartsWith(m.first, "reboot,")) {
814 correctForBitErrorOrUnderline(subReason, m.first.substr(strlen("reboot,")) + terminator);
815 } else if (android::base::StartsWith(m.first, "kernel_panic,sysrq,")) {
816 correctForBitErrorOrUnderline(subReason,
817 m.first.substr(strlen("kernel_panic,sysrq,")) + terminator);
818 } else if (android::base::StartsWith(m.first, "kernel_panic,")) {
819 correctForBitErrorOrUnderline(subReason, m.first.substr(strlen("kernel_panic,")) + terminator);
820 }
821 }
822 for (pos = 0; pos < subReason.length(); ++pos) {
823 char c = subReason[pos];
824 if (!(::isprint(c) || likely_space(c)) || likely_newline(c) ||
825 (quoted && likely_single_quote(c))) {
826 subReason.erase(pos);
827 break;
828 }
829 }
830 transformReason(subReason);
831 return subReason;
832 }
833
addKernelPanicSubReason(const pstoreConsole & console,std::string & ret)834 void addKernelPanicSubReason(const pstoreConsole& console, std::string& ret) {
835 // Check for kernel panic types to refine information
836 if ((console.rfind("SysRq : Trigger a crash") != std::string::npos) ||
837 (console.rfind("PC is at sysrq_handle_crash+") != std::string::npos)) {
838 ret = "kernel_panic,sysrq";
839 // Invented for Android to allow daemons that specifically trigger sysrq
840 // to communicate more accurate boot subreasons via last console messages.
841 static constexpr char sysrqSubreason[] = "SysRq : Trigger a crash : '";
842 auto pos = console.rfind(sysrqSubreason);
843 if (pos != std::string::npos) {
844 ret += "," + getSubreason(console, pos + strlen(sysrqSubreason), /* quoted */ true);
845 }
846 return;
847 }
848 if (console.rfind("Unable to handle kernel NULL pointer dereference at virtual address") !=
849 std::string::npos) {
850 ret = "kernel_panic,null";
851 return;
852 }
853 if (console.rfind("Kernel BUG at ") != std::string::npos) {
854 ret = "kernel_panic,bug";
855 return;
856 }
857
858 std::string panic("Kernel panic - not syncing: ");
859 auto pos = console.rfind(panic);
860 if (pos == std::string::npos) return;
861
862 static const std::vector<std::pair<const std::string, const std::string>> panicReasons = {
863 {"Out of memory", "oom"},
864 {"out of memory", "oom"},
865 {"Oh boy, that early out of memory", "oom"}, // omg
866 {"BUG!", "bug"},
867 {"hung_task: blocked tasks", "hung"},
868 {"audit: ", "audit"},
869 {"scheduling while atomic", "atomic"},
870 {"Attempted to kill init!", "init"},
871 {"Requested init", "init"},
872 {"No working init", "init"},
873 {"Could not decompress init", "init"},
874 {"RCU Stall", "hung,rcu"},
875 {"stack-protector", "stack"},
876 {"kernel stack overflow", "stack"},
877 {"Corrupt kernel stack", "stack"},
878 {"low stack detected", "stack"},
879 {"corrupted stack end", "stack"},
880 {"subsys-restart: Resetting the SoC - modem crashed.", "modem"},
881 {"subsys-restart: Resetting the SoC - adsp crashed.", "adsp"},
882 {"subsys-restart: Resetting the SoC - dsps crashed.", "dsps"},
883 {"subsys-restart: Resetting the SoC - wcnss crashed.", "wcnss"},
884 };
885
886 ret = "kernel_panic";
887 for (auto& s : panicReasons) {
888 if (console.find(panic + s.first, pos) != std::string::npos) {
889 ret += "," + s.second;
890 return;
891 }
892 }
893 auto reason = getSubreason(console, pos + panic.length(), /* newline */ false);
894 if (reason.length() > 3) {
895 ret += "," + reason;
896 }
897 }
898
addKernelPanicSubReason(const std::string & content,std::string & ret)899 void addKernelPanicSubReason(const std::string& content, std::string& ret) {
900 addKernelPanicSubReason(pstoreConsole(content), ret);
901 }
902
903 const char system_reboot_reason_property[] = "sys.boot.reason";
904 const char last_reboot_reason_property[] = LAST_REBOOT_REASON_PROPERTY;
905 const char last_reboot_reason_file[] = LAST_REBOOT_REASON_FILE;
906 const char last_last_reboot_reason_property[] = "sys.boot.reason.last";
907 constexpr size_t history_reboot_reason_size = 4;
908 const char history_reboot_reason_property[] = LAST_REBOOT_REASON_PROPERTY ".history";
909 const char bootloader_reboot_reason_property[] = "ro.boot.bootreason";
910
911 // Land system_boot_reason into system_reboot_reason_property.
912 // Shift system_boot_reason into history_reboot_reason_property.
BootReasonAddToHistory(const std::string & system_boot_reason)913 void BootReasonAddToHistory(const std::string& system_boot_reason) {
914 if (system_boot_reason.empty()) return;
915 LOG(INFO) << "Canonical boot reason: " << system_boot_reason;
916
917 // skip system_boot_reason(factory_reset, ota) shift since device boot up from shipmode
918 const auto bootloader_boot_reason =
919 android::base::GetProperty(bootloader_reboot_reason_property, "");
920 const char reg_fship[] = ".*fship.*";
921 if (std::regex_search(bootloader_boot_reason, std::regex(reg_fship)) != 0) {
922 if (system_boot_reason == "reboot,factory_reset" || system_boot_reason == "reboot,ota") {
923 LOG(INFO) << "skip boot reason (" << system_boot_reason
924 << ") shift since device boot up from shipmode.";
925 return;
926 }
927 }
928
929 auto old_system_boot_reason = android::base::GetProperty(system_reboot_reason_property, "");
930 if (!android::base::SetProperty(system_reboot_reason_property, system_boot_reason)) {
931 android::base::SetProperty(system_reboot_reason_property,
932 system_boot_reason.substr(0, PROPERTY_VALUE_MAX - 1));
933 }
934 auto reason_history =
935 android::base::Split(android::base::GetProperty(history_reboot_reason_property, ""), "\n");
936 static auto mark = time(nullptr);
937 auto mark_str = std::string(",") + std::to_string(mark);
938 auto marked_system_boot_reason = system_boot_reason + mark_str;
939 if (!reason_history.empty()) {
940 // delete any entries that we just wrote in a previous
941 // call and leveraging duplicate line handling
942 auto last = old_system_boot_reason + mark_str;
943 // trim the list to (history_reboot_reason_size - 1)
944 ssize_t max = history_reboot_reason_size;
945 for (auto it = reason_history.begin(); it != reason_history.end();) {
946 if (it->empty() || (last == *it) || (marked_system_boot_reason == *it) || (--max <= 0)) {
947 it = reason_history.erase(it);
948 } else {
949 last = *it;
950 ++it;
951 }
952 }
953 }
954 // insert at the front, concatenating mark (<epoch time>) detail to the value.
955 reason_history.insert(reason_history.begin(), marked_system_boot_reason);
956 // If the property string is too long ( > PROPERTY_VALUE_MAX)
957 // we get an error, so trim out last entry and try again.
958 while (!android::base::SetProperty(history_reboot_reason_property,
959 android::base::Join(reason_history, '\n'))) {
960 auto it = std::prev(reason_history.end());
961 if (it == reason_history.end()) break;
962 reason_history.erase(it);
963 }
964 }
965
966 // Scrub, Sanitize, Standardize and Enhance the boot reason string supplied.
BootReasonStrToReason(const std::string & boot_reason)967 std::string BootReasonStrToReason(const std::string& boot_reason) {
968 auto ret = android::base::GetProperty(system_reboot_reason_property, "");
969 std::string reason(boot_reason);
970
971 // skip BootReasonStrToReason() if device boot up from shipmode
972 const char reg_fship[] = ".*fship.*";
973 if (reason == ret && std::regex_search(reason, std::regex(reg_fship)) != 0) {
974 LOG(INFO) << "skip boot reason enhancement if device boot up from shipmode";
975 return ret;
976 }
977
978 // If sys.boot.reason == ro.boot.bootreason, let's re-evaluate
979 if (reason == ret) ret = "";
980
981 transformReason(reason);
982
983 // Is the current system boot reason sys.boot.reason valid?
984 if (!isKnownRebootReason(ret)) ret = "";
985
986 if (ret == "") {
987 // Is the bootloader boot reason ro.boot.bootreason known?
988 std::vector<std::string> words(android::base::Split(reason, ",_-"));
989 for (auto& s : knownReasons) {
990 std::string blunt;
991 for (auto& r : words) {
992 if (r == s) {
993 if (isBluntRebootReason(s)) {
994 blunt = s;
995 } else {
996 ret = s;
997 break;
998 }
999 }
1000 }
1001 if (ret == "") ret = blunt;
1002 if (ret != "") break;
1003 }
1004 }
1005
1006 if (ret == "") {
1007 // A series of checks to take some officially unsupported reasons
1008 // reported by the bootloader and find some logical and canonical
1009 // sense. In an ideal world, we would require those bootloaders
1010 // to behave and follow our CTS standards.
1011 //
1012 // first member is the output
1013 // second member is an unanchored regex for an alias
1014 //
1015 // If output has a prefix of <bang> '!', we do not use it as a
1016 // match needle (and drop the <bang> prefix when landing in output),
1017 // otherwise look for it as well. This helps keep the scale of the
1018 // following table smaller.
1019 static const std::vector<std::pair<const std::string, const std::string>> aliasReasons = {
1020 {"watchdog", "wdog"},
1021 {"kernel_panic", "panic"},
1022 {"shutdown,thermal", "thermal"},
1023 {"warm,s3_wakeup", "s3_wakeup"},
1024 {"hard,hw_reset", "hw_reset"},
1025 {"cold,charger", "usb|power_on_cable"},
1026 {"cold,powerkey", "powerkey|power_key|PowerKey|power_on"},
1027 {"cold,rtc", "rtc"},
1028 {"cold,rtc,2sec", "2sec_reboot"},
1029 {"!warm", "wdt_by_pass_pwk"}, // change flavour of blunt
1030 {"!reboot", "^wdt$"}, // change flavour of blunt
1031 {"reboot,tool", "tool_by_pass_pwk"},
1032 {"!reboot,longkey", "reboot_longkey"},
1033 {"!reboot,longkey", "kpdpwr"},
1034 {"!reboot,undervoltage", "uvlo"},
1035 {"!reboot,powerloss", "smpl"},
1036 {"bootloader", ""},
1037 };
1038
1039 for (auto& s : aliasReasons) {
1040 size_t firstHasNot = s.first[0] == '!';
1041 if (!firstHasNot && (reason.find(s.first) != std::string::npos)) {
1042 ret = s.first;
1043 break;
1044 }
1045 if (s.second.size() && std::regex_search(reason, std::regex(s.second))) {
1046 ret = s.first.substr(firstHasNot);
1047 break;
1048 }
1049 }
1050 }
1051
1052 // If watchdog is the reason, see if there is a security angle?
1053 if (ret == "watchdog") {
1054 if (reason.find("sec") != std::string::npos) {
1055 ret += ",security";
1056 }
1057 }
1058
1059 if (ret == "kernel_panic") {
1060 // Check to see if last klog has some refinement hints.
1061 std::string content;
1062 if (readPstoreConsole(content)) {
1063 addKernelPanicSubReason(content, ret);
1064 }
1065 } else if (isBluntRebootReason(ret)) {
1066 // Check the other available reason resources if the reason is still blunt.
1067
1068 // Check to see if last klog has some refinement hints.
1069 std::string content;
1070 if (readPstoreConsole(content)) {
1071 const pstoreConsole console(content);
1072 // The toybox reboot command used directly (unlikely)? But also
1073 // catches init's response to Android's more controlled reboot command.
1074 if (console.rfind("reboot: Power down") != std::string::npos) {
1075 ret = "shutdown"; // Still too blunt, but more accurate.
1076 // ToDo: init should record the shutdown reason to kernel messages ala:
1077 // init: shutdown system with command 'last_reboot_reason'
1078 // so that if pstore has persistence we can get some details
1079 // that could be missing in last_reboot_reason_property.
1080 }
1081
1082 static const char cmd[] = "reboot: Restarting system with command '";
1083 size_t pos = console.rfind(cmd);
1084 if (pos != std::string::npos) {
1085 std::string subReason(getSubreason(content, pos + strlen(cmd), /* quoted */ true));
1086 if (subReason != "") { // Will not land "reboot" as that is too blunt.
1087 if (isKernelRebootReason(subReason)) {
1088 ret = "reboot," + subReason; // User space can't talk kernel reasons.
1089 } else if (isKnownRebootReason(subReason)) {
1090 ret = subReason;
1091 } else {
1092 ret = "reboot," + subReason; // legitimize unknown reasons
1093 }
1094 }
1095 // Some bootloaders shutdown results record in last kernel message.
1096 if (!strcmp(ret.c_str(), "reboot,kernel_power_off_charging__reboot_system")) {
1097 ret = "shutdown";
1098 }
1099 }
1100
1101 // Check for kernel panics, allowed to override reboot command.
1102 (void)addKernelPanicSubReason(console, ret);
1103 }
1104
1105 // TODO: use the HAL to get battery level (http://b/77725702).
1106
1107 // Is there a controlled shutdown hint in last_reboot_reason_property?
1108 if (isBluntRebootReason(ret)) {
1109 // Content buffer no longer will have console data. Beware if more
1110 // checks added below, that depend on parsing console content.
1111 if (!android::base::ReadFileToString(last_reboot_reason_file, &content)) {
1112 content = android::base::GetProperty(last_reboot_reason_property, "");
1113 }
1114 transformReason(content);
1115
1116 // Anything in last is better than 'super-blunt' reboot or shutdown.
1117 if ((ret == "") || (ret == "reboot") || (ret == "shutdown") || !isBluntRebootReason(content)) {
1118 ret = content;
1119 }
1120 }
1121
1122 // Other System Health HAL reasons?
1123
1124 // ToDo: /proc/sys/kernel/boot_reason needs a HAL interface to
1125 // possibly offer hardware-specific clues from the PMIC.
1126 }
1127
1128 // If unknown left over from above, make it "reboot,<boot_reason>"
1129 if (ret == "") {
1130 ret = "reboot";
1131 if (android::base::StartsWith(reason, "reboot")) {
1132 reason = reason.substr(strlen("reboot"));
1133 while ((reason[0] == ',') || (reason[0] == '_')) {
1134 reason = reason.substr(1);
1135 }
1136 }
1137 if (reason != "") {
1138 ret += ",";
1139 ret += reason;
1140 }
1141 }
1142
1143 LOG(INFO) << "Canonical boot reason: " << ret;
1144 return ret;
1145 }
1146
1147 // Returns the appropriate metric key prefix for the boot_complete metric such
1148 // that boot metrics after a system update are labeled as ota_boot_complete;
1149 // otherwise, they are labeled as boot_complete. This method encapsulates the
1150 // bookkeeping required to track when a system update has occurred by storing
1151 // the UTC timestamp of the system build date and comparing against the current
1152 // system build date.
CalculateBootCompletePrefix()1153 std::string CalculateBootCompletePrefix() {
1154 static const std::string kBuildDateKey = "build_date";
1155 std::string boot_complete_prefix = "boot_complete";
1156
1157 auto build_date_str = android::base::GetProperty("ro.build.date.utc", "");
1158 int32_t build_date;
1159 if (!android::base::ParseInt(build_date_str, &build_date)) {
1160 return std::string();
1161 }
1162
1163 BootEventRecordStore boot_event_store;
1164 BootEventRecordStore::BootEventRecord record;
1165 if (!boot_event_store.GetBootEvent(kBuildDateKey, &record)) {
1166 boot_complete_prefix = "factory_reset_" + boot_complete_prefix;
1167 boot_event_store.AddBootEventWithValue(kBuildDateKey, build_date);
1168 BootReasonAddToHistory("reboot,factory_reset");
1169 } else if (build_date != record.second) {
1170 boot_complete_prefix = "ota_" + boot_complete_prefix;
1171 boot_event_store.AddBootEventWithValue(kBuildDateKey, build_date);
1172 BootReasonAddToHistory("reboot,ota");
1173 }
1174
1175 return boot_complete_prefix;
1176 }
1177
1178 // Records the value of a given ro.boottime.init property in milliseconds.
RecordInitBootTimeProp(BootEventRecordStore * boot_event_store,const char * property)1179 void RecordInitBootTimeProp(BootEventRecordStore* boot_event_store, const char* property) {
1180 auto value = android::base::GetProperty(property, "");
1181
1182 int32_t time_in_ms;
1183 if (android::base::ParseInt(value, &time_in_ms)) {
1184 boot_event_store->AddBootEventWithValue(property, time_in_ms);
1185 }
1186 }
1187
1188 // A map from bootloader timing stage to the time that stage took during boot.
1189 typedef std::map<std::string, int32_t> BootloaderTimingMap;
1190
1191 // Returns a mapping from bootloader stage names to the time those stages
1192 // took to boot.
GetBootLoaderTimings()1193 const BootloaderTimingMap GetBootLoaderTimings() {
1194 BootloaderTimingMap timings;
1195
1196 // |ro.boot.boottime| is of the form 'stage1:time1,...,stageN:timeN',
1197 // where timeN is in milliseconds.
1198 auto value = android::base::GetProperty("ro.boot.boottime", "");
1199 if (value.empty()) {
1200 // ro.boot.boottime is not reported on all devices.
1201 return BootloaderTimingMap();
1202 }
1203
1204 auto stages = android::base::Split(value, ",");
1205 for (const auto& stageTiming : stages) {
1206 // |stageTiming| is of the form 'stage:time'.
1207 auto stageTimingValues = android::base::Split(stageTiming, ":");
1208 DCHECK_EQ(2U, stageTimingValues.size());
1209
1210 if (stageTimingValues.size() < 2) continue;
1211 std::string stageName = stageTimingValues[0];
1212 int32_t time_ms;
1213 if (android::base::ParseInt(stageTimingValues[1], &time_ms)) {
1214 timings[stageName] = time_ms;
1215 }
1216 }
1217
1218 return timings;
1219 }
1220
1221 // Returns the total bootloader boot time from the ro.boot.boottime system property.
GetBootloaderTime(const BootloaderTimingMap & bootloader_timings)1222 int32_t GetBootloaderTime(const BootloaderTimingMap& bootloader_timings) {
1223 int32_t total_time = 0;
1224 for (const auto& timing : bootloader_timings) {
1225 total_time += timing.second;
1226 }
1227
1228 return total_time;
1229 }
1230
1231 // Parses and records the set of bootloader stages and associated boot times
1232 // from the ro.boot.boottime system property.
RecordBootloaderTimings(BootEventRecordStore * boot_event_store,const BootloaderTimingMap & bootloader_timings)1233 void RecordBootloaderTimings(BootEventRecordStore* boot_event_store,
1234 const BootloaderTimingMap& bootloader_timings) {
1235 int32_t total_time = 0;
1236 for (const auto& timing : bootloader_timings) {
1237 total_time += timing.second;
1238 boot_event_store->AddBootEventWithValue("boottime.bootloader." + timing.first, timing.second);
1239 }
1240
1241 boot_event_store->AddBootEventWithValue("boottime.bootloader.total", total_time);
1242 }
1243
1244 // Returns the closest estimation to the absolute device boot time, i.e.,
1245 // from power on to boot_complete, including bootloader times.
GetAbsoluteBootTime(const BootloaderTimingMap & bootloader_timings,std::chrono::milliseconds uptime)1246 std::chrono::milliseconds GetAbsoluteBootTime(const BootloaderTimingMap& bootloader_timings,
1247 std::chrono::milliseconds uptime) {
1248 int32_t bootloader_time_ms = 0;
1249
1250 for (const auto& timing : bootloader_timings) {
1251 if (timing.first.compare("SW") != 0) {
1252 bootloader_time_ms += timing.second;
1253 }
1254 }
1255
1256 auto bootloader_duration = std::chrono::milliseconds(bootloader_time_ms);
1257 return bootloader_duration + uptime;
1258 }
1259
1260 // Records the closest estimation to the absolute device boot time in seconds.
1261 // i.e. from power on to boot_complete, including bootloader times.
RecordAbsoluteBootTime(BootEventRecordStore * boot_event_store,std::chrono::milliseconds absolute_total)1262 void RecordAbsoluteBootTime(BootEventRecordStore* boot_event_store,
1263 std::chrono::milliseconds absolute_total) {
1264 auto absolute_total_sec = std::chrono::duration_cast<std::chrono::seconds>(absolute_total);
1265 boot_event_store->AddBootEventWithValue("absolute_boot_time", absolute_total_sec.count());
1266 }
1267
1268 // Logs the total boot time and reason to statsd.
LogBootInfoToStatsd(std::chrono::milliseconds end_time,std::chrono::milliseconds total_duration,int32_t bootloader_duration_ms,double time_since_last_boot_sec)1269 void LogBootInfoToStatsd(std::chrono::milliseconds end_time,
1270 std::chrono::milliseconds total_duration, int32_t bootloader_duration_ms,
1271 double time_since_last_boot_sec) {
1272 auto reason = android::base::GetProperty(bootloader_reboot_reason_property, "<EMPTY>");
1273 auto system_reason = android::base::GetProperty(system_reboot_reason_property, "<EMPTY>");
1274 android::util::stats_write(android::util::BOOT_SEQUENCE_REPORTED, reason.c_str(),
1275 system_reason.c_str(), end_time.count(), total_duration.count(),
1276 (int64_t)bootloader_duration_ms,
1277 (int64_t)time_since_last_boot_sec * 1000);
1278 }
1279
SetSystemBootReason()1280 void SetSystemBootReason() {
1281 const auto bootloader_boot_reason =
1282 android::base::GetProperty(bootloader_reboot_reason_property, "");
1283 const std::string system_boot_reason(BootReasonStrToReason(bootloader_boot_reason));
1284 // Record the scrubbed system_boot_reason to the property
1285 BootReasonAddToHistory(system_boot_reason);
1286 // Shift last_reboot_reason_property to last_last_reboot_reason_property
1287 std::string last_boot_reason;
1288 if (!android::base::ReadFileToString(last_reboot_reason_file, &last_boot_reason)) {
1289 PLOG(ERROR) << "Failed to read " << last_reboot_reason_file;
1290 last_boot_reason = android::base::GetProperty(last_reboot_reason_property, "");
1291 LOG(INFO) << "Value of " << last_reboot_reason_property << " : " << last_boot_reason;
1292 } else {
1293 LOG(INFO) << "Last reboot reason read from " << last_reboot_reason_file << " : "
1294 << last_boot_reason << ". Last reboot reason read from "
1295 << last_reboot_reason_property << " : "
1296 << android::base::GetProperty(last_reboot_reason_property, "");
1297 }
1298 if (last_boot_reason.empty() || isKernelRebootReason(system_boot_reason)) {
1299 last_boot_reason = system_boot_reason;
1300 } else {
1301 transformReason(last_boot_reason);
1302 }
1303 LOG(INFO) << "Normalized last reboot reason : " << last_boot_reason;
1304 android::base::SetProperty(last_last_reboot_reason_property, last_boot_reason);
1305 android::base::SetProperty(last_reboot_reason_property, "");
1306 if (unlink(last_reboot_reason_file) != 0) {
1307 PLOG(ERROR) << "Failed to unlink " << last_reboot_reason_file;
1308 }
1309 }
1310
1311 // Gets the boot time offset. This is useful when Android is running in a
1312 // container, because the boot_clock is not reset when Android reboots.
GetBootTimeOffset()1313 std::chrono::nanoseconds GetBootTimeOffset() {
1314 static const int64_t boottime_offset =
1315 android::base::GetIntProperty<int64_t>("ro.boot.boottime_offset", 0);
1316 return std::chrono::nanoseconds(boottime_offset);
1317 }
1318
1319 // Returns the current uptime, accounting for any offset in the CLOCK_BOOTTIME
1320 // clock.
GetUptime()1321 android::base::boot_clock::duration GetUptime() {
1322 return android::base::boot_clock::now().time_since_epoch() - GetBootTimeOffset();
1323 }
1324
1325 // Records several metrics related to the time it takes to boot the device.
RecordBootComplete()1326 void RecordBootComplete() {
1327 BootEventRecordStore boot_event_store;
1328 BootEventRecordStore::BootEventRecord record;
1329
1330 auto uptime_ns = GetUptime();
1331 auto uptime_s = std::chrono::duration_cast<std::chrono::seconds>(uptime_ns);
1332 time_t current_time_utc = time(nullptr);
1333 time_t time_since_last_boot = 0;
1334
1335 if (boot_event_store.GetBootEvent("last_boot_time_utc", &record)) {
1336 time_t last_boot_time_utc = record.second;
1337 time_since_last_boot = difftime(current_time_utc, last_boot_time_utc);
1338 boot_event_store.AddBootEventWithValue("time_since_last_boot", time_since_last_boot);
1339 }
1340
1341 boot_event_store.AddBootEventWithValue("last_boot_time_utc", current_time_utc);
1342
1343 // The boot_complete metric has two variants: boot_complete and
1344 // ota_boot_complete. The latter signifies that the device is booting after
1345 // a system update.
1346 std::string boot_complete_prefix = CalculateBootCompletePrefix();
1347 if (boot_complete_prefix.empty()) {
1348 // The system is hosed because the build date property could not be read.
1349 return;
1350 }
1351
1352 // The *_no_encryption events are emitted unconditionally, since they are left
1353 // over from a time when encryption meant "full-disk encryption". But Android
1354 // now always uses file-based encryption instead of full-disk encryption. At
1355 // some point, these misleading and redundant events should be removed.
1356 boot_event_store.AddBootEventWithValue(boot_complete_prefix + "_no_encryption",
1357 uptime_s.count());
1358
1359 // Record the total time from device startup to boot complete. Note: we are
1360 // recording seconds here even though the field in statsd atom specifies
1361 // milliseconds.
1362 boot_event_store.AddBootEventWithValue(boot_complete_prefix, uptime_s.count());
1363
1364 RecordInitBootTimeProp(&boot_event_store, "ro.boottime.init");
1365 RecordInitBootTimeProp(&boot_event_store, "ro.boottime.init.first_stage");
1366 RecordInitBootTimeProp(&boot_event_store, "ro.boottime.init.selinux");
1367 RecordInitBootTimeProp(&boot_event_store, "ro.boottime.init.cold_boot_wait");
1368
1369 const BootloaderTimingMap bootloader_timings = GetBootLoaderTimings();
1370 int32_t bootloader_boot_duration = GetBootloaderTime(bootloader_timings);
1371 RecordBootloaderTimings(&boot_event_store, bootloader_timings);
1372
1373 auto uptime_ms = std::chrono::duration_cast<std::chrono::milliseconds>(uptime_ns);
1374 auto absolute_boot_time = GetAbsoluteBootTime(bootloader_timings, uptime_ms);
1375 RecordAbsoluteBootTime(&boot_event_store, absolute_boot_time);
1376
1377 auto boot_end_time_point = std::chrono::system_clock::now().time_since_epoch();
1378 auto boot_end_time = std::chrono::duration_cast<std::chrono::milliseconds>(boot_end_time_point);
1379
1380 LogBootInfoToStatsd(boot_end_time, absolute_boot_time, bootloader_boot_duration,
1381 time_since_last_boot);
1382 }
1383
1384 // Records the boot_reason metric by querying the ro.boot.bootreason system
1385 // property.
RecordBootReason()1386 void RecordBootReason() {
1387 const auto reason = android::base::GetProperty(bootloader_reboot_reason_property, "");
1388
1389 if (reason.empty()) {
1390 // TODO(b/148575354): Replace with statsd.
1391 // Log an empty boot reason value as '<EMPTY>' to ensure the value is intentional
1392 // (and not corruption anywhere else in the reporting pipeline).
1393 // android::metricslogger::LogMultiAction(android::metricslogger::ACTION_BOOT,
1394 // android::metricslogger::FIELD_PLATFORM_REASON,
1395 // "<EMPTY>");
1396 } else {
1397 // TODO(b/148575354): Replace with statsd.
1398 // android::metricslogger::LogMultiAction(android::metricslogger::ACTION_BOOT,
1399 // android::metricslogger::FIELD_PLATFORM_REASON,
1400 // reason);
1401 }
1402
1403 // Log the raw bootloader_boot_reason property value.
1404 int32_t boot_reason = BootReasonStrToEnum(reason);
1405 BootEventRecordStore boot_event_store;
1406 boot_event_store.AddBootEventWithValue("boot_reason", boot_reason);
1407
1408 // Log the scrubbed system_boot_reason.
1409 const auto system_reason = android::base::GetProperty(system_reboot_reason_property, "");
1410 int32_t system_boot_reason = BootReasonStrToEnum(system_reason);
1411 boot_event_store.AddBootEventWithValue("system_boot_reason", system_boot_reason);
1412
1413 if (reason == "") {
1414 android::base::SetProperty(bootloader_reboot_reason_property, system_reason);
1415 }
1416 }
1417
1418 // Records two metrics related to the user resetting a device: the time at
1419 // which the device is reset, and the time since the user last reset the
1420 // device. The former is only set once per-factory reset.
RecordFactoryReset()1421 void RecordFactoryReset() {
1422 BootEventRecordStore boot_event_store;
1423 BootEventRecordStore::BootEventRecord record;
1424
1425 time_t current_time_utc = time(nullptr);
1426
1427 if (current_time_utc < 0) {
1428 // UMA does not display negative values in buckets, so convert to positive.
1429 // Logging via BootEventRecordStore.
1430 android::util::stats_write(
1431 static_cast<int32_t>(android::util::BOOT_TIME_EVENT_ERROR_CODE_REPORTED),
1432 static_cast<int32_t>(
1433 android::util::BOOT_TIME_EVENT_ERROR_CODE__EVENT__FACTORY_RESET_CURRENT_TIME_FAILURE),
1434 static_cast<int32_t>(std::abs(current_time_utc)));
1435
1436 // Logging via BootEventRecordStore to see if using android::metricslogger::LogHistogram
1437 // is losing records somehow.
1438 boot_event_store.AddBootEventWithValue("factory_reset_current_time_failure",
1439 std::abs(current_time_utc));
1440 return;
1441 } else {
1442 android::util::stats_write(
1443 static_cast<int32_t>(android::util::BOOT_TIME_EVENT_UTC_TIME_REPORTED),
1444 static_cast<int32_t>(
1445 android::util::BOOT_TIME_EVENT_UTC_TIME__EVENT__FACTORY_RESET_CURRENT_TIME),
1446 static_cast<int64_t>(current_time_utc));
1447
1448 // Logging via BootEventRecordStore to see if using android::metricslogger::LogHistogram
1449 // is losing records somehow.
1450 boot_event_store.AddBootEventWithValue("factory_reset_current_time", current_time_utc);
1451 }
1452
1453 // The factory_reset boot event does not exist after the device is reset, so
1454 // use this signal to mark the time of the factory reset.
1455 if (!boot_event_store.GetBootEvent("factory_reset", &record)) {
1456 boot_event_store.AddBootEventWithValue("factory_reset", current_time_utc);
1457
1458 // Don't log the time_since_factory_reset until some time has elapsed.
1459 // The data is not meaningful yet and skews the histogram buckets.
1460 return;
1461 }
1462
1463 // Calculate and record the difference in time between now and the
1464 // factory_reset time.
1465 time_t factory_reset_utc = record.second;
1466 android::util::stats_write(
1467 static_cast<int32_t>(android::util::BOOT_TIME_EVENT_UTC_TIME_REPORTED),
1468 static_cast<int32_t>(
1469 android::util::BOOT_TIME_EVENT_UTC_TIME__EVENT__FACTORY_RESET_RECORD_VALUE),
1470 static_cast<int64_t>(factory_reset_utc));
1471
1472 // Logging via BootEventRecordStore to see if using android::metricslogger::LogHistogram
1473 // is losing records somehow.
1474 boot_event_store.AddBootEventWithValue("factory_reset_record_value", factory_reset_utc);
1475
1476 time_t time_since_factory_reset = difftime(current_time_utc, factory_reset_utc);
1477 boot_event_store.AddBootEventWithValue("time_since_factory_reset", time_since_factory_reset);
1478 }
1479
1480 // List the associated boot reason(s), if arg is nullptr then all.
PrintBootReasonEnum(const char * arg)1481 void PrintBootReasonEnum(const char* arg) {
1482 int value = -1;
1483 if (arg != nullptr) {
1484 value = BootReasonStrToEnum(arg);
1485 }
1486 for (const auto& [match, id] : kBootReasonMap) {
1487 if ((value < 0) || (value == id)) {
1488 printf("%u\t%s\n", id, match.c_str());
1489 }
1490 }
1491 }
1492
1493 } // namespace
1494
main(int argc,char ** argv)1495 int main(int argc, char** argv) {
1496 android::base::InitLogging(argv);
1497
1498 const std::string cmd_line = GetCommandLine(argc, argv);
1499 LOG(INFO) << "Service started: " << cmd_line;
1500
1501 int option_index = 0;
1502 static const char value_str[] = "value";
1503 static const char system_boot_reason_str[] = "set_system_boot_reason";
1504 static const char boot_complete_str[] = "record_boot_complete";
1505 static const char boot_reason_str[] = "record_boot_reason";
1506 static const char factory_reset_str[] = "record_time_since_factory_reset";
1507 static const char boot_reason_enum_str[] = "boot_reason_enum";
1508 static const struct option long_options[] = {
1509 // clang-format off
1510 { "help", no_argument, NULL, 'h' },
1511 { "log", no_argument, NULL, 'l' },
1512 { "print", no_argument, NULL, 'p' },
1513 { "record", required_argument, NULL, 'r' },
1514 { value_str, required_argument, NULL, 0 },
1515 { system_boot_reason_str, no_argument, NULL, 0 },
1516 { boot_complete_str, no_argument, NULL, 0 },
1517 { boot_reason_str, no_argument, NULL, 0 },
1518 { factory_reset_str, no_argument, NULL, 0 },
1519 { boot_reason_enum_str, optional_argument, NULL, 0 },
1520 { NULL, 0, NULL, 0 }
1521 // clang-format on
1522 };
1523
1524 std::string boot_event;
1525 std::string value;
1526 int opt = 0;
1527 while ((opt = getopt_long(argc, argv, "hlpr:", long_options, &option_index)) != -1) {
1528 switch (opt) {
1529 // This case handles long options which have no single-character mapping.
1530 case 0: {
1531 const std::string option_name = long_options[option_index].name;
1532 if (option_name == value_str) {
1533 // |optarg| is an external variable set by getopt representing
1534 // the option argument.
1535 value = optarg;
1536 } else if (option_name == system_boot_reason_str) {
1537 SetSystemBootReason();
1538 } else if (option_name == boot_complete_str) {
1539 RecordBootComplete();
1540 } else if (option_name == boot_reason_str) {
1541 RecordBootReason();
1542 } else if (option_name == factory_reset_str) {
1543 RecordFactoryReset();
1544 } else if (option_name == boot_reason_enum_str) {
1545 PrintBootReasonEnum(optarg);
1546 } else {
1547 LOG(ERROR) << "Invalid option: " << option_name;
1548 }
1549 break;
1550 }
1551
1552 case 'h': {
1553 ShowHelp(argv[0]);
1554 break;
1555 }
1556
1557 case 'l': {
1558 LogBootEvents();
1559 break;
1560 }
1561
1562 case 'p': {
1563 PrintBootEvents();
1564 break;
1565 }
1566
1567 case 'r': {
1568 // |optarg| is an external variable set by getopt representing
1569 // the option argument.
1570 boot_event = optarg;
1571 break;
1572 }
1573
1574 default: {
1575 DCHECK_EQ(opt, '?');
1576
1577 // |optopt| is an external variable set by getopt representing
1578 // the value of the invalid option.
1579 LOG(ERROR) << "Invalid option: " << optopt;
1580 ShowHelp(argv[0]);
1581 return EXIT_FAILURE;
1582 }
1583 }
1584 }
1585
1586 if (!boot_event.empty()) {
1587 RecordBootEventFromCommandLine(boot_event, value);
1588 }
1589
1590 return 0;
1591 }
1592