blob: ea49798c9b286d259579f117b9abfa9d4a07241d [file] [log] [blame]
James Hawkinsabd73e62016-01-19 15:10:38 -08001/*
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
James Hawkinsa4a1a4a2016-02-09 15:32:38 -080021#include <getopt.h>
Mark Salyzynb304f6d2017-08-04 13:35:51 -070022#include <sys/klog.h>
Mark Salyzyn14b1e6d2017-09-18 10:41:14 -070023#include <unistd.h>
Mark Salyzynff2dcd92016-09-28 15:54:45 -070024
James Hawkinse78ea772017-03-24 11:43:02 -070025#include <chrono>
James Hawkins0660b302016-03-08 16:18:15 -080026#include <cmath>
James Hawkinsabd73e62016-01-19 15:10:38 -080027#include <cstddef>
28#include <cstdio>
James Hawkins500d7152016-02-16 15:05:54 -080029#include <ctime>
Mark Salyzyn5c58c9d2018-06-28 09:21:55 -070030#include <iterator>
James Hawkinsa4a1a4a2016-02-09 15:32:38 -080031#include <map>
James Hawkinsabd73e62016-01-19 15:10:38 -080032#include <memory>
Mark Salyzyn25900dd2018-03-16 09:05:59 -070033#include <regex>
James Hawkinsabd73e62016-01-19 15:10:38 -080034#include <string>
Mark Salyzyn853bb802018-03-16 08:44:56 -070035#include <utility>
James Hawkinsbe46fd12017-02-02 16:21:25 -080036#include <vector>
Mark Salyzynff2dcd92016-09-28 15:54:45 -070037
James Hawkinse78ea772017-03-24 11:43:02 -070038#include <android-base/chrono_utils.h>
Mark Salyzynb304f6d2017-08-04 13:35:51 -070039#include <android-base/file.h>
James Hawkinseabe08b2016-01-19 16:54:35 -080040#include <android-base/logging.h>
James Hawkins4dded612016-07-28 11:50:23 -070041#include <android-base/parseint.h>
Luis Hector Chavez583d34c2018-04-12 15:25:15 -070042#include <android-base/properties.h>
James Hawkinsbe46fd12017-02-02 16:21:25 -080043#include <android-base/strings.h>
James Hawkinse78ea772017-03-24 11:43:02 -070044#include <android/log.h>
Mark Salyzynb304f6d2017-08-04 13:35:51 -070045#include <cutils/android_reboot.h>
James Hawkinsa4a1a4a2016-02-09 15:32:38 -080046#include <cutils/properties.h>
James Hawkins9aec9262017-01-31 11:42:24 -080047#include <metricslogger/metrics_logger.h>
Tej Singh4eacd382018-01-25 17:59:57 -080048#include <statslog.h>
Mark Salyzynff2dcd92016-09-28 15:54:45 -070049
James Hawkinsabd73e62016-01-19 15:10:38 -080050#include "boot_event_record_store.h"
James Hawkinsabd73e62016-01-19 15:10:38 -080051
52namespace {
53
James Hawkinsabd73e62016-01-19 15:10:38 -080054// Scans the boot event record store for record files and logs each boot event
55// via EventLog.
56void LogBootEvents() {
57 BootEventRecordStore boot_event_store;
58
59 auto events = boot_event_store.GetAllBootEvents();
60 for (auto i = events.cbegin(); i != events.cend(); ++i) {
James Hawkins9aec9262017-01-31 11:42:24 -080061 android::metricslogger::LogHistogram(i->first, i->second);
James Hawkinsabd73e62016-01-19 15:10:38 -080062 }
63}
64
James Hawkinsc6275582016-03-22 10:47:44 -070065// 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.
Mark Salyzyn14b1e6d2017-09-18 10:41:14 -070068void RecordBootEventFromCommandLine(const std::string& event, const std::string& value_str) {
James Hawkinsc6275582016-03-22 10:47:44 -070069 BootEventRecordStore boot_event_store;
70 if (!value_str.empty()) {
71 int32_t value = 0;
Elliott Hughesda46b392016-10-11 17:09:00 -070072 if (android::base::ParseInt(value_str, &value)) {
James Hawkins4dded612016-07-28 11:50:23 -070073 boot_event_store.AddBootEventWithValue(event, value);
74 }
James Hawkinsc6275582016-03-22 10:47:44 -070075 } else {
76 boot_event_store.AddBootEvent(event);
77 }
78}
79
James Hawkinsabd73e62016-01-19 15:10:38 -080080void 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
Mark Salyzyn14b1e6d2017-09-18 10:41:14 -070091void ShowHelp(const char* cmd) {
James Hawkinsabd73e62016-01-19 15:10:38 -080092 fprintf(stderr, "Usage: %s [options]\n", cmd);
93 fprintf(stderr,
94 "options include:\n"
Yongqin Liu78b2b942017-07-07 13:26:49 +080095 " -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"
James Hawkins53684ea2016-02-23 16:18:19 -0800102 " --record_time_since_factory_reset Record the time since the device was reset\n");
James Hawkinsabd73e62016-01-19 15:10:38 -0800103}
104
105// Constructs a readable, printable string from the givencommand line
106// arguments.
Mark Salyzyn14b1e6d2017-09-18 10:41:14 -0700107std::string GetCommandLine(int argc, char** argv) {
James Hawkinsabd73e62016-01-19 15:10:38 -0800108 std::string cmd;
109 for (int i = 0; i < argc; ++i) {
110 cmd += argv[i];
111 cmd += " ";
112 }
113
114 return cmd;
115}
116
James Hawkins25f71222017-10-10 16:37:05 -0700117constexpr int32_t kEmptyBootReason = 0;
James Hawkins6f74c0b2016-02-12 15:49:16 -0800118constexpr int32_t kUnknownBootReason = 1;
119
James Hawkinsa4a1a4a2016-02-09 15:32:38 -0800120// A mapping from boot reason string, as read from the ro.boot.bootreason
121// system property, to a unique integer ID. Viewers of log data dashboards for
122// the boot_reason metric may refer to this mapping to discern the histogram
123// values.
James Hawkins6f74c0b2016-02-12 15:49:16 -0800124const std::map<std::string, int32_t> kBootReasonMap = {
James Hawkins25f71222017-10-10 16:37:05 -0700125 {"empty", kEmptyBootReason},
Mark Salyzyn2b820532018-03-16 08:53:34 -0700126 {"__BOOTSTAT_UNKNOWN__", kUnknownBootReason},
Mark Salyzyn14b1e6d2017-09-18 10:41:14 -0700127 {"normal", 2},
128 {"recovery", 3},
129 {"reboot", 4},
130 {"PowerKey", 5},
131 {"hard_reset", 6},
132 {"kernel_panic", 7},
133 {"rpm_err", 8},
134 {"hw_reset", 9},
135 {"tz_err", 10},
136 {"adsp_err", 11},
137 {"modem_err", 12},
138 {"mba_err", 13},
139 {"Watchdog", 14},
140 {"Panic", 15},
141 {"power_key", 16},
142 {"power_on", 17},
143 {"Reboot", 18},
144 {"rtc", 19},
145 {"edl", 20},
146 {"oem_pon1", 21},
147 {"oem_powerkey", 22},
148 {"oem_unknown_reset", 23},
149 {"srto: HWWDT reset SC", 24},
150 {"srto: HWWDT reset platform", 25},
151 {"srto: bootloader", 26},
152 {"srto: kernel panic", 27},
153 {"srto: kernel watchdog reset", 28},
154 {"srto: normal", 29},
155 {"srto: reboot", 30},
156 {"srto: reboot-bootloader", 31},
157 {"srto: security watchdog reset", 32},
158 {"srto: wakesrc", 33},
159 {"srto: watchdog", 34},
160 {"srto:1-1", 35},
161 {"srto:omap_hsmm", 36},
162 {"srto:phy0", 37},
163 {"srto:rtc0", 38},
164 {"srto:touchpad", 39},
165 {"watchdog", 40},
166 {"watchdogr", 41},
167 {"wdog_bark", 42},
168 {"wdog_bite", 43},
169 {"wdog_reset", 44},
Mark Salyzyn274b5442018-08-07 08:45:13 -0700170 {"shutdown,", 45}, // Trailing comma is intentional. Do NOT use.
Mark Salyzyn14b1e6d2017-09-18 10:41:14 -0700171 {"shutdown,userrequested", 46},
172 {"reboot,bootloader", 47},
173 {"reboot,cold", 48},
174 {"reboot,recovery", 49},
175 {"thermal_shutdown", 50},
176 {"s3_wakeup", 51},
177 {"kernel_panic,sysrq", 52},
178 {"kernel_panic,NULL", 53},
Mark Salyzyn853bb802018-03-16 08:44:56 -0700179 {"kernel_panic,null", 53},
Mark Salyzyn14b1e6d2017-09-18 10:41:14 -0700180 {"kernel_panic,BUG", 54},
Mark Salyzyn853bb802018-03-16 08:44:56 -0700181 {"kernel_panic,bug", 54},
Mark Salyzyn14b1e6d2017-09-18 10:41:14 -0700182 {"bootloader", 55},
183 {"cold", 56},
184 {"hard", 57},
185 {"warm", 58},
Mark Salyzyn15199252018-03-16 09:26:05 -0700186 {"reboot,kernel_power_off_charging__reboot_system", 59}, // Can not happen
Mark Salyzyn14b1e6d2017-09-18 10:41:14 -0700187 {"thermal-shutdown", 60},
188 {"shutdown,thermal", 61},
189 {"shutdown,battery", 62},
190 {"reboot,ota", 63},
191 {"reboot,factory_reset", 64},
192 {"reboot,", 65},
193 {"reboot,shell", 66},
194 {"reboot,adb", 67},
Mark Salyzyn9033bf52017-09-21 11:30:29 -0700195 {"reboot,userrequested", 68},
Mark Salyzyn161b8622017-09-26 08:26:12 -0700196 {"shutdown,container", 69}, // Host OS asking Android Container to shutdown
Mark Salyzyn243fa292017-10-11 09:02:04 -0700197 {"cold,powerkey", 70},
198 {"warm,s3_wakeup", 71},
199 {"hard,hw_reset", 72},
200 {"shutdown,suspend", 73}, // Suspend to RAM
201 {"shutdown,hibernate", 74}, // Suspend to DISK
James Hawkins34073b52017-10-17 15:53:27 -0700202 {"power_on_key", 75},
203 {"reboot_by_key", 76},
204 {"wdt_by_pass_pwk", 77},
205 {"reboot_longkey", 78},
206 {"powerkey", 79},
207 {"usb", 80},
208 {"wdt", 81},
209 {"tool_by_pass_pwk", 82},
210 {"2sec_reboot", 83},
211 {"reboot,by_key", 84},
212 {"reboot,longkey", 85},
Mark Salyzyn186f6762018-03-16 11:00:26 -0700213 {"reboot,2sec", 86}, // Deprecate in two years, replaced with cold,rtc,2sec
Mark Salyzync89f9da2017-10-24 15:35:34 -0700214 {"shutdown,thermal,battery", 87},
Mark Salyzyn72a8ea32017-10-25 09:23:19 -0700215 {"reboot,its_just_so_hard", 88}, // produced by boot_reason_test
216 {"reboot,Its Just So Hard", 89}, // produced by boot_reason_test
Mark Salyzyn75046892018-05-03 13:11:15 -0700217 {"reboot,rescueparty", 90},
James Hawkins74b17582017-11-20 14:13:41 -0800218 {"charge", 91},
219 {"oem_tz_crash", 92},
Mark Salyzynec7bafe2018-09-26 08:01:04 -0700220 {"uvlo", 93}, // aliasReasons converts to reboot,undervoltage
James Hawkins74b17582017-11-20 14:13:41 -0800221 {"oem_ps_hold", 94},
222 {"abnormal_reset", 95},
223 {"oemerr_unknown", 96},
224 {"reboot_fastboot_mode", 97},
James Hawkins5f85f832017-11-29 14:30:06 -0800225 {"watchdog_apps_bite", 98},
226 {"xpu_err", 99},
227 {"power_on_usb", 100},
James Hawkinsf4444f02017-11-30 15:01:40 -0800228 {"watchdog_rpm", 101},
229 {"watchdog_nonsec", 102},
230 {"watchdog_apps_bark", 103},
231 {"reboot_dmverity_corrupted", 104},
Mark Salyzynf62983a2018-09-26 09:55:25 -0700232 {"reboot_smpl", 105}, // aliasReasons converts to reboot,powerloss
James Hawkins00433a22017-12-04 14:20:21 -0800233 {"watchdog_sdi_apps_reset", 106},
Mark Salyzynf62983a2018-09-26 09:55:25 -0700234 {"smpl", 107}, // aliasReasons converts to reboot,powerloss
James Hawkins00433a22017-12-04 14:20:21 -0800235 {"oem_modem_failed_to_powerup", 108},
James Hawkinse2c27242017-12-18 13:40:27 -0800236 {"reboot_normal", 109},
237 {"oem_lpass_cfg", 110},
238 {"oem_xpu_ns_error", 111},
239 {"power_key_press", 112},
240 {"hardware_reset", 113},
241 {"reboot_by_powerkey", 114},
242 {"reboot_verity", 115},
243 {"oem_rpm_undef_error", 116},
244 {"oem_crash_on_the_lk", 117},
245 {"oem_rpm_reset", 118},
Mark Salyzynf62983a2018-09-26 09:55:25 -0700246 {"reboot,powerloss", 119},
Mark Salyzynec7bafe2018-09-26 08:01:04 -0700247 {"reboot,undervoltage", 120},
James Hawkinse2c27242017-12-18 13:40:27 -0800248 {"factory_cable", 121},
249 {"oem_ar6320_failed_to_powerup", 122},
250 {"watchdog_rpm_bite", 123},
251 {"power_on_cable", 124},
252 {"reboot_unknown", 125},
253 {"wireless_charger", 126},
254 {"0x776655ff", 127},
255 {"oem_thermal_bite_reset", 128},
256 {"charger", 129},
257 {"pon1", 130},
258 {"unknown", 131},
259 {"reboot_rtc", 132},
260 {"cold_boot", 133},
261 {"hard_rst", 134},
James Hawkinsb607dae2018-01-05 14:42:55 -0800262 {"power-on", 135},
263 {"oem_adsp_resetting_the_soc", 136},
264 {"kpdpwr", 137},
265 {"oem_modem_timeout_waiting", 138},
266 {"usb_chg", 139},
267 {"warm_reset_0x02", 140},
268 {"warm_reset_0x80", 141},
269 {"pon_reason_0xb0", 142},
270 {"reboot_download", 143},
James Hawkins79a4ee22018-01-26 14:31:04 -0800271 {"reboot_recovery_mode", 144},
272 {"oem_sdi_err_fatal", 145},
273 {"pmic_watchdog", 146},
274 {"software_master", 147},
Mark Salyzyn8aa36c62018-03-16 11:00:14 -0700275 {"cold,charger", 148},
276 {"cold,rtc", 149},
Mark Salyzyn39cc3e72018-03-19 15:16:29 -0700277 {"cold,rtc,2sec", 150},
278 {"reboot,tool", 151},
279 {"reboot,wdt", 152},
280 {"reboot,unknown", 153},
Mark Salyzyn3f48fa92018-03-22 08:41:22 -0700281 {"kernel_panic,audit", 154},
282 {"kernel_panic,atomic", 155},
283 {"kernel_panic,hung", 156},
284 {"kernel_panic,hung,rcu", 157},
285 {"kernel_panic,init", 158},
286 {"kernel_panic,oom", 159},
287 {"kernel_panic,stack", 160},
Mark Salyzynafd66f22018-03-19 15:16:29 -0700288 {"kernel_panic,sysrq,livelock,alarm", 161}, // llkd
289 {"kernel_panic,sysrq,livelock,driver", 162}, // llkd
290 {"kernel_panic,sysrq,livelock,zombie", 163}, // llkd
Mark Salyzyn8ad6e672018-06-01 08:59:05 -0700291 {"kernel_panic,modem", 164},
292 {"kernel_panic,adsp", 165},
293 {"kernel_panic,dsps", 166},
294 {"kernel_panic,wcnss", 167},
Mark Salyzyn78e54fd2018-06-08 10:19:16 -0700295 {"kernel_panic,_sde_encoder_phys_cmd_handle_ppdone_timeout", 168},
Mark Salyzyn6fc08292019-03-11 10:06:36 -0700296 {"recovery,quiescent", 169},
297 {"reboot,quiescent", 170},
James Hawkinsa4a1a4a2016-02-09 15:32:38 -0800298};
299
300// Converts a string value representing the reason the system booted to an
301// integer representation. This is necessary for logging the boot_reason metric
302// via Tron, which does not accept non-integer buckets in histograms.
303int32_t BootReasonStrToEnum(const std::string& boot_reason) {
James Hawkinsa4a1a4a2016-02-09 15:32:38 -0800304 auto mapping = kBootReasonMap.find(boot_reason);
305 if (mapping != kBootReasonMap.end()) {
306 return mapping->second;
307 }
308
James Hawkins25f71222017-10-10 16:37:05 -0700309 if (boot_reason.empty()) {
310 return kEmptyBootReason;
311 }
312
James Hawkinsa4a1a4a2016-02-09 15:32:38 -0800313 LOG(INFO) << "Unknown boot reason: " << boot_reason;
314 return kUnknownBootReason;
315}
316
Mark Salyzynb304f6d2017-08-04 13:35:51 -0700317// Canonical list of supported primary reboot reasons.
318const std::vector<const std::string> knownReasons = {
Mark Salyzyn14b1e6d2017-09-18 10:41:14 -0700319 // clang-format off
320 // kernel
321 "watchdog",
322 "kernel_panic",
323 // strong
324 "recovery", // Should not happen from ro.boot.bootreason
325 "bootloader", // Should not happen from ro.boot.bootreason
326 // blunt
327 "cold",
328 "hard",
329 "warm",
Mark Salyzyn62909822017-10-09 09:27:16 -0700330 // super blunt
Mark Salyzyn14b1e6d2017-09-18 10:41:14 -0700331 "shutdown", // Can not happen from ro.boot.bootreason
332 "reboot", // Default catch-all for anything unknown
333 // clang-format on
Mark Salyzynb304f6d2017-08-04 13:35:51 -0700334};
335
336// Returns true if the supplied reason prefix is considered detailed enough.
337bool isStrongRebootReason(const std::string& r) {
Mark Salyzyn14b1e6d2017-09-18 10:41:14 -0700338 for (auto& s : knownReasons) {
Mark Salyzynb304f6d2017-08-04 13:35:51 -0700339 if (s == "cold") break;
340 // Prefix defined as terminated by a nul or comma (,).
Elliott Hughes579e6822017-12-20 09:41:00 -0800341 if (android::base::StartsWith(r, s) && ((r.length() == s.length()) || (r[s.length()] == ','))) {
Mark Salyzynb304f6d2017-08-04 13:35:51 -0700342 return true;
343 }
344 }
345 return false;
346}
347
348// Returns true if the supplied reason prefix is associated with the kernel.
349bool isKernelRebootReason(const std::string& r) {
Mark Salyzyn14b1e6d2017-09-18 10:41:14 -0700350 for (auto& s : knownReasons) {
Mark Salyzynb304f6d2017-08-04 13:35:51 -0700351 if (s == "recovery") break;
352 // Prefix defined as terminated by a nul or comma (,).
Elliott Hughes579e6822017-12-20 09:41:00 -0800353 if (android::base::StartsWith(r, s) && ((r.length() == s.length()) || (r[s.length()] == ','))) {
Mark Salyzynb304f6d2017-08-04 13:35:51 -0700354 return true;
355 }
356 }
357 return false;
358}
359
360// Returns true if the supplied reason prefix is considered known.
361bool isKnownRebootReason(const std::string& r) {
Mark Salyzyn14b1e6d2017-09-18 10:41:14 -0700362 for (auto& s : knownReasons) {
Mark Salyzynb304f6d2017-08-04 13:35:51 -0700363 // Prefix defined as terminated by a nul or comma (,).
Elliott Hughes579e6822017-12-20 09:41:00 -0800364 if (android::base::StartsWith(r, s) && ((r.length() == s.length()) || (r[s.length()] == ','))) {
Mark Salyzynb304f6d2017-08-04 13:35:51 -0700365 return true;
366 }
367 }
368 return false;
369}
370
371// If the reboot reason should be improved, report true if is too blunt.
372bool isBluntRebootReason(const std::string& r) {
373 if (isStrongRebootReason(r)) return false;
374
Mark Salyzyn14b1e6d2017-09-18 10:41:14 -0700375 if (!isKnownRebootReason(r)) return true; // Can not support unknown as detail
Mark Salyzynb304f6d2017-08-04 13:35:51 -0700376
377 size_t pos = 0;
378 while ((pos = r.find(',', pos)) != std::string::npos) {
379 ++pos;
380 std::string next(r.substr(pos));
381 if (next.length() == 0) break;
382 if (next[0] == ',') continue;
Mark Salyzyn14b1e6d2017-09-18 10:41:14 -0700383 if (!isKnownRebootReason(next)) return false; // Unknown subreason is good.
384 if (isStrongRebootReason(next)) return false; // eg: reboot,reboot
Mark Salyzynb304f6d2017-08-04 13:35:51 -0700385 }
386 return true;
387}
388
Mark Salyzyn64610892017-09-18 10:41:14 -0700389bool readPstoreConsole(std::string& console) {
390 if (android::base::ReadFileToString("/sys/fs/pstore/console-ramoops-0", &console)) {
391 return true;
392 }
393 return android::base::ReadFileToString("/sys/fs/pstore/console-ramoops", &console);
394}
395
Mark Salyzyn293cb3b2017-09-20 08:37:46 -0700396// Implement a variant of std::string::rfind that is resilient to errors in
397// the data stream being inspected.
398class pstoreConsole {
399 private:
400 const size_t kBitErrorRate = 8; // number of bits per error
401 const std::string& console;
402
403 // Number of bits that differ between the two arguments l and r.
404 // Returns zero if the values for l and r are identical.
405 size_t numError(uint8_t l, uint8_t r) const { return std::bitset<8>(l ^ r).count(); }
406
407 // A string comparison function, reports the number of errors discovered
408 // in the match to a maximum of the bitLength / kBitErrorRate, at that
409 // point returning npos to indicate match is too poor.
410 //
411 // Since called in rfind which works backwards, expect cache locality will
412 // help if we check in reverse here as well for performance.
413 //
414 // Assumption: l (from console.c_str() + pos) is long enough to house
415 // _r.length(), checked in rfind caller below.
416 //
417 size_t numError(size_t pos, const std::string& _r) const {
418 const char* l = console.c_str() + pos;
419 const char* r = _r.c_str();
420 size_t n = _r.length();
421 const uint8_t* le = reinterpret_cast<const uint8_t*>(l) + n;
422 const uint8_t* re = reinterpret_cast<const uint8_t*>(r) + n;
423 size_t count = 0;
424 n = 0;
425 do {
426 // individual character bit error rate > threshold + slop
427 size_t num = numError(*--le, *--re);
428 if (num > ((8 + kBitErrorRate) / kBitErrorRate)) return std::string::npos;
429 // total bit error rate > threshold + slop
430 count += num;
431 ++n;
432 if (count > ((n * 8 + kBitErrorRate - (n > 2)) / kBitErrorRate)) {
433 return std::string::npos;
434 }
435 } while (le != reinterpret_cast<const uint8_t*>(l));
436 return count;
437 }
438
439 public:
440 explicit pstoreConsole(const std::string& console) : console(console) {}
441 // scope of argument must be equal to or greater than scope of pstoreConsole
442 explicit pstoreConsole(const std::string&& console) = delete;
443 explicit pstoreConsole(std::string&& console) = delete;
444
445 // Our implementation of rfind, use exact match first, then resort to fuzzy.
446 size_t rfind(const std::string& needle) const {
447 size_t pos = console.rfind(needle); // exact match?
448 if (pos != std::string::npos) return pos;
449
450 // Check to make sure needle fits in console string.
451 pos = console.length();
452 if (needle.length() > pos) return std::string::npos;
453 pos -= needle.length();
454 // fuzzy match to maximum kBitErrorRate
Ivan Lozano44d3cac2017-11-07 13:13:55 -0800455 for (;;) {
Mark Salyzyn293cb3b2017-09-20 08:37:46 -0700456 if (numError(pos, needle) != std::string::npos) return pos;
Ivan Lozano44d3cac2017-11-07 13:13:55 -0800457 if (pos == 0) break;
458 --pos;
459 }
Mark Salyzyn293cb3b2017-09-20 08:37:46 -0700460 return std::string::npos;
461 }
462
463 // Our implementation of find, use only fuzzy match.
464 size_t find(const std::string& needle, size_t start = 0) const {
465 // Check to make sure needle fits in console string.
466 if (needle.length() > console.length()) return std::string::npos;
467 const size_t last_pos = console.length() - needle.length();
468 // fuzzy match to maximum kBitErrorRate
469 for (size_t pos = start; pos <= last_pos; ++pos) {
470 if (numError(pos, needle) != std::string::npos) return pos;
471 }
472 return std::string::npos;
473 }
Mark Salyzyn39cc3e72018-03-19 15:16:29 -0700474
475 operator const std::string&() const { return console; }
Mark Salyzyn293cb3b2017-09-20 08:37:46 -0700476};
477
478// If bit error match to needle, correct it.
479// Return true if any corrections were discovered and applied.
Mark Salyzyn1e7d1c72018-03-16 08:57:20 -0700480bool correctForBitError(std::string& reason, const std::string& needle) {
Mark Salyzyn293cb3b2017-09-20 08:37:46 -0700481 bool corrected = false;
482 if (reason.length() < needle.length()) return corrected;
483 const pstoreConsole console(reason);
484 const size_t last_pos = reason.length() - needle.length();
485 for (size_t pos = 0; pos <= last_pos; pos += needle.length()) {
486 pos = console.find(needle, pos);
487 if (pos == std::string::npos) break;
488
489 // exact match has no malice
490 if (needle == reason.substr(pos, needle.length())) continue;
491
492 corrected = true;
493 reason = reason.substr(0, pos) + needle + reason.substr(pos + needle.length());
494 }
495 return corrected;
496}
497
Mark Salyzyn1e7d1c72018-03-16 08:57:20 -0700498// If bit error match to needle, correct it.
499// Return true if any corrections were discovered and applied.
500// Try again if we can replace underline with spaces.
501bool correctForBitErrorOrUnderline(std::string& reason, const std::string& needle) {
502 bool corrected = correctForBitError(reason, needle);
503 std::string _needle(needle);
504 std::transform(_needle.begin(), _needle.end(), _needle.begin(),
505 [](char c) { return (c == '_') ? ' ' : c; });
506 if (needle != _needle) {
507 corrected |= correctForBitError(reason, _needle);
508 }
509 return corrected;
510}
511
Mark Salyzyn39cc3e72018-03-19 15:16:29 -0700512// Converts a string value representing the reason the system booted to a
513// string complying with Android system standard reason.
514void transformReason(std::string& reason) {
515 std::transform(reason.begin(), reason.end(), reason.begin(), ::tolower);
516 std::transform(reason.begin(), reason.end(), reason.begin(),
517 [](char c) { return ::isblank(c) ? '_' : c; });
518 std::transform(reason.begin(), reason.end(), reason.begin(),
519 [](char c) { return ::isprint(c) ? c : '?'; });
520}
521
Mark Salyzyn3f48fa92018-03-22 08:41:22 -0700522// Check subreasons for reboot,<subreason> kernel_panic,sysrq,<subreason> or
523// kernel_panic,<subreason>.
524//
525// If quoted flag is set, pull out and correct single quoted ('), newline (\n)
526// or unprintable character terminated subreason, pos is supplied just beyond
527// first quote. if quoted false, pull out and correct newline (\n) or
528// unprintable character terminated subreason.
529//
530// Heuristics to find termination is painted into a corner:
531
532// single bit error for quote ' that we can block. It is acceptable for
533// the others 7, g in reason. 2/9 chance will miss the terminating quote,
534// but there is always the terminating newline that usually immediately
535// follows to fortify our chances.
536bool likely_single_quote(char c) {
537 switch (static_cast<uint8_t>(c)) {
538 case '\'': // '\''
539 case '\'' ^ 0x01: // '&'
540 case '\'' ^ 0x02: // '%'
541 case '\'' ^ 0x04: // '#'
542 case '\'' ^ 0x08: // '/'
543 return true;
544 case '\'' ^ 0x10: // '7'
545 break;
546 case '\'' ^ 0x20: // '\a' (unprintable)
547 return true;
548 case '\'' ^ 0x40: // 'g'
549 break;
550 case '\'' ^ 0x80: // 0xA7 (unprintable)
551 return true;
552 }
553 return false;
554}
555
556// ::isprint(c) and likely_space() will prevent us from being called for
557// fundamentally printable entries, except for '\r' and '\b'.
558//
559// Except for * and J, single bit errors for \n, all others are non-
560// printable so easy catch. It is _acceptable_ for *, J or j to exist in
561// the reason string, so 2/9 chance we will miss the terminating newline.
562//
563// NB: J might not be acceptable, except if at the beginning or preceded
564// with a space, '(' or any of the quotes and their BER aliases.
565// NB: * might not be acceptable, except if at the beginning or preceded
566// with a space, another *, or any of the quotes or their BER aliases.
567//
568// To reduce the chances to closer to 1/9 is too complicated for the gain.
569bool likely_newline(char c) {
570 switch (static_cast<uint8_t>(c)) {
571 case '\n': // '\n' (unprintable)
572 case '\n' ^ 0x01: // '\r' (unprintable)
573 case '\n' ^ 0x02: // '\b' (unprintable)
574 case '\n' ^ 0x04: // 0x0E (unprintable)
575 case '\n' ^ 0x08: // 0x02 (unprintable)
576 case '\n' ^ 0x10: // 0x1A (unprintable)
577 return true;
578 case '\n' ^ 0x20: // '*'
579 case '\n' ^ 0x40: // 'J'
580 break;
581 case '\n' ^ 0x80: // 0x8A (unprintable)
582 return true;
583 }
584 return false;
585}
586
587// ::isprint(c) will prevent us from being called for all the printable
588// matches below. If we let unprintables through because of this, they
589// get converted to underscore (_) by the validation phase.
590bool likely_space(char c) {
591 switch (static_cast<uint8_t>(c)) {
592 case ' ': // ' '
593 case ' ' ^ 0x01: // '!'
594 case ' ' ^ 0x02: // '"'
595 case ' ' ^ 0x04: // '$'
596 case ' ' ^ 0x08: // '('
597 case ' ' ^ 0x10: // '0'
598 case ' ' ^ 0x20: // '\0' (unprintable)
599 case ' ' ^ 0x40: // 'P'
600 case ' ' ^ 0x80: // 0xA0 (unprintable)
601 case '\t': // '\t'
602 case '\t' ^ 0x01: // '\b' (unprintable) (likely_newline counters)
603 case '\t' ^ 0x02: // '\v' (unprintable)
604 case '\t' ^ 0x04: // '\r' (unprintable) (likely_newline counters)
605 case '\t' ^ 0x08: // 0x01 (unprintable)
606 case '\t' ^ 0x10: // 0x19 (unprintable)
607 case '\t' ^ 0x20: // ')'
608 case '\t' ^ 0x40: // '1'
609 case '\t' ^ 0x80: // 0x89 (unprintable)
610 return true;
611 }
612 return false;
613}
614
615std::string getSubreason(const std::string& content, size_t pos, bool quoted) {
Mark Salyzyn39cc3e72018-03-19 15:16:29 -0700616 static constexpr size_t max_reason_length = 256;
617
618 std::string subReason(content.substr(pos, max_reason_length));
619 // Correct against any known strings that Bit Error Match
620 for (const auto& s : knownReasons) {
621 correctForBitErrorOrUnderline(subReason, s);
622 }
Mark Salyzyn3f48fa92018-03-22 08:41:22 -0700623 std::string terminator(quoted ? "'" : "");
Mark Salyzyn39cc3e72018-03-19 15:16:29 -0700624 for (const auto& m : kBootReasonMap) {
625 if (m.first.length() <= strlen("cold")) continue; // too short?
Mark Salyzyn3f48fa92018-03-22 08:41:22 -0700626 if (correctForBitErrorOrUnderline(subReason, m.first + terminator)) continue;
Mark Salyzyn39cc3e72018-03-19 15:16:29 -0700627 if (m.first.length() <= strlen("reboot,cold")) continue; // short?
628 if (android::base::StartsWith(m.first, "reboot,")) {
Mark Salyzyn3f48fa92018-03-22 08:41:22 -0700629 correctForBitErrorOrUnderline(subReason, m.first.substr(strlen("reboot,")) + terminator);
Mark Salyzyn39cc3e72018-03-19 15:16:29 -0700630 } else if (android::base::StartsWith(m.first, "kernel_panic,sysrq,")) {
Mark Salyzyn3f48fa92018-03-22 08:41:22 -0700631 correctForBitErrorOrUnderline(subReason,
632 m.first.substr(strlen("kernel_panic,sysrq,")) + terminator);
633 } else if (android::base::StartsWith(m.first, "kernel_panic,")) {
634 correctForBitErrorOrUnderline(subReason, m.first.substr(strlen("kernel_panic,")) + terminator);
Mark Salyzyn39cc3e72018-03-19 15:16:29 -0700635 }
636 }
637 for (pos = 0; pos < subReason.length(); ++pos) {
638 char c = subReason[pos];
Mark Salyzyn3f48fa92018-03-22 08:41:22 -0700639 if (!(::isprint(c) || likely_space(c)) || likely_newline(c) ||
640 (quoted && likely_single_quote(c))) {
Mark Salyzyn39cc3e72018-03-19 15:16:29 -0700641 subReason.erase(pos);
642 break;
643 }
644 }
645 transformReason(subReason);
646 return subReason;
647}
648
Mark Salyzyn293cb3b2017-09-20 08:37:46 -0700649bool addKernelPanicSubReason(const pstoreConsole& console, std::string& ret) {
Mark Salyzyn64610892017-09-18 10:41:14 -0700650 // Check for kernel panic types to refine information
Mark Salyzyn853bb802018-03-16 08:44:56 -0700651 if ((console.rfind("SysRq : Trigger a crash") != std::string::npos) ||
652 (console.rfind("PC is at sysrq_handle_crash+") != std::string::npos)) {
Mark Salyzyn64610892017-09-18 10:41:14 -0700653 ret = "kernel_panic,sysrq";
Mark Salyzyn39cc3e72018-03-19 15:16:29 -0700654 // Invented for Android to allow daemons that specifically trigger sysrq
655 // to communicate more accurate boot subreasons via last console messages.
656 static constexpr char sysrqSubreason[] = "SysRq : Trigger a crash : '";
657 auto pos = console.rfind(sysrqSubreason);
658 if (pos != std::string::npos) {
Mark Salyzyn3f48fa92018-03-22 08:41:22 -0700659 ret += "," + getSubreason(console, pos + strlen(sysrqSubreason), /* quoted */ true);
Mark Salyzyn39cc3e72018-03-19 15:16:29 -0700660 }
Mark Salyzyn64610892017-09-18 10:41:14 -0700661 return true;
662 }
663 if (console.rfind("Unable to handle kernel NULL pointer dereference at virtual address") !=
664 std::string::npos) {
Mark Salyzyn853bb802018-03-16 08:44:56 -0700665 ret = "kernel_panic,null";
Mark Salyzyn64610892017-09-18 10:41:14 -0700666 return true;
667 }
668 if (console.rfind("Kernel BUG at ") != std::string::npos) {
Mark Salyzyn853bb802018-03-16 08:44:56 -0700669 ret = "kernel_panic,bug";
Mark Salyzyn64610892017-09-18 10:41:14 -0700670 return true;
671 }
Mark Salyzyn3f48fa92018-03-22 08:41:22 -0700672
673 std::string panic("Kernel panic - not syncing: ");
674 auto pos = console.rfind(panic);
675 if (pos != std::string::npos) {
676 static const std::vector<std::pair<const std::string, const std::string>> panicReasons = {
677 {"Out of memory", "oom"},
678 {"out of memory", "oom"},
679 {"Oh boy, that early out of memory", "oom"}, // omg
680 {"BUG!", "bug"},
681 {"hung_task: blocked tasks", "hung"},
682 {"audit: ", "audit"},
683 {"scheduling while atomic", "atomic"},
684 {"Attempted to kill init!", "init"},
685 {"Requested init", "init"},
686 {"No working init", "init"},
687 {"Could not decompress init", "init"},
688 {"RCU Stall", "hung,rcu"},
689 {"stack-protector", "stack"},
690 {"kernel stack overflow", "stack"},
691 {"Corrupt kernel stack", "stack"},
692 {"low stack detected", "stack"},
693 {"corrupted stack end", "stack"},
Mark Salyzyn8ad6e672018-06-01 08:59:05 -0700694 {"subsys-restart: Resetting the SoC - modem crashed.", "modem"},
695 {"subsys-restart: Resetting the SoC - adsp crashed.", "adsp"},
696 {"subsys-restart: Resetting the SoC - dsps crashed.", "dsps"},
697 {"subsys-restart: Resetting the SoC - wcnss crashed.", "wcnss"},
Mark Salyzyn3f48fa92018-03-22 08:41:22 -0700698 };
699
700 ret = "kernel_panic";
701 for (auto& s : panicReasons) {
702 if (console.find(panic + s.first, pos) != std::string::npos) {
703 ret += "," + s.second;
704 return true;
705 }
706 }
707 auto reason = getSubreason(console, pos + panic.length(), /* newline */ false);
708 if (reason.length() > 3) {
709 ret += "," + reason;
710 }
711 return true;
712 }
Mark Salyzyn64610892017-09-18 10:41:14 -0700713 return false;
714}
715
Mark Salyzyn293cb3b2017-09-20 08:37:46 -0700716bool addKernelPanicSubReason(const std::string& content, std::string& ret) {
717 return addKernelPanicSubReason(pstoreConsole(content), ret);
718}
719
Mark Salyzynb304f6d2017-08-04 13:35:51 -0700720const char system_reboot_reason_property[] = "sys.boot.reason";
721const char last_reboot_reason_property[] = LAST_REBOOT_REASON_PROPERTY;
Mark Salyzynadc433d2018-06-05 08:17:35 -0700722const char last_last_reboot_reason_property[] = "sys.boot.reason.last";
Mark Salyzyn5c58c9d2018-06-28 09:21:55 -0700723constexpr size_t history_reboot_reason_size = 4;
724const char history_reboot_reason_property[] = LAST_REBOOT_REASON_PROPERTY ".history";
Mark Salyzynb304f6d2017-08-04 13:35:51 -0700725const char bootloader_reboot_reason_property[] = "ro.boot.bootreason";
726
Mark Salyzyn5c58c9d2018-06-28 09:21:55 -0700727// Land system_boot_reason into system_reboot_reason_property.
728// Shift system_boot_reason into history_reboot_reason_property.
729void BootReasonAddToHistory(const std::string& system_boot_reason) {
730 if (system_boot_reason.empty()) return;
731 LOG(INFO) << "Canonical boot reason: " << system_boot_reason;
Mark Salyzyn88d308d2019-02-08 10:53:18 -0800732 auto old_system_boot_reason = android::base::GetProperty(system_reboot_reason_property, "");
733 if (!android::base::SetProperty(system_reboot_reason_property, system_boot_reason)) {
734 android::base::SetProperty(system_reboot_reason_property,
735 system_boot_reason.substr(0, PROPERTY_VALUE_MAX - 1));
Mark Salyzyn5c58c9d2018-06-28 09:21:55 -0700736 }
Mark Salyzyn88d308d2019-02-08 10:53:18 -0800737 auto reason_history =
738 android::base::Split(android::base::GetProperty(history_reboot_reason_property, ""), "\n");
Mark Salyzyn5c58c9d2018-06-28 09:21:55 -0700739 static auto mark = time(nullptr);
740 auto mark_str = std::string(",") + std::to_string(mark);
741 auto marked_system_boot_reason = system_boot_reason + mark_str;
742 if (!reason_history.empty()) {
743 // delete any entries that we just wrote in a previous
744 // call and leveraging duplicate line handling
745 auto last = old_system_boot_reason + mark_str;
746 // trim the list to (history_reboot_reason_size - 1)
747 ssize_t max = history_reboot_reason_size;
748 for (auto it = reason_history.begin(); it != reason_history.end();) {
749 if (it->empty() || (last == *it) || (marked_system_boot_reason == *it) || (--max <= 0)) {
750 it = reason_history.erase(it);
751 } else {
752 last = *it;
753 ++it;
754 }
755 }
756 }
757 // insert at the front, concatenating mark (<epoch time>) detail to the value.
758 reason_history.insert(reason_history.begin(), marked_system_boot_reason);
759 // If the property string is too long ( > PROPERTY_VALUE_MAX)
760 // we get an error, so trim out last entry and try again.
Mark Salyzyn88d308d2019-02-08 10:53:18 -0800761 while (!android::base::SetProperty(history_reboot_reason_property,
762 android::base::Join(reason_history, '\n'))) {
Mark Salyzyn5c58c9d2018-06-28 09:21:55 -0700763 auto it = std::prev(reason_history.end());
764 if (it == reason_history.end()) break;
765 reason_history.erase(it);
766 }
767}
768
Mark Salyzynb304f6d2017-08-04 13:35:51 -0700769// Scrub, Sanitize, Standardize and Enhance the boot reason string supplied.
770std::string BootReasonStrToReason(const std::string& boot_reason) {
Mark Salyzyn88d308d2019-02-08 10:53:18 -0800771 auto ret = android::base::GetProperty(system_reboot_reason_property, "");
Mark Salyzynb304f6d2017-08-04 13:35:51 -0700772 std::string reason(boot_reason);
773 // If sys.boot.reason == ro.boot.bootreason, let's re-evaluate
774 if (reason == ret) ret = "";
775
Mark Salyzyn88d692c2017-09-20 08:37:46 -0700776 transformReason(reason);
Mark Salyzynb304f6d2017-08-04 13:35:51 -0700777
778 // Is the current system boot reason sys.boot.reason valid?
779 if (!isKnownRebootReason(ret)) ret = "";
780
781 if (ret == "") {
782 // Is the bootloader boot reason ro.boot.bootreason known?
783 std::vector<std::string> words(android::base::Split(reason, ",_-"));
Mark Salyzyn14b1e6d2017-09-18 10:41:14 -0700784 for (auto& s : knownReasons) {
Mark Salyzynb304f6d2017-08-04 13:35:51 -0700785 std::string blunt;
Mark Salyzyn14b1e6d2017-09-18 10:41:14 -0700786 for (auto& r : words) {
Mark Salyzynb304f6d2017-08-04 13:35:51 -0700787 if (r == s) {
788 if (isBluntRebootReason(s)) {
789 blunt = s;
790 } else {
791 ret = s;
792 break;
793 }
794 }
795 }
796 if (ret == "") ret = blunt;
797 if (ret != "") break;
798 }
799 }
800
801 if (ret == "") {
802 // A series of checks to take some officially unsupported reasons
803 // reported by the bootloader and find some logical and canonical
804 // sense. In an ideal world, we would require those bootloaders
Mark Salyzyn25900dd2018-03-16 09:05:59 -0700805 // to behave and follow our CTS standards.
806 //
807 // first member is the output
808 // second member is an unanchored regex for an alias
809 //
Mark Salyzyn28193282018-03-16 09:05:59 -0700810 // If output has a prefix of <bang> '!', we do not use it as a
811 // match needle (and drop the <bang> prefix when landing in output),
812 // otherwise look for it as well. This helps keep the scale of the
Mark Salyzyn25900dd2018-03-16 09:05:59 -0700813 // following table smaller.
Mark Salyzynb304f6d2017-08-04 13:35:51 -0700814 static const std::vector<std::pair<const std::string, const std::string>> aliasReasons = {
Mark Salyzyn14b1e6d2017-09-18 10:41:14 -0700815 {"watchdog", "wdog"},
Mark Salyzyn25900dd2018-03-16 09:05:59 -0700816 {"cold,powerkey", "powerkey|power_key|PowerKey"},
Mark Salyzyn14b1e6d2017-09-18 10:41:14 -0700817 {"kernel_panic", "panic"},
818 {"shutdown,thermal", "thermal"},
819 {"warm,s3_wakeup", "s3_wakeup"},
820 {"hard,hw_reset", "hw_reset"},
Mark Salyzyn8aa36c62018-03-16 11:00:14 -0700821 {"cold,charger", "usb"},
822 {"cold,rtc", "rtc"},
Mark Salyzyn186f6762018-03-16 11:00:26 -0700823 {"cold,rtc,2sec", "2sec_reboot"},
824 {"!warm", "wdt_by_pass_pwk"}, // change flavour of blunt
825 {"!reboot", "^wdt$"}, // change flavour of blunt
826 {"reboot,tool", "tool_by_pass_pwk"},
Mark Salyzyn88d1b4a2018-06-07 09:39:24 -0700827 {"!reboot,longkey", "reboot_longkey"},
828 {"!reboot,longkey", "kpdpwr"},
Mark Salyzynec7bafe2018-09-26 08:01:04 -0700829 {"!reboot,undervoltage", "uvlo"},
Mark Salyzynf62983a2018-09-26 09:55:25 -0700830 {"!reboot,powerloss", "smpl"},
Mark Salyzyn14b1e6d2017-09-18 10:41:14 -0700831 {"bootloader", ""},
Mark Salyzynb304f6d2017-08-04 13:35:51 -0700832 };
833
Mark Salyzyn14b1e6d2017-09-18 10:41:14 -0700834 for (auto& s : aliasReasons) {
Mark Salyzyn28193282018-03-16 09:05:59 -0700835 size_t firstHasNot = s.first[0] == '!';
836 if (!firstHasNot && (reason.find(s.first) != std::string::npos)) {
Mark Salyzynb304f6d2017-08-04 13:35:51 -0700837 ret = s.first;
838 break;
839 }
Mark Salyzyn25900dd2018-03-16 09:05:59 -0700840 if (s.second.size() && std::regex_search(reason, std::regex(s.second))) {
Mark Salyzyn28193282018-03-16 09:05:59 -0700841 ret = s.first.substr(firstHasNot);
Mark Salyzynb304f6d2017-08-04 13:35:51 -0700842 break;
843 }
844 }
845 }
846
847 // If watchdog is the reason, see if there is a security angle?
848 if (ret == "watchdog") {
849 if (reason.find("sec") != std::string::npos) {
850 ret += ",security";
851 }
852 }
853
Mark Salyzyn64610892017-09-18 10:41:14 -0700854 if (ret == "kernel_panic") {
Mark Salyzynb304f6d2017-08-04 13:35:51 -0700855 // Check to see if last klog has some refinement hints.
856 std::string content;
Mark Salyzyn64610892017-09-18 10:41:14 -0700857 if (readPstoreConsole(content)) {
858 addKernelPanicSubReason(content, ret);
Mark Salyzynb304f6d2017-08-04 13:35:51 -0700859 }
Mark Salyzyn64610892017-09-18 10:41:14 -0700860 } else if (isBluntRebootReason(ret)) {
861 // Check the other available reason resources if the reason is still blunt.
Mark Salyzynb304f6d2017-08-04 13:35:51 -0700862
Mark Salyzyn64610892017-09-18 10:41:14 -0700863 // Check to see if last klog has some refinement hints.
864 std::string content;
865 if (readPstoreConsole(content)) {
Mark Salyzyn293cb3b2017-09-20 08:37:46 -0700866 const pstoreConsole console(content);
Mark Salyzyn64610892017-09-18 10:41:14 -0700867 // The toybox reboot command used directly (unlikely)? But also
868 // catches init's response to Android's more controlled reboot command.
Mark Salyzyn293cb3b2017-09-20 08:37:46 -0700869 if (console.rfind("reboot: Power down") != std::string::npos) {
Mark Salyzyn64610892017-09-18 10:41:14 -0700870 ret = "shutdown"; // Still too blunt, but more accurate.
871 // ToDo: init should record the shutdown reason to kernel messages ala:
872 // init: shutdown system with command 'last_reboot_reason'
873 // so that if pstore has persistence we can get some details
874 // that could be missing in last_reboot_reason_property.
875 }
Mark Salyzynb304f6d2017-08-04 13:35:51 -0700876
Mark Salyzyn64610892017-09-18 10:41:14 -0700877 static const char cmd[] = "reboot: Restarting system with command '";
Mark Salyzyn293cb3b2017-09-20 08:37:46 -0700878 size_t pos = console.rfind(cmd);
Mark Salyzyn64610892017-09-18 10:41:14 -0700879 if (pos != std::string::npos) {
Mark Salyzyn3f48fa92018-03-22 08:41:22 -0700880 std::string subReason(getSubreason(content, pos + strlen(cmd), /* quoted */ true));
Mark Salyzyn64610892017-09-18 10:41:14 -0700881 if (subReason != "") { // Will not land "reboot" as that is too blunt.
882 if (isKernelRebootReason(subReason)) {
883 ret = "reboot," + subReason; // User space can't talk kernel reasons.
Mark Salyzyndafced92017-09-20 08:37:46 -0700884 } else if (isKnownRebootReason(subReason)) {
Mark Salyzyn64610892017-09-18 10:41:14 -0700885 ret = subReason;
Mark Salyzyndafced92017-09-20 08:37:46 -0700886 } else {
887 ret = "reboot," + subReason; // legitimize unknown reasons
Mark Salyzyn64610892017-09-18 10:41:14 -0700888 }
Mark Salyzynb304f6d2017-08-04 13:35:51 -0700889 }
Mark Salyzyn15199252018-03-16 09:26:05 -0700890 // Some bootloaders shutdown results record in last kernel message.
891 if (!strcmp(ret.c_str(), "reboot,kernel_power_off_charging__reboot_system")) {
892 ret = "shutdown";
893 }
Mark Salyzynb304f6d2017-08-04 13:35:51 -0700894 }
Mark Salyzynb304f6d2017-08-04 13:35:51 -0700895
Mark Salyzyn64610892017-09-18 10:41:14 -0700896 // Check for kernel panics, allowed to override reboot command.
Mark Salyzyn293cb3b2017-09-20 08:37:46 -0700897 if (!addKernelPanicSubReason(console, ret) &&
Mark Salyzyn64610892017-09-18 10:41:14 -0700898 // check for long-press power down
Mark Salyzyn293cb3b2017-09-20 08:37:46 -0700899 ((console.rfind("Power held for ") != std::string::npos) ||
900 (console.rfind("charger: [") != std::string::npos))) {
Mark Salyzyn64610892017-09-18 10:41:14 -0700901 ret = "cold";
902 }
Mark Salyzynb304f6d2017-08-04 13:35:51 -0700903 }
904
Elliott Hughes50a24eb2018-06-14 10:59:09 -0700905 // TODO: use the HAL to get battery level (http://b/77725702).
Mark Salyzynb304f6d2017-08-04 13:35:51 -0700906
907 // Is there a controlled shutdown hint in last_reboot_reason_property?
908 if (isBluntRebootReason(ret)) {
909 // Content buffer no longer will have console data. Beware if more
910 // checks added below, that depend on parsing console content.
Mark Salyzyn88d308d2019-02-08 10:53:18 -0800911 content = android::base::GetProperty(last_reboot_reason_property, "");
Mark Salyzyn88d692c2017-09-20 08:37:46 -0700912 transformReason(content);
Mark Salyzynb304f6d2017-08-04 13:35:51 -0700913
Mark Salyzyn62909822017-10-09 09:27:16 -0700914 // Anything in last is better than 'super-blunt' reboot or shutdown.
915 if ((ret == "") || (ret == "reboot") || (ret == "shutdown") || !isBluntRebootReason(content)) {
916 ret = content;
Mark Salyzynb304f6d2017-08-04 13:35:51 -0700917 }
918 }
919
920 // Other System Health HAL reasons?
921
922 // ToDo: /proc/sys/kernel/boot_reason needs a HAL interface to
923 // possibly offer hardware-specific clues from the PMIC.
924 }
925
926 // If unknown left over from above, make it "reboot,<boot_reason>"
927 if (ret == "") {
928 ret = "reboot";
929 if (android::base::StartsWith(reason, "reboot")) {
930 reason = reason.substr(strlen("reboot"));
Mark Salyzyn0af71a52017-10-05 13:58:04 -0700931 while ((reason[0] == ',') || (reason[0] == '_')) {
Mark Salyzynb304f6d2017-08-04 13:35:51 -0700932 reason = reason.substr(1);
933 }
934 }
935 if (reason != "") {
936 ret += ",";
937 ret += reason;
938 }
939 }
940
941 LOG(INFO) << "Canonical boot reason: " << ret;
Mark Salyzynb304f6d2017-08-04 13:35:51 -0700942 return ret;
943}
944
James Hawkinsb9cf7712016-04-08 15:32:19 -0700945// Returns the appropriate metric key prefix for the boot_complete metric such
946// that boot metrics after a system update are labeled as ota_boot_complete;
947// otherwise, they are labeled as boot_complete. This method encapsulates the
948// bookkeeping required to track when a system update has occurred by storing
949// the UTC timestamp of the system build date and comparing against the current
950// system build date.
951std::string CalculateBootCompletePrefix() {
952 static const std::string kBuildDateKey = "build_date";
953 std::string boot_complete_prefix = "boot_complete";
954
Mark Salyzyn88d308d2019-02-08 10:53:18 -0800955 auto build_date_str = android::base::GetProperty("ro.build.date.utc", "");
James Hawkins4dded612016-07-28 11:50:23 -0700956 int32_t build_date;
Elliott Hughesda46b392016-10-11 17:09:00 -0700957 if (!android::base::ParseInt(build_date_str, &build_date)) {
James Hawkins4dded612016-07-28 11:50:23 -0700958 return std::string();
959 }
James Hawkinsb9cf7712016-04-08 15:32:19 -0700960
961 BootEventRecordStore boot_event_store;
962 BootEventRecordStore::BootEventRecord record;
James Hawkins0bc4ad42017-05-30 15:03:15 -0700963 if (!boot_event_store.GetBootEvent(kBuildDateKey, &record)) {
964 boot_complete_prefix = "factory_reset_" + boot_complete_prefix;
965 boot_event_store.AddBootEventWithValue(kBuildDateKey, build_date);
Mark Salyzyn5c58c9d2018-06-28 09:21:55 -0700966 BootReasonAddToHistory("reboot,factory_reset");
James Hawkins0bc4ad42017-05-30 15:03:15 -0700967 } else if (build_date != record.second) {
James Hawkinsb9cf7712016-04-08 15:32:19 -0700968 boot_complete_prefix = "ota_" + boot_complete_prefix;
969 boot_event_store.AddBootEventWithValue(kBuildDateKey, build_date);
Mark Salyzyn5c58c9d2018-06-28 09:21:55 -0700970 BootReasonAddToHistory("reboot,ota");
James Hawkinsb9cf7712016-04-08 15:32:19 -0700971 }
972
973 return boot_complete_prefix;
974}
975
James Hawkinsef0a0902017-01-06 14:38:23 -0800976// Records the value of a given ro.boottime.init property in milliseconds.
Mark Salyzyn14b1e6d2017-09-18 10:41:14 -0700977void RecordInitBootTimeProp(BootEventRecordStore* boot_event_store, const char* property) {
Mark Salyzyn88d308d2019-02-08 10:53:18 -0800978 auto value = android::base::GetProperty(property, "");
James Hawkinsef0a0902017-01-06 14:38:23 -0800979
James Hawkins27c05222017-01-26 11:55:44 -0800980 int32_t time_in_ms;
981 if (android::base::ParseInt(value, &time_in_ms)) {
James Hawkinsef0a0902017-01-06 14:38:23 -0800982 boot_event_store->AddBootEventWithValue(property, time_in_ms);
983 }
984}
985
James Hawkins1bfcaec2017-05-19 14:27:27 -0700986// A map from bootloader timing stage to the time that stage took during boot.
987typedef std::map<std::string, int32_t> BootloaderTimingMap;
988
989// Returns a mapping from bootloader stage names to the time those stages
990// took to boot.
991const BootloaderTimingMap GetBootLoaderTimings() {
992 BootloaderTimingMap timings;
993
994 // |ro.boot.boottime| is of the form 'stage1:time1,...,stageN:timeN',
995 // where timeN is in milliseconds.
Mark Salyzyn88d308d2019-02-08 10:53:18 -0800996 auto value = android::base::GetProperty("ro.boot.boottime", "");
James Hawkins6b5c5aa2017-02-16 11:53:03 -0800997 if (value.empty()) {
998 // ro.boot.boottime is not reported on all devices.
James Hawkins1bfcaec2017-05-19 14:27:27 -0700999 return BootloaderTimingMap();
James Hawkins6b5c5aa2017-02-16 11:53:03 -08001000 }
James Hawkinsbe46fd12017-02-02 16:21:25 -08001001
1002 auto stages = android::base::Split(value, ",");
James Hawkins1bfcaec2017-05-19 14:27:27 -07001003 for (const auto& stageTiming : stages) {
James Hawkinsbe46fd12017-02-02 16:21:25 -08001004 // |stageTiming| is of the form 'stage:time'.
1005 auto stageTimingValues = android::base::Split(stageTiming, ":");
James Hawkins0bc4ad42017-05-30 15:03:15 -07001006 DCHECK_EQ(2U, stageTimingValues.size());
James Hawkinsbe46fd12017-02-02 16:21:25 -08001007
Mark Salyzyn7c721162019-02-08 10:41:15 -08001008 if (stageTimingValues.size() < 2) continue;
James Hawkinsbe46fd12017-02-02 16:21:25 -08001009 std::string stageName = stageTimingValues[0];
1010 int32_t time_ms;
1011 if (android::base::ParseInt(stageTimingValues[1], &time_ms)) {
James Hawkins1bfcaec2017-05-19 14:27:27 -07001012 timings[stageName] = time_ms;
James Hawkinsbe46fd12017-02-02 16:21:25 -08001013 }
1014 }
James Hawkins6b5c5aa2017-02-16 11:53:03 -08001015
James Hawkins1bfcaec2017-05-19 14:27:27 -07001016 return timings;
1017}
1018
Tej Singh4eacd382018-01-25 17:59:57 -08001019// Returns the total bootloader boot time from the ro.boot.boottime system property.
1020int32_t GetBootloaderTime(const BootloaderTimingMap& bootloader_timings) {
1021 int32_t total_time = 0;
1022 for (const auto& timing : bootloader_timings) {
1023 total_time += timing.second;
1024 }
1025
1026 return total_time;
1027}
1028
James Hawkins1bfcaec2017-05-19 14:27:27 -07001029// Parses and records the set of bootloader stages and associated boot times
1030// from the ro.boot.boottime system property.
1031void RecordBootloaderTimings(BootEventRecordStore* boot_event_store,
1032 const BootloaderTimingMap& bootloader_timings) {
1033 int32_t total_time = 0;
1034 for (const auto& timing : bootloader_timings) {
1035 total_time += timing.second;
1036 boot_event_store->AddBootEventWithValue("boottime.bootloader." + timing.first, timing.second);
1037 }
1038
James Hawkins6b5c5aa2017-02-16 11:53:03 -08001039 boot_event_store->AddBootEventWithValue("boottime.bootloader.total", total_time);
James Hawkinsbe46fd12017-02-02 16:21:25 -08001040}
1041
Tej Singh4eacd382018-01-25 17:59:57 -08001042// Returns the closest estimation to the absolute device boot time, i.e.,
James Hawkins1bfcaec2017-05-19 14:27:27 -07001043// from power on to boot_complete, including bootloader times.
Tej Singh4eacd382018-01-25 17:59:57 -08001044std::chrono::milliseconds GetAbsoluteBootTime(const BootloaderTimingMap& bootloader_timings,
1045 std::chrono::milliseconds uptime) {
James Hawkins1bfcaec2017-05-19 14:27:27 -07001046 int32_t bootloader_time_ms = 0;
1047
1048 for (const auto& timing : bootloader_timings) {
1049 if (timing.first.compare("SW") != 0) {
1050 bootloader_time_ms += timing.second;
1051 }
1052 }
1053
1054 auto bootloader_duration = std::chrono::milliseconds(bootloader_time_ms);
Tej Singh4eacd382018-01-25 17:59:57 -08001055 return bootloader_duration + uptime;
1056}
1057
1058// Records the closest estimation to the absolute device boot time in seconds.
1059// i.e. from power on to boot_complete, including bootloader times.
1060void RecordAbsoluteBootTime(BootEventRecordStore* boot_event_store,
1061 std::chrono::milliseconds absolute_total) {
1062 auto absolute_total_sec = std::chrono::duration_cast<std::chrono::seconds>(absolute_total);
1063 boot_event_store->AddBootEventWithValue("absolute_boot_time", absolute_total_sec.count());
1064}
1065
1066// Logs the total boot time and reason to statsd.
1067void LogBootInfoToStatsd(std::chrono::milliseconds end_time,
1068 std::chrono::milliseconds total_duration, int32_t bootloader_duration_ms,
1069 double time_since_last_boot_sec) {
Mark Salyzyn88d308d2019-02-08 10:53:18 -08001070 const auto reason = android::base::GetProperty(bootloader_reboot_reason_property, "");
Tej Singh4eacd382018-01-25 17:59:57 -08001071
1072 if (reason.empty()) {
1073 android::util::stats_write(android::util::BOOT_SEQUENCE_REPORTED, "<EMPTY>", "<EMPTY>",
1074 end_time.count(), total_duration.count(),
1075 (int64_t)bootloader_duration_ms,
1076 (int64_t)time_since_last_boot_sec * 1000);
1077 return;
1078 }
1079
Mark Salyzyn88d308d2019-02-08 10:53:18 -08001080 const auto system_reason = android::base::GetProperty(system_reboot_reason_property, "");
Tej Singh4eacd382018-01-25 17:59:57 -08001081 android::util::stats_write(android::util::BOOT_SEQUENCE_REPORTED, reason.c_str(),
1082 system_reason.c_str(), end_time.count(), total_duration.count(),
1083 (int64_t)bootloader_duration_ms,
1084 (int64_t)time_since_last_boot_sec * 1000);
James Hawkins1bfcaec2017-05-19 14:27:27 -07001085}
1086
Tej Singhfe3e7622018-02-06 15:57:38 -08001087void SetSystemBootReason() {
Mark Salyzyn88d308d2019-02-08 10:53:18 -08001088 const auto bootloader_boot_reason =
1089 android::base::GetProperty(bootloader_reboot_reason_property, "");
Tej Singhfe3e7622018-02-06 15:57:38 -08001090 const std::string system_boot_reason(BootReasonStrToReason(bootloader_boot_reason));
1091 // Record the scrubbed system_boot_reason to the property
Mark Salyzyn5c58c9d2018-06-28 09:21:55 -07001092 BootReasonAddToHistory(system_boot_reason);
Mark Salyzynadc433d2018-06-05 08:17:35 -07001093 // Shift last_reboot_reason_property to last_last_reboot_reason_property
Mark Salyzyn88d308d2019-02-08 10:53:18 -08001094 auto last_boot_reason = android::base::GetProperty(last_reboot_reason_property, "");
Mark Salyzynadc433d2018-06-05 08:17:35 -07001095 if (last_boot_reason.empty() || isKernelRebootReason(system_boot_reason)) {
1096 last_boot_reason = system_boot_reason;
1097 } else {
1098 transformReason(last_boot_reason);
1099 }
Mark Salyzyn88d308d2019-02-08 10:53:18 -08001100 android::base::SetProperty(last_last_reboot_reason_property, last_boot_reason);
1101 android::base::SetProperty(last_reboot_reason_property, "");
Tej Singhfe3e7622018-02-06 15:57:38 -08001102}
1103
Luis Hector Chavez583d34c2018-04-12 15:25:15 -07001104// Gets the boot time offset. This is useful when Android is running in a
1105// container, because the boot_clock is not reset when Android reboots.
1106std::chrono::nanoseconds GetBootTimeOffset() {
1107 static const int64_t boottime_offset =
1108 android::base::GetIntProperty<int64_t>("ro.boot.boottime_offset", 0);
1109 return std::chrono::nanoseconds(boottime_offset);
1110}
1111
1112// Returns the current uptime, accounting for any offset in the CLOCK_BOOTTIME
1113// clock.
1114android::base::boot_clock::duration GetUptime() {
1115 return android::base::boot_clock::now().time_since_epoch() - GetBootTimeOffset();
1116}
1117
James Hawkinsc08e9962016-03-11 14:59:50 -08001118// Records several metrics related to the time it takes to boot the device,
1119// including disambiguating boot time on encrypted or non-encrypted devices.
1120void RecordBootComplete() {
1121 BootEventRecordStore boot_event_store;
James Hawkinsb9cf7712016-04-08 15:32:19 -07001122 BootEventRecordStore::BootEventRecord record;
James Hawkins2d8b3e62016-04-14 14:13:20 -07001123
Luis Hector Chavez583d34c2018-04-12 15:25:15 -07001124 auto uptime_ns = GetUptime();
1125 auto uptime_s = std::chrono::duration_cast<std::chrono::seconds>(uptime_ns);
James Hawkins2d8b3e62016-04-14 14:13:20 -07001126 time_t current_time_utc = time(nullptr);
Tej Singh4eacd382018-01-25 17:59:57 -08001127 time_t time_since_last_boot = 0;
James Hawkins2d8b3e62016-04-14 14:13:20 -07001128
1129 if (boot_event_store.GetBootEvent("last_boot_time_utc", &record)) {
1130 time_t last_boot_time_utc = record.second;
Tej Singh4eacd382018-01-25 17:59:57 -08001131 time_since_last_boot = difftime(current_time_utc, last_boot_time_utc);
Mark Salyzyn14b1e6d2017-09-18 10:41:14 -07001132 boot_event_store.AddBootEventWithValue("time_since_last_boot", time_since_last_boot);
James Hawkins2d8b3e62016-04-14 14:13:20 -07001133 }
1134
1135 boot_event_store.AddBootEventWithValue("last_boot_time_utc", current_time_utc);
James Hawkinsc08e9962016-03-11 14:59:50 -08001136
James Hawkinsb9cf7712016-04-08 15:32:19 -07001137 // The boot_complete metric has two variants: boot_complete and
1138 // ota_boot_complete. The latter signifies that the device is booting after
1139 // a system update.
1140 std::string boot_complete_prefix = CalculateBootCompletePrefix();
James Hawkins4dded612016-07-28 11:50:23 -07001141 if (boot_complete_prefix.empty()) {
1142 // The system is hosed because the build date property could not be read.
1143 return;
1144 }
James Hawkinsc08e9962016-03-11 14:59:50 -08001145
1146 // post_decrypt_time_elapsed is only logged on encrypted devices.
1147 if (boot_event_store.GetBootEvent("post_decrypt_time_elapsed", &record)) {
1148 // Log the amount of time elapsed until the device is decrypted, which
1149 // includes the variable amount of time the user takes to enter the
1150 // decryption password.
Luis Hector Chavez583d34c2018-04-12 15:25:15 -07001151 boot_event_store.AddBootEventWithValue("boot_decryption_complete", uptime_s.count());
James Hawkinsc08e9962016-03-11 14:59:50 -08001152
1153 // Subtract the decryption time to normalize the boot cycle timing.
Luis Hector Chavez583d34c2018-04-12 15:25:15 -07001154 std::chrono::seconds boot_complete = std::chrono::seconds(uptime_s.count() - record.second);
James Hawkinsb9cf7712016-04-08 15:32:19 -07001155 boot_event_store.AddBootEventWithValue(boot_complete_prefix + "_post_decrypt",
James Hawkinse78ea772017-03-24 11:43:02 -07001156 boot_complete.count());
James Hawkinsc08e9962016-03-11 14:59:50 -08001157 } else {
Luis Hector Chavez583d34c2018-04-12 15:25:15 -07001158 boot_event_store.AddBootEventWithValue(boot_complete_prefix + "_no_encryption",
1159 uptime_s.count());
James Hawkinsc08e9962016-03-11 14:59:50 -08001160 }
1161
1162 // Record the total time from device startup to boot complete, regardless of
1163 // encryption state.
Luis Hector Chavez583d34c2018-04-12 15:25:15 -07001164 boot_event_store.AddBootEventWithValue(boot_complete_prefix, uptime_s.count());
James Hawkinsef0a0902017-01-06 14:38:23 -08001165
1166 RecordInitBootTimeProp(&boot_event_store, "ro.boottime.init");
1167 RecordInitBootTimeProp(&boot_event_store, "ro.boottime.init.selinux");
1168 RecordInitBootTimeProp(&boot_event_store, "ro.boottime.init.cold_boot_wait");
James Hawkinsbe46fd12017-02-02 16:21:25 -08001169
James Hawkins1bfcaec2017-05-19 14:27:27 -07001170 const BootloaderTimingMap bootloader_timings = GetBootLoaderTimings();
Tej Singh4eacd382018-01-25 17:59:57 -08001171 int32_t bootloader_boot_duration = GetBootloaderTime(bootloader_timings);
James Hawkins1bfcaec2017-05-19 14:27:27 -07001172 RecordBootloaderTimings(&boot_event_store, bootloader_timings);
1173
Luis Hector Chavez583d34c2018-04-12 15:25:15 -07001174 auto uptime_ms = std::chrono::duration_cast<std::chrono::milliseconds>(uptime_ns);
Tej Singh4eacd382018-01-25 17:59:57 -08001175 auto absolute_boot_time = GetAbsoluteBootTime(bootloader_timings, uptime_ms);
1176 RecordAbsoluteBootTime(&boot_event_store, absolute_boot_time);
1177
1178 auto boot_end_time_point = std::chrono::system_clock::now().time_since_epoch();
1179 auto boot_end_time = std::chrono::duration_cast<std::chrono::milliseconds>(boot_end_time_point);
1180
1181 LogBootInfoToStatsd(boot_end_time, absolute_boot_time, bootloader_boot_duration,
1182 time_since_last_boot);
James Hawkinsc08e9962016-03-11 14:59:50 -08001183}
1184
James Hawkinsa4a1a4a2016-02-09 15:32:38 -08001185// Records the boot_reason metric by querying the ro.boot.bootreason system
1186// property.
1187void RecordBootReason() {
Mark Salyzyn88d308d2019-02-08 10:53:18 -08001188 const auto reason = android::base::GetProperty(bootloader_reboot_reason_property, "");
James Hawkins25f71222017-10-10 16:37:05 -07001189
1190 if (reason.empty()) {
1191 // Log an empty boot reason value as '<EMPTY>' to ensure the value is intentional
1192 // (and not corruption anywhere else in the reporting pipeline).
1193 android::metricslogger::LogMultiAction(android::metricslogger::ACTION_BOOT,
1194 android::metricslogger::FIELD_PLATFORM_REASON, "<EMPTY>");
1195 } else {
1196 android::metricslogger::LogMultiAction(android::metricslogger::ACTION_BOOT,
1197 android::metricslogger::FIELD_PLATFORM_REASON, reason);
1198 }
Mark Salyzynb304f6d2017-08-04 13:35:51 -07001199
1200 // Log the raw bootloader_boot_reason property value.
1201 int32_t boot_reason = BootReasonStrToEnum(reason);
James Hawkinsa4a1a4a2016-02-09 15:32:38 -08001202 BootEventRecordStore boot_event_store;
1203 boot_event_store.AddBootEventWithValue("boot_reason", boot_reason);
Mark Salyzynb304f6d2017-08-04 13:35:51 -07001204
1205 // Log the scrubbed system_boot_reason.
Mark Salyzyn88d308d2019-02-08 10:53:18 -08001206 const auto system_reason = android::base::GetProperty(system_reboot_reason_property, "");
Mark Salyzynb304f6d2017-08-04 13:35:51 -07001207 int32_t system_boot_reason = BootReasonStrToEnum(system_reason);
1208 boot_event_store.AddBootEventWithValue("system_boot_reason", system_boot_reason);
1209
Mark Salyzynb304f6d2017-08-04 13:35:51 -07001210 if (reason == "") {
Mark Salyzyn88d308d2019-02-08 10:53:18 -08001211 android::base::SetProperty(bootloader_reboot_reason_property, system_reason);
Mark Salyzynb304f6d2017-08-04 13:35:51 -07001212 }
James Hawkinsa4a1a4a2016-02-09 15:32:38 -08001213}
1214
James Hawkins500d7152016-02-16 15:05:54 -08001215// Records two metrics related to the user resetting a device: the time at
1216// which the device is reset, and the time since the user last reset the
1217// device. The former is only set once per-factory reset.
1218void RecordFactoryReset() {
1219 BootEventRecordStore boot_event_store;
1220 BootEventRecordStore::BootEventRecord record;
1221
1222 time_t current_time_utc = time(nullptr);
1223
James Hawkins0660b302016-03-08 16:18:15 -08001224 if (current_time_utc < 0) {
1225 // UMA does not display negative values in buckets, so convert to positive.
Mark Salyzyn14b1e6d2017-09-18 10:41:14 -07001226 android::metricslogger::LogHistogram("factory_reset_current_time_failure",
1227 std::abs(current_time_utc));
James Hawkinsfff95ba2016-03-29 16:13:49 -07001228
James Hawkins9aec9262017-01-31 11:42:24 -08001229 // Logging via BootEventRecordStore to see if using android::metricslogger::LogHistogram
James Hawkinsfff95ba2016-03-29 16:13:49 -07001230 // is losing records somehow.
Mark Salyzyn14b1e6d2017-09-18 10:41:14 -07001231 boot_event_store.AddBootEventWithValue("factory_reset_current_time_failure",
1232 std::abs(current_time_utc));
James Hawkins0660b302016-03-08 16:18:15 -08001233 return;
1234 } else {
James Hawkins9aec9262017-01-31 11:42:24 -08001235 android::metricslogger::LogHistogram("factory_reset_current_time", current_time_utc);
James Hawkinsfff95ba2016-03-29 16:13:49 -07001236
James Hawkins9aec9262017-01-31 11:42:24 -08001237 // Logging via BootEventRecordStore to see if using android::metricslogger::LogHistogram
James Hawkinsfff95ba2016-03-29 16:13:49 -07001238 // is losing records somehow.
Mark Salyzyn14b1e6d2017-09-18 10:41:14 -07001239 boot_event_store.AddBootEventWithValue("factory_reset_current_time", current_time_utc);
James Hawkins0660b302016-03-08 16:18:15 -08001240 }
1241
James Hawkins500d7152016-02-16 15:05:54 -08001242 // The factory_reset boot event does not exist after the device is reset, so
1243 // use this signal to mark the time of the factory reset.
1244 if (!boot_event_store.GetBootEvent("factory_reset", &record)) {
1245 boot_event_store.AddBootEventWithValue("factory_reset", current_time_utc);
James Hawkins3bf9b142016-03-03 14:50:24 -08001246
1247 // Don't log the time_since_factory_reset until some time has elapsed.
1248 // The data is not meaningful yet and skews the histogram buckets.
James Hawkins500d7152016-02-16 15:05:54 -08001249 return;
1250 }
1251
1252 // Calculate and record the difference in time between now and the
1253 // factory_reset time.
1254 time_t factory_reset_utc = record.second;
James Hawkins9aec9262017-01-31 11:42:24 -08001255 android::metricslogger::LogHistogram("factory_reset_record_value", factory_reset_utc);
James Hawkinsfff95ba2016-03-29 16:13:49 -07001256
James Hawkins9aec9262017-01-31 11:42:24 -08001257 // Logging via BootEventRecordStore to see if using android::metricslogger::LogHistogram
James Hawkinsfff95ba2016-03-29 16:13:49 -07001258 // is losing records somehow.
Mark Salyzyn14b1e6d2017-09-18 10:41:14 -07001259 boot_event_store.AddBootEventWithValue("factory_reset_record_value", factory_reset_utc);
James Hawkinsfff95ba2016-03-29 16:13:49 -07001260
Mark Salyzyn14b1e6d2017-09-18 10:41:14 -07001261 time_t time_since_factory_reset = difftime(current_time_utc, factory_reset_utc);
1262 boot_event_store.AddBootEventWithValue("time_since_factory_reset", time_since_factory_reset);
James Hawkins500d7152016-02-16 15:05:54 -08001263}
1264
James Hawkinsabd73e62016-01-19 15:10:38 -08001265} // namespace
1266
Mark Salyzyn14b1e6d2017-09-18 10:41:14 -07001267int main(int argc, char** argv) {
James Hawkinsabd73e62016-01-19 15:10:38 -08001268 android::base::InitLogging(argv);
1269
1270 const std::string cmd_line = GetCommandLine(argc, argv);
1271 LOG(INFO) << "Service started: " << cmd_line;
1272
James Hawkinsa4a1a4a2016-02-09 15:32:38 -08001273 int option_index = 0;
James Hawkinsc6275582016-03-22 10:47:44 -07001274 static const char value_str[] = "value";
Tej Singhfe3e7622018-02-06 15:57:38 -08001275 static const char system_boot_reason_str[] = "set_system_boot_reason";
James Hawkinsc08e9962016-03-11 14:59:50 -08001276 static const char boot_complete_str[] = "record_boot_complete";
James Hawkinsa4a1a4a2016-02-09 15:32:38 -08001277 static const char boot_reason_str[] = "record_boot_reason";
James Hawkins53684ea2016-02-23 16:18:19 -08001278 static const char factory_reset_str[] = "record_time_since_factory_reset";
James Hawkinsa4a1a4a2016-02-09 15:32:38 -08001279 static const struct option long_options[] = {
Mark Salyzyn14b1e6d2017-09-18 10:41:14 -07001280 // clang-format off
Tej Singhfe3e7622018-02-06 15:57:38 -08001281 { "help", no_argument, NULL, 'h' },
1282 { "log", no_argument, NULL, 'l' },
1283 { "print", no_argument, NULL, 'p' },
1284 { "record", required_argument, NULL, 'r' },
1285 { value_str, required_argument, NULL, 0 },
1286 { system_boot_reason_str, no_argument, NULL, 0 },
1287 { boot_complete_str, no_argument, NULL, 0 },
1288 { boot_reason_str, no_argument, NULL, 0 },
1289 { factory_reset_str, no_argument, NULL, 0 },
1290 { NULL, 0, NULL, 0 }
Mark Salyzyn14b1e6d2017-09-18 10:41:14 -07001291 // clang-format on
James Hawkinsa4a1a4a2016-02-09 15:32:38 -08001292 };
1293
James Hawkinsc6275582016-03-22 10:47:44 -07001294 std::string boot_event;
1295 std::string value;
James Hawkinsabd73e62016-01-19 15:10:38 -08001296 int opt = 0;
James Hawkinsa4a1a4a2016-02-09 15:32:38 -08001297 while ((opt = getopt_long(argc, argv, "hlpr:", long_options, &option_index)) != -1) {
James Hawkinsabd73e62016-01-19 15:10:38 -08001298 switch (opt) {
James Hawkinsa4a1a4a2016-02-09 15:32:38 -08001299 // This case handles long options which have no single-character mapping.
1300 case 0: {
1301 const std::string option_name = long_options[option_index].name;
James Hawkinsc6275582016-03-22 10:47:44 -07001302 if (option_name == value_str) {
1303 // |optarg| is an external variable set by getopt representing
1304 // the option argument.
1305 value = optarg;
Tej Singhfe3e7622018-02-06 15:57:38 -08001306 } else if (option_name == system_boot_reason_str) {
1307 SetSystemBootReason();
James Hawkinsc6275582016-03-22 10:47:44 -07001308 } else if (option_name == boot_complete_str) {
James Hawkinsc08e9962016-03-11 14:59:50 -08001309 RecordBootComplete();
1310 } else if (option_name == boot_reason_str) {
James Hawkinsa4a1a4a2016-02-09 15:32:38 -08001311 RecordBootReason();
James Hawkins500d7152016-02-16 15:05:54 -08001312 } else if (option_name == factory_reset_str) {
1313 RecordFactoryReset();
James Hawkinsa4a1a4a2016-02-09 15:32:38 -08001314 } else {
1315 LOG(ERROR) << "Invalid option: " << option_name;
1316 }
1317 break;
1318 }
1319
James Hawkinsabd73e62016-01-19 15:10:38 -08001320 case 'h': {
1321 ShowHelp(argv[0]);
1322 break;
1323 }
1324
1325 case 'l': {
1326 LogBootEvents();
1327 break;
1328 }
1329
1330 case 'p': {
1331 PrintBootEvents();
1332 break;
1333 }
1334
1335 case 'r': {
1336 // |optarg| is an external variable set by getopt representing
1337 // the option argument.
James Hawkinsc6275582016-03-22 10:47:44 -07001338 boot_event = optarg;
James Hawkinsabd73e62016-01-19 15:10:38 -08001339 break;
1340 }
1341
1342 default: {
1343 DCHECK_EQ(opt, '?');
1344
1345 // |optopt| is an external variable set by getopt representing
1346 // the value of the invalid option.
1347 LOG(ERROR) << "Invalid option: " << optopt;
1348 ShowHelp(argv[0]);
1349 return EXIT_FAILURE;
1350 }
1351 }
1352 }
1353
James Hawkinsc6275582016-03-22 10:47:44 -07001354 if (!boot_event.empty()) {
1355 RecordBootEventFromCommandLine(boot_event, value);
1356 }
1357
James Hawkinsabd73e62016-01-19 15:10:38 -08001358 return 0;
1359}