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