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