1/* 2 * Copyright (C) 2016 The Android Open Source Project 3 * 4 * Licensed under the Apache License, Version 2.0 (the "License"); 5 * you may not use this file except in compliance with the License. 6 * You may obtain a copy of the License at 7 * 8 * http://www.apache.org/licenses/LICENSE-2.0 9 * 10 * Unless required by applicable law or agreed to in writing, software 11 * distributed under the License is distributed on an "AS IS" BASIS, 12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. 13 * See the License for the specific language governing permissions and 14 * limitations under the License. 15 */ 16 17// The bootstat command provides options to persist boot events with the current 18// timestamp, dump the persisted events, and log all events to EventLog to be 19// uploaded to Android log storage via Tron. 20 21#include <getopt.h> 22#include <unistd.h> 23#include <cmath> 24#include <cstddef> 25#include <cstdio> 26#include <ctime> 27#include <map> 28#include <memory> 29#include <string> 30#include <android-base/logging.h> 31#include <cutils/properties.h> 32#include <log/log.h> 33#include "boot_event_record_store.h" 34#include "event_log_list_builder.h" 35#include "histogram_logger.h" 36#include "uptime_parser.h" 37 38namespace { 39 40// Scans the boot event record store for record files and logs each boot event 41// via EventLog. 42void LogBootEvents() { 43 BootEventRecordStore boot_event_store; 44 45 auto events = boot_event_store.GetAllBootEvents(); 46 for (auto i = events.cbegin(); i != events.cend(); ++i) { 47 bootstat::LogHistogram(i->first, i->second); 48 } 49} 50 51void PrintBootEvents() { 52 printf("Boot events:\n"); 53 printf("------------\n"); 54 55 BootEventRecordStore boot_event_store; 56 auto events = boot_event_store.GetAllBootEvents(); 57 for (auto i = events.cbegin(); i != events.cend(); ++i) { 58 printf("%s\t%d\n", i->first.c_str(), i->second); 59 } 60} 61 62void ShowHelp(const char *cmd) { 63 fprintf(stderr, "Usage: %s [options]\n", cmd); 64 fprintf(stderr, 65 "options include:\n" 66 " -h, --help Show this help\n" 67 " -l, --log Log all metrics to logstorage\n" 68 " -p, --print Dump the boot event records to the console\n" 69 " -r, --record Record the timestamp of a named boot event\n" 70 " --record_boot_reason Record the reason why the device booted\n" 71 " --record_time_since_factory_reset Record the time since the device was reset\n"); 72} 73 74// Constructs a readable, printable string from the givencommand line 75// arguments. 76std::string GetCommandLine(int argc, char **argv) { 77 std::string cmd; 78 for (int i = 0; i < argc; ++i) { 79 cmd += argv[i]; 80 cmd += " "; 81 } 82 83 return cmd; 84} 85 86// Convenience wrapper over the property API that returns an 87// std::string. 88std::string GetProperty(const char* key) { 89 std::vector<char> temp(PROPERTY_VALUE_MAX); 90 const int len = property_get(key, &temp[0], nullptr); 91 if (len < 0) { 92 return ""; 93 } 94 return std::string(&temp[0], len); 95} 96 97constexpr int32_t kUnknownBootReason = 1; 98 99// A mapping from boot reason string, as read from the ro.boot.bootreason 100// system property, to a unique integer ID. Viewers of log data dashboards for 101// the boot_reason metric may refer to this mapping to discern the histogram 102// values. 103const std::map<std::string, int32_t> kBootReasonMap = { 104 {"unknown", kUnknownBootReason}, 105 {"normal", 2}, 106 {"recovery", 3}, 107 {"reboot", 4}, 108 {"PowerKey", 5}, 109 {"hard_reset", 6}, 110 {"kernel_panic", 7}, 111 {"rpm_err", 8}, 112 {"hw_reset", 9}, 113 {"tz_err", 10}, 114 {"adsp_err", 11}, 115 {"modem_err", 12}, 116 {"mba_err", 13}, 117 {"Watchdog", 14}, 118 {"Panic", 15}, 119 {"power_key", 16}, 120 {"power_on", 17}, 121 {"Reboot", 18}, 122 {"rtc", 19}, 123 {"edl", 20}, 124}; 125 126// Converts a string value representing the reason the system booted to an 127// integer representation. This is necessary for logging the boot_reason metric 128// via Tron, which does not accept non-integer buckets in histograms. 129int32_t BootReasonStrToEnum(const std::string& boot_reason) { 130 auto mapping = kBootReasonMap.find(boot_reason); 131 if (mapping != kBootReasonMap.end()) { 132 return mapping->second; 133 } 134 135 LOG(INFO) << "Unknown boot reason: " << boot_reason; 136 return kUnknownBootReason; 137} 138 139// Returns the appropriate metric key prefix for the boot_complete metric such 140// that boot metrics after a system update are labeled as ota_boot_complete; 141// otherwise, they are labeled as boot_complete. This method encapsulates the 142// bookkeeping required to track when a system update has occurred by storing 143// the UTC timestamp of the system build date and comparing against the current 144// system build date. 145std::string CalculateBootCompletePrefix() { 146 static const std::string kBuildDateKey = "build_date"; 147 std::string boot_complete_prefix = "boot_complete"; 148 149 std::string build_date_str = GetProperty("ro.build.date.utc"); 150 int32_t build_date = std::stoi(build_date_str); 151 152 BootEventRecordStore boot_event_store; 153 BootEventRecordStore::BootEventRecord record; 154 if (!boot_event_store.GetBootEvent(kBuildDateKey, &record) || 155 build_date != record.second) { 156 boot_complete_prefix = "ota_" + boot_complete_prefix; 157 boot_event_store.AddBootEventWithValue(kBuildDateKey, build_date); 158 } 159 160 return boot_complete_prefix; 161} 162 163// Records several metrics related to the time it takes to boot the device, 164// including disambiguating boot time on encrypted or non-encrypted devices. 165void RecordBootComplete() { 166 BootEventRecordStore boot_event_store; 167 BootEventRecordStore::BootEventRecord record; 168 time_t uptime = bootstat::ParseUptime(); 169 170 // The boot_complete metric has two variants: boot_complete and 171 // ota_boot_complete. The latter signifies that the device is booting after 172 // a system update. 173 std::string boot_complete_prefix = CalculateBootCompletePrefix(); 174 175 // post_decrypt_time_elapsed is only logged on encrypted devices. 176 if (boot_event_store.GetBootEvent("post_decrypt_time_elapsed", &record)) { 177 // Log the amount of time elapsed until the device is decrypted, which 178 // includes the variable amount of time the user takes to enter the 179 // decryption password. 180 boot_event_store.AddBootEventWithValue("boot_decryption_complete", uptime); 181 182 // Subtract the decryption time to normalize the boot cycle timing. 183 time_t boot_complete = uptime - record.second; 184 boot_event_store.AddBootEventWithValue(boot_complete_prefix + "_post_decrypt", 185 boot_complete); 186 187 188 } else { 189 boot_event_store.AddBootEventWithValue(boot_complete_prefix + "_no_encryption", 190 uptime); 191 } 192 193 // Record the total time from device startup to boot complete, regardless of 194 // encryption state. 195 boot_event_store.AddBootEventWithValue(boot_complete_prefix, uptime); 196} 197 198// Records the boot_reason metric by querying the ro.boot.bootreason system 199// property. 200void RecordBootReason() { 201 int32_t boot_reason = BootReasonStrToEnum(GetProperty("ro.boot.bootreason")); 202 BootEventRecordStore boot_event_store; 203 boot_event_store.AddBootEventWithValue("boot_reason", boot_reason); 204} 205 206// Records two metrics related to the user resetting a device: the time at 207// which the device is reset, and the time since the user last reset the 208// device. The former is only set once per-factory reset. 209void RecordFactoryReset() { 210 BootEventRecordStore boot_event_store; 211 BootEventRecordStore::BootEventRecord record; 212 213 time_t current_time_utc = time(nullptr); 214 215 if (current_time_utc < 0) { 216 // UMA does not display negative values in buckets, so convert to positive. 217 bootstat::LogHistogram( 218 "factory_reset_current_time_failure", std::abs(current_time_utc)); 219 220 // Logging via BootEventRecordStore to see if using bootstat::LogHistogram 221 // is losing records somehow. 222 boot_event_store.AddBootEventWithValue( 223 "factory_reset_current_time_failure", std::abs(current_time_utc)); 224 return; 225 } else { 226 bootstat::LogHistogram("factory_reset_current_time", current_time_utc); 227 228 // Logging via BootEventRecordStore to see if using bootstat::LogHistogram 229 // is losing records somehow. 230 boot_event_store.AddBootEventWithValue( 231 "factory_reset_current_time", current_time_utc); 232 } 233 234 // The factory_reset boot event does not exist after the device is reset, so 235 // use this signal to mark the time of the factory reset. 236 if (!boot_event_store.GetBootEvent("factory_reset", &record)) { 237 boot_event_store.AddBootEventWithValue("factory_reset", current_time_utc); 238 239 // Don't log the time_since_factory_reset until some time has elapsed. 240 // The data is not meaningful yet and skews the histogram buckets. 241 return; 242 } 243 244 // Calculate and record the difference in time between now and the 245 // factory_reset time. 246 time_t factory_reset_utc = record.second; 247 bootstat::LogHistogram("factory_reset_record_value", factory_reset_utc); 248 249 // Logging via BootEventRecordStore to see if using bootstat::LogHistogram 250 // is losing records somehow. 251 boot_event_store.AddBootEventWithValue( 252 "factory_reset_record_value", factory_reset_utc); 253 254 time_t time_since_factory_reset = difftime(current_time_utc, 255 factory_reset_utc); 256 boot_event_store.AddBootEventWithValue("time_since_factory_reset", 257 time_since_factory_reset); 258} 259 260} // namespace 261 262int main(int argc, char **argv) { 263 android::base::InitLogging(argv); 264 265 const std::string cmd_line = GetCommandLine(argc, argv); 266 LOG(INFO) << "Service started: " << cmd_line; 267 268 int option_index = 0; 269 static const char boot_complete_str[] = "record_boot_complete"; 270 static const char boot_reason_str[] = "record_boot_reason"; 271 static const char factory_reset_str[] = "record_time_since_factory_reset"; 272 static const struct option long_options[] = { 273 { "help", no_argument, NULL, 'h' }, 274 { "log", no_argument, NULL, 'l' }, 275 { "print", no_argument, NULL, 'p' }, 276 { "record", required_argument, NULL, 'r' }, 277 { boot_complete_str, no_argument, NULL, 0 }, 278 { boot_reason_str, no_argument, NULL, 0 }, 279 { factory_reset_str, no_argument, NULL, 0 }, 280 { NULL, 0, NULL, 0 } 281 }; 282 283 int opt = 0; 284 while ((opt = getopt_long(argc, argv, "hlpr:", long_options, &option_index)) != -1) { 285 switch (opt) { 286 // This case handles long options which have no single-character mapping. 287 case 0: { 288 const std::string option_name = long_options[option_index].name; 289 if (option_name == boot_complete_str) { 290 RecordBootComplete(); 291 } else if (option_name == boot_reason_str) { 292 RecordBootReason(); 293 } else if (option_name == factory_reset_str) { 294 RecordFactoryReset(); 295 } else { 296 LOG(ERROR) << "Invalid option: " << option_name; 297 } 298 break; 299 } 300 301 case 'h': { 302 ShowHelp(argv[0]); 303 break; 304 } 305 306 case 'l': { 307 LogBootEvents(); 308 break; 309 } 310 311 case 'p': { 312 PrintBootEvents(); 313 break; 314 } 315 316 case 'r': { 317 // |optarg| is an external variable set by getopt representing 318 // the option argument. 319 const char* event = optarg; 320 321 BootEventRecordStore boot_event_store; 322 boot_event_store.AddBootEvent(event); 323 break; 324 } 325 326 default: { 327 DCHECK_EQ(opt, '?'); 328 329 // |optopt| is an external variable set by getopt representing 330 // the value of the invalid option. 331 LOG(ERROR) << "Invalid option: " << optopt; 332 ShowHelp(argv[0]); 333 return EXIT_FAILURE; 334 } 335 } 336 } 337 338 return 0; 339} 340