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