1 /* 2 * Copyright (C) 2009 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 package com.android.server; 18 19 import android.content.BroadcastReceiver; 20 import android.content.Context; 21 import android.content.Intent; 22 import android.content.pm.IPackageManager; 23 import android.os.Build; 24 import android.os.DropBoxManager; 25 import android.os.Environment; 26 import android.os.FileObserver; 27 import android.os.FileUtils; 28 import android.os.RecoverySystem; 29 import android.os.RemoteException; 30 import android.os.ServiceManager; 31 import android.os.SystemProperties; 32 import android.os.storage.StorageManager; 33 import android.provider.Downloads; 34 import android.text.TextUtils; 35 import android.util.AtomicFile; 36 import android.util.EventLog; 37 import android.util.Slog; 38 import android.util.StatsLog; 39 import android.util.Xml; 40 41 import com.android.internal.annotations.VisibleForTesting; 42 import com.android.internal.logging.MetricsLogger; 43 import com.android.internal.util.FastXmlSerializer; 44 import com.android.internal.util.XmlUtils; 45 import com.android.server.DropboxLogTags; 46 47 import java.io.File; 48 import java.io.FileInputStream; 49 import java.io.FileOutputStream; 50 import java.io.IOException; 51 import java.io.FileNotFoundException; 52 import java.nio.charset.StandardCharsets; 53 import java.util.HashMap; 54 import java.util.Iterator; 55 import java.util.regex.Matcher; 56 import java.util.regex.Pattern; 57 58 import org.xmlpull.v1.XmlPullParser; 59 import org.xmlpull.v1.XmlPullParserException; 60 import org.xmlpull.v1.XmlSerializer; 61 62 /** 63 * Performs a number of miscellaneous, non-system-critical actions 64 * after the system has finished booting. 65 */ 66 public class BootReceiver extends BroadcastReceiver { 67 private static final String TAG = "BootReceiver"; 68 69 // Maximum size of a logged event (files get truncated if they're longer). 70 // Give userdebug builds a larger max to capture extra debug, esp. for last_kmsg. 71 private static final int LOG_SIZE = 72 SystemProperties.getInt("ro.debuggable", 0) == 1 ? 98304 : 65536; 73 74 private static final File TOMBSTONE_DIR = new File("/data/tombstones"); 75 private static final String TAG_TOMBSTONE = "SYSTEM_TOMBSTONE"; 76 77 // The pre-froyo package and class of the system updater, which 78 // ran in the system process. We need to remove its packages here 79 // in order to clean up after a pre-froyo-to-froyo update. 80 private static final String OLD_UPDATER_PACKAGE = 81 "com.google.android.systemupdater"; 82 private static final String OLD_UPDATER_CLASS = 83 "com.google.android.systemupdater.SystemUpdateReceiver"; 84 85 // Keep a reference to the observer so the finalizer doesn't disable it. 86 private static FileObserver sTombstoneObserver = null; 87 88 private static final String LOG_FILES_FILE = "log-files.xml"; 89 private static final AtomicFile sFile = new AtomicFile(new File( 90 Environment.getDataSystemDirectory(), LOG_FILES_FILE), "log-files"); 91 private static final String LAST_HEADER_FILE = "last-header.txt"; 92 private static final File lastHeaderFile = new File( 93 Environment.getDataSystemDirectory(), LAST_HEADER_FILE); 94 95 // example: fs_stat,/dev/block/platform/soc/by-name/userdata,0x5 96 private static final String FS_STAT_PATTERN = "fs_stat,[^,]*/([^/,]+),(0x[0-9a-fA-F]+)"; 97 private static final int FS_STAT_FS_FIXED = 0x400; // should match with fs_mgr.cpp:FsStatFlags 98 private static final String FSCK_PASS_PATTERN = "Pass ([1-9]E?):"; 99 private static final String FSCK_TREE_OPTIMIZATION_PATTERN = 100 "Inode [0-9]+ extent tree.*could be shorter"; 101 private static final String FSCK_FS_MODIFIED = "FILE SYSTEM WAS MODIFIED"; 102 // ro.boottime.init.mount_all. + postfix for mount_all duration 103 private static final String[] MOUNT_DURATION_PROPS_POSTFIX = 104 new String[] { "early", "default", "late" }; 105 // for reboot, fs shutdown time is recorded in last_kmsg. 106 private static final String[] LAST_KMSG_FILES = 107 new String[] { "/sys/fs/pstore/console-ramoops", "/proc/last_kmsg" }; 108 // first: fs shutdown time in ms, second: umount status defined in init/reboot.h 109 private static final String LAST_SHUTDOWN_TIME_PATTERN = 110 "powerctl_shutdown_time_ms:([0-9]+):([0-9]+)"; 111 private static final int UMOUNT_STATUS_NOT_AVAILABLE = 4; // should match with init/reboot.h 112 113 // Location of file with metrics recorded during shutdown 114 private static final String SHUTDOWN_METRICS_FILE = "/data/system/shutdown-metrics.txt"; 115 116 private static final String SHUTDOWN_TRON_METRICS_PREFIX = "shutdown_"; 117 private static final String METRIC_SYSTEM_SERVER = "shutdown_system_server"; 118 private static final String METRIC_SHUTDOWN_TIME_START = "begin_shutdown"; 119 120 @Override onReceive(final Context context, Intent intent)121 public void onReceive(final Context context, Intent intent) { 122 // Log boot events in the background to avoid blocking the main thread with I/O 123 new Thread() { 124 @Override 125 public void run() { 126 try { 127 logBootEvents(context); 128 } catch (Exception e) { 129 Slog.e(TAG, "Can't log boot events", e); 130 } 131 try { 132 boolean onlyCore = false; 133 try { 134 onlyCore = IPackageManager.Stub.asInterface(ServiceManager.getService( 135 "package")).isOnlyCoreApps(); 136 } catch (RemoteException e) { 137 } 138 if (!onlyCore) { 139 removeOldUpdatePackages(context); 140 } 141 } catch (Exception e) { 142 Slog.e(TAG, "Can't remove old update packages", e); 143 } 144 145 } 146 }.start(); 147 } 148 removeOldUpdatePackages(Context context)149 private void removeOldUpdatePackages(Context context) { 150 Downloads.removeAllDownloadsByPackage(context, OLD_UPDATER_PACKAGE, OLD_UPDATER_CLASS); 151 } 152 getPreviousBootHeaders()153 private String getPreviousBootHeaders() { 154 try { 155 return FileUtils.readTextFile(lastHeaderFile, 0, null); 156 } catch (IOException e) { 157 return null; 158 } 159 } 160 getCurrentBootHeaders()161 private String getCurrentBootHeaders() throws IOException { 162 return new StringBuilder(512) 163 .append("Build: ").append(Build.FINGERPRINT).append("\n") 164 .append("Hardware: ").append(Build.BOARD).append("\n") 165 .append("Revision: ") 166 .append(SystemProperties.get("ro.revision", "")).append("\n") 167 .append("Bootloader: ").append(Build.BOOTLOADER).append("\n") 168 .append("Radio: ").append(Build.getRadioVersion()).append("\n") 169 .append("Kernel: ") 170 .append(FileUtils.readTextFile(new File("/proc/version"), 1024, "...\n")) 171 .append("\n").toString(); 172 } 173 174 getBootHeadersToLogAndUpdate()175 private String getBootHeadersToLogAndUpdate() throws IOException { 176 final String oldHeaders = getPreviousBootHeaders(); 177 final String newHeaders = getCurrentBootHeaders(); 178 179 try { 180 FileUtils.stringToFile(lastHeaderFile, newHeaders); 181 } catch (IOException e) { 182 Slog.e(TAG, "Error writing " + lastHeaderFile, e); 183 } 184 185 if (oldHeaders == null) { 186 // If we failed to read the old headers, use the current headers 187 // but note this in the headers so we know 188 return "isPrevious: false\n" + newHeaders; 189 } 190 191 return "isPrevious: true\n" + oldHeaders; 192 } 193 logBootEvents(Context ctx)194 private void logBootEvents(Context ctx) throws IOException { 195 final DropBoxManager db = (DropBoxManager) ctx.getSystemService(Context.DROPBOX_SERVICE); 196 final String headers = getBootHeadersToLogAndUpdate(); 197 final String bootReason = SystemProperties.get("ro.boot.bootreason", null); 198 199 String recovery = RecoverySystem.handleAftermath(ctx); 200 if (recovery != null && db != null) { 201 db.addText("SYSTEM_RECOVERY_LOG", headers + recovery); 202 } 203 204 String lastKmsgFooter = ""; 205 if (bootReason != null) { 206 lastKmsgFooter = new StringBuilder(512) 207 .append("\n") 208 .append("Boot info:\n") 209 .append("Last boot reason: ").append(bootReason).append("\n") 210 .toString(); 211 } 212 213 HashMap<String, Long> timestamps = readTimestamps(); 214 215 if (SystemProperties.getLong("ro.runtime.firstboot", 0) == 0) { 216 if (StorageManager.inCryptKeeperBounce()) { 217 // Encrypted, first boot to get PIN/pattern/password so data is tmpfs 218 // Don't set ro.runtime.firstboot so that we will do this again 219 // when data is properly mounted 220 } else { 221 String now = Long.toString(System.currentTimeMillis()); 222 SystemProperties.set("ro.runtime.firstboot", now); 223 } 224 if (db != null) db.addText("SYSTEM_BOOT", headers); 225 226 // Negative sizes mean to take the *tail* of the file (see FileUtils.readTextFile()) 227 addFileWithFootersToDropBox(db, timestamps, headers, lastKmsgFooter, 228 "/proc/last_kmsg", -LOG_SIZE, "SYSTEM_LAST_KMSG"); 229 addFileWithFootersToDropBox(db, timestamps, headers, lastKmsgFooter, 230 "/sys/fs/pstore/console-ramoops", -LOG_SIZE, "SYSTEM_LAST_KMSG"); 231 addFileWithFootersToDropBox(db, timestamps, headers, lastKmsgFooter, 232 "/sys/fs/pstore/console-ramoops-0", -LOG_SIZE, "SYSTEM_LAST_KMSG"); 233 addFileToDropBox(db, timestamps, headers, "/cache/recovery/log", -LOG_SIZE, 234 "SYSTEM_RECOVERY_LOG"); 235 addFileToDropBox(db, timestamps, headers, "/cache/recovery/last_kmsg", 236 -LOG_SIZE, "SYSTEM_RECOVERY_KMSG"); 237 addAuditErrorsToDropBox(db, timestamps, headers, -LOG_SIZE, "SYSTEM_AUDIT"); 238 } else { 239 if (db != null) db.addText("SYSTEM_RESTART", headers); 240 } 241 // log always available fs_stat last so that logcat collecting tools can wait until 242 // fs_stat to get all file system metrics. 243 logFsShutdownTime(); 244 logFsMountTime(); 245 addFsckErrorsToDropBoxAndLogFsStat(db, timestamps, headers, -LOG_SIZE, "SYSTEM_FSCK"); 246 logSystemServerShutdownTimeMetrics(); 247 248 // Scan existing tombstones (in case any new ones appeared) 249 File[] tombstoneFiles = TOMBSTONE_DIR.listFiles(); 250 for (int i = 0; tombstoneFiles != null && i < tombstoneFiles.length; i++) { 251 if (tombstoneFiles[i].isFile()) { 252 addFileToDropBox(db, timestamps, headers, tombstoneFiles[i].getPath(), 253 LOG_SIZE, "SYSTEM_TOMBSTONE"); 254 } 255 } 256 257 writeTimestamps(timestamps); 258 259 // Start watching for new tombstone files; will record them as they occur. 260 // This gets registered with the singleton file observer thread. 261 sTombstoneObserver = new FileObserver(TOMBSTONE_DIR.getPath(), FileObserver.CLOSE_WRITE) { 262 @Override 263 public void onEvent(int event, String path) { 264 HashMap<String, Long> timestamps = readTimestamps(); 265 try { 266 File file = new File(TOMBSTONE_DIR, path); 267 if (file.isFile()) { 268 addFileToDropBox(db, timestamps, headers, file.getPath(), LOG_SIZE, 269 TAG_TOMBSTONE); 270 } 271 } catch (IOException e) { 272 Slog.e(TAG, "Can't log tombstone", e); 273 } 274 writeTimestamps(timestamps); 275 } 276 }; 277 278 sTombstoneObserver.startWatching(); 279 } 280 addFileToDropBox( DropBoxManager db, HashMap<String, Long> timestamps, String headers, String filename, int maxSize, String tag)281 private static void addFileToDropBox( 282 DropBoxManager db, HashMap<String, Long> timestamps, 283 String headers, String filename, int maxSize, String tag) throws IOException { 284 addFileWithFootersToDropBox(db, timestamps, headers, "", filename, maxSize, tag); 285 } 286 addFileWithFootersToDropBox( DropBoxManager db, HashMap<String, Long> timestamps, String headers, String footers, String filename, int maxSize, String tag)287 private static void addFileWithFootersToDropBox( 288 DropBoxManager db, HashMap<String, Long> timestamps, 289 String headers, String footers, String filename, int maxSize, 290 String tag) throws IOException { 291 if (db == null || !db.isTagEnabled(tag)) return; // Logging disabled 292 293 File file = new File(filename); 294 long fileTime = file.lastModified(); 295 if (fileTime <= 0) return; // File does not exist 296 297 if (timestamps.containsKey(filename) && timestamps.get(filename) == fileTime) { 298 return; // Already logged this particular file 299 } 300 301 timestamps.put(filename, fileTime); 302 303 304 String fileContents = FileUtils.readTextFile(file, maxSize, "[[TRUNCATED]]\n"); 305 String text = headers + fileContents + footers; 306 // Create an additional report for system server native crashes, with a special tag. 307 if (tag.equals(TAG_TOMBSTONE) && fileContents.contains(">>> system_server <<<")) { 308 addTextToDropBox(db, "system_server_native_crash", text, filename, maxSize); 309 } 310 addTextToDropBox(db, tag, text, filename, maxSize); 311 } 312 addTextToDropBox(DropBoxManager db, String tag, String text, String filename, int maxSize)313 private static void addTextToDropBox(DropBoxManager db, String tag, String text, 314 String filename, int maxSize) { 315 Slog.i(TAG, "Copying " + filename + " to DropBox (" + tag + ")"); 316 db.addText(tag, text); 317 EventLog.writeEvent(DropboxLogTags.DROPBOX_FILE_COPY, filename, maxSize, tag); 318 } 319 addAuditErrorsToDropBox(DropBoxManager db, HashMap<String, Long> timestamps, String headers, int maxSize, String tag)320 private static void addAuditErrorsToDropBox(DropBoxManager db, 321 HashMap<String, Long> timestamps, String headers, int maxSize, String tag) 322 throws IOException { 323 if (db == null || !db.isTagEnabled(tag)) return; // Logging disabled 324 Slog.i(TAG, "Copying audit failures to DropBox"); 325 326 File file = new File("/proc/last_kmsg"); 327 long fileTime = file.lastModified(); 328 if (fileTime <= 0) { 329 file = new File("/sys/fs/pstore/console-ramoops"); 330 fileTime = file.lastModified(); 331 if (fileTime <= 0) { 332 file = new File("/sys/fs/pstore/console-ramoops-0"); 333 fileTime = file.lastModified(); 334 } 335 } 336 337 if (fileTime <= 0) return; // File does not exist 338 339 if (timestamps.containsKey(tag) && timestamps.get(tag) == fileTime) { 340 return; // Already logged this particular file 341 } 342 343 timestamps.put(tag, fileTime); 344 345 String log = FileUtils.readTextFile(file, maxSize, "[[TRUNCATED]]\n"); 346 StringBuilder sb = new StringBuilder(); 347 for (String line : log.split("\n")) { 348 if (line.contains("audit")) { 349 sb.append(line + "\n"); 350 } 351 } 352 Slog.i(TAG, "Copied " + sb.toString().length() + " worth of audits to DropBox"); 353 db.addText(tag, headers + sb.toString()); 354 } 355 addFsckErrorsToDropBoxAndLogFsStat(DropBoxManager db, HashMap<String, Long> timestamps, String headers, int maxSize, String tag)356 private static void addFsckErrorsToDropBoxAndLogFsStat(DropBoxManager db, 357 HashMap<String, Long> timestamps, String headers, int maxSize, String tag) 358 throws IOException { 359 boolean uploadEnabled = true; 360 if (db == null || !db.isTagEnabled(tag)) { 361 uploadEnabled = false; 362 } 363 boolean uploadNeeded = false; 364 Slog.i(TAG, "Checking for fsck errors"); 365 366 File file = new File("/dev/fscklogs/log"); 367 long fileTime = file.lastModified(); 368 if (fileTime <= 0) return; // File does not exist 369 370 String log = FileUtils.readTextFile(file, maxSize, "[[TRUNCATED]]\n"); 371 Pattern pattern = Pattern.compile(FS_STAT_PATTERN); 372 String lines[] = log.split("\n"); 373 int lineNumber = 0; 374 int lastFsStatLineNumber = 0; 375 for (String line : lines) { // should check all lines 376 if (line.contains(FSCK_FS_MODIFIED)) { 377 uploadNeeded = true; 378 } else if (line.contains("fs_stat")){ 379 Matcher matcher = pattern.matcher(line); 380 if (matcher.find()) { 381 handleFsckFsStat(matcher, lines, lastFsStatLineNumber, lineNumber); 382 lastFsStatLineNumber = lineNumber; 383 } else { 384 Slog.w(TAG, "cannot parse fs_stat:" + line); 385 } 386 } 387 lineNumber++; 388 } 389 390 if (uploadEnabled && uploadNeeded ) { 391 addFileToDropBox(db, timestamps, headers, "/dev/fscklogs/log", maxSize, tag); 392 } 393 394 // Remove the file so we don't re-upload if the runtime restarts. 395 file.delete(); 396 } 397 logFsMountTime()398 private static void logFsMountTime() { 399 for (String propPostfix : MOUNT_DURATION_PROPS_POSTFIX) { 400 int duration = SystemProperties.getInt("ro.boottime.init.mount_all." + propPostfix, 0); 401 if (duration != 0) { 402 MetricsLogger.histogram(null, "boot_mount_all_duration_" + propPostfix, duration); 403 } 404 } 405 } 406 407 // TODO b/64815357 Move to bootstat.cpp and log AbsoluteRebootTime logSystemServerShutdownTimeMetrics()408 private static void logSystemServerShutdownTimeMetrics() { 409 File metricsFile = new File(SHUTDOWN_METRICS_FILE); 410 String metricsStr = null; 411 if (metricsFile.exists()) { 412 try { 413 metricsStr = FileUtils.readTextFile(metricsFile, 0, null); 414 } catch (IOException e) { 415 Slog.e(TAG, "Problem reading " + metricsFile, e); 416 } 417 } 418 if (!TextUtils.isEmpty(metricsStr)) { 419 String reboot = null; 420 String reason = null; 421 String start_time = null; 422 String duration = null; 423 String[] array = metricsStr.split(","); 424 for (String keyValueStr : array) { 425 String[] keyValue = keyValueStr.split(":"); 426 if (keyValue.length != 2) { 427 Slog.e(TAG, "Wrong format of shutdown metrics - " + metricsStr); 428 continue; 429 } 430 // Ignore keys that are not indended for tron 431 if (keyValue[0].startsWith(SHUTDOWN_TRON_METRICS_PREFIX)) { 432 logTronShutdownMetric(keyValue[0], keyValue[1]); 433 if (keyValue[0].equals(METRIC_SYSTEM_SERVER)) { 434 duration = keyValue[1]; 435 } 436 } 437 if (keyValue[0].equals("reboot")) { 438 reboot = keyValue[1]; 439 } else if (keyValue[0].equals("reason")) { 440 reason = keyValue[1]; 441 } else if (keyValue[0].equals(METRIC_SHUTDOWN_TIME_START)) { 442 start_time = keyValue[1]; 443 } 444 } 445 logStatsdShutdownAtom(reboot, reason, start_time, duration); 446 } 447 metricsFile.delete(); 448 } 449 logTronShutdownMetric(String metricName, String valueStr)450 private static void logTronShutdownMetric(String metricName, String valueStr) { 451 int value; 452 try { 453 value = Integer.parseInt(valueStr); 454 } catch (NumberFormatException e) { 455 Slog.e(TAG, "Cannot parse metric " + metricName + " int value - " + valueStr); 456 return; 457 } 458 if (value >= 0) { 459 MetricsLogger.histogram(null, metricName, value); 460 } 461 } 462 logStatsdShutdownAtom( String rebootStr, String reasonStr, String startStr, String durationStr)463 private static void logStatsdShutdownAtom( 464 String rebootStr, String reasonStr, String startStr, String durationStr) { 465 boolean reboot = false; 466 String reason = "<EMPTY>"; 467 long start = 0; 468 long duration = 0; 469 470 if (rebootStr != null) { 471 if (rebootStr.equals("y")) { 472 reboot = true; 473 } else if (!rebootStr.equals("n")) { 474 Slog.e(TAG, "Unexpected value for reboot : " + rebootStr); 475 } 476 } else { 477 Slog.e(TAG, "No value received for reboot"); 478 } 479 480 if (reasonStr != null) { 481 reason = reasonStr; 482 } else { 483 Slog.e(TAG, "No value received for shutdown reason"); 484 } 485 486 if (startStr != null) { 487 try { 488 start = Long.parseLong(startStr); 489 } catch (NumberFormatException e) { 490 Slog.e(TAG, "Cannot parse shutdown start time: " + startStr); 491 } 492 } else { 493 Slog.e(TAG, "No value received for shutdown start time"); 494 } 495 496 if (durationStr != null) { 497 try { 498 duration = Long.parseLong(durationStr); 499 } catch (NumberFormatException e) { 500 Slog.e(TAG, "Cannot parse shutdown duration: " + startStr); 501 } 502 } else { 503 Slog.e(TAG, "No value received for shutdown duration"); 504 } 505 506 StatsLog.write(StatsLog.SHUTDOWN_SEQUENCE_REPORTED, reboot, reason, start, duration); 507 } 508 logFsShutdownTime()509 private static void logFsShutdownTime() { 510 File f = null; 511 for (String fileName : LAST_KMSG_FILES) { 512 File file = new File(fileName); 513 if (!file.exists()) continue; 514 f = file; 515 break; 516 } 517 if (f == null) { // no last_kmsg 518 return; 519 } 520 521 final int maxReadSize = 16*1024; 522 // last_kmsg can be very big, so only parse the last part 523 String lines; 524 try { 525 lines = FileUtils.readTextFile(f, -maxReadSize, null); 526 } catch (IOException e) { 527 Slog.w(TAG, "cannot read last msg", e); 528 return; 529 } 530 Pattern pattern = Pattern.compile(LAST_SHUTDOWN_TIME_PATTERN, Pattern.MULTILINE); 531 Matcher matcher = pattern.matcher(lines); 532 if (matcher.find()) { 533 MetricsLogger.histogram(null, "boot_fs_shutdown_duration", 534 Integer.parseInt(matcher.group(1))); 535 MetricsLogger.histogram(null, "boot_fs_shutdown_umount_stat", 536 Integer.parseInt(matcher.group(2))); 537 Slog.i(TAG, "boot_fs_shutdown," + matcher.group(1) + "," + matcher.group(2)); 538 } else { // not found 539 // This can happen when a device has too much kernel log after file system unmount 540 // ,exceeding maxReadSize. And having that much kernel logging can affect overall 541 // performance as well. So it is better to fix the kernel to reduce the amount of log. 542 MetricsLogger.histogram(null, "boot_fs_shutdown_umount_stat", 543 UMOUNT_STATUS_NOT_AVAILABLE); 544 Slog.w(TAG, "boot_fs_shutdown, string not found"); 545 } 546 } 547 548 /** 549 * Fix fs_stat from e2fsck. 550 * For now, only handle the case of quota warning caused by tree optimization. Clear fs fix 551 * flag (=0x400) caused by that. 552 * 553 * @param partition partition name 554 * @param statOrg original stat reported from e2fsck log 555 * @param lines e2fsck logs broken down into lines 556 * @param startLineNumber start line to parse 557 * @param endLineNumber end line. exclusive. 558 * @return updated fs_stat. For tree optimization, will clear bit 0x400. 559 */ 560 @VisibleForTesting fixFsckFsStat(String partition, int statOrg, String[] lines, int startLineNumber, int endLineNumber)561 public static int fixFsckFsStat(String partition, int statOrg, String[] lines, 562 int startLineNumber, int endLineNumber) { 563 int stat = statOrg; 564 if ((stat & FS_STAT_FS_FIXED) != 0) { 565 // fs was fixed. should check if quota warning was caused by tree optimization. 566 // This is not a real fix but optimization, so should not be counted as a fs fix. 567 Pattern passPattern = Pattern.compile(FSCK_PASS_PATTERN); 568 Pattern treeOptPattern = Pattern.compile(FSCK_TREE_OPTIMIZATION_PATTERN); 569 String currentPass = ""; 570 boolean foundTreeOptimization = false; 571 boolean foundQuotaFix = false; 572 boolean foundTimestampAdjustment = false; 573 boolean foundOtherFix = false; 574 String otherFixLine = null; 575 for (int i = startLineNumber; i < endLineNumber; i++) { 576 String line = lines[i]; 577 if (line.contains(FSCK_FS_MODIFIED)) { // no need to parse above this 578 break; 579 } else if (line.startsWith("Pass ")) { 580 Matcher matcher = passPattern.matcher(line); 581 if (matcher.find()) { 582 currentPass = matcher.group(1); 583 } 584 } else if (line.startsWith("Inode ")) { 585 Matcher matcher = treeOptPattern.matcher(line); 586 if (matcher.find() && currentPass.equals("1")) { 587 foundTreeOptimization = true; 588 Slog.i(TAG, "fs_stat, partition:" + partition + " found tree optimization:" 589 + line); 590 } else { 591 foundOtherFix = true; 592 otherFixLine = line; 593 break; 594 } 595 } else if (line.startsWith("[QUOTA WARNING]") && currentPass.equals("5")) { 596 Slog.i(TAG, "fs_stat, partition:" + partition + " found quota warning:" 597 + line); 598 foundQuotaFix = true; 599 if (!foundTreeOptimization) { // only quota warning, this is real fix. 600 otherFixLine = line; 601 break; 602 } 603 } else if (line.startsWith("Update quota info") && currentPass.equals("5")) { 604 // follows "[QUOTA WARNING]", ignore 605 } else if (line.startsWith("Timestamp(s) on inode") && 606 line.contains("beyond 2310-04-04 are likely pre-1970") && 607 currentPass.equals("1")) { 608 Slog.i(TAG, "fs_stat, partition:" + partition + " found timestamp adjustment:" 609 + line); 610 // followed by next line, "Fix? yes" 611 if (lines[i + 1].contains("Fix? yes")) { 612 i++; 613 } 614 foundTimestampAdjustment = true; 615 } else { 616 line = line.trim(); 617 // ignore empty msg or any msg before Pass 1 618 if (!line.isEmpty() && !currentPass.isEmpty()) { 619 foundOtherFix = true; 620 otherFixLine = line; 621 break; 622 } 623 } 624 } 625 if (foundOtherFix) { 626 if (otherFixLine != null) { 627 Slog.i(TAG, "fs_stat, partition:" + partition + " fix:" + otherFixLine); 628 } 629 } else if (foundQuotaFix && !foundTreeOptimization) { 630 Slog.i(TAG, "fs_stat, got quota fix without tree optimization, partition:" + 631 partition); 632 } else if ((foundTreeOptimization && foundQuotaFix) || foundTimestampAdjustment) { 633 // not a real fix, so clear it. 634 Slog.i(TAG, "fs_stat, partition:" + partition + " fix ignored"); 635 stat &= ~FS_STAT_FS_FIXED; 636 } 637 } 638 return stat; 639 } 640 handleFsckFsStat(Matcher match, String[] lines, int startLineNumber, int endLineNumber)641 private static void handleFsckFsStat(Matcher match, String[] lines, int startLineNumber, 642 int endLineNumber) { 643 String partition = match.group(1); 644 int stat; 645 try { 646 stat = Integer.decode(match.group(2)); 647 } catch (NumberFormatException e) { 648 Slog.w(TAG, "cannot parse fs_stat: partition:" + partition + " stat:" + match.group(2)); 649 return; 650 } 651 stat = fixFsckFsStat(partition, stat, lines, startLineNumber, endLineNumber); 652 MetricsLogger.histogram(null, "boot_fs_stat_" + partition, stat); 653 Slog.i(TAG, "fs_stat, partition:" + partition + " stat:0x" + Integer.toHexString(stat)); 654 } 655 readTimestamps()656 private static HashMap<String, Long> readTimestamps() { 657 synchronized (sFile) { 658 HashMap<String, Long> timestamps = new HashMap<String, Long>(); 659 boolean success = false; 660 try (final FileInputStream stream = sFile.openRead()) { 661 XmlPullParser parser = Xml.newPullParser(); 662 parser.setInput(stream, StandardCharsets.UTF_8.name()); 663 664 int type; 665 while ((type = parser.next()) != XmlPullParser.START_TAG 666 && type != XmlPullParser.END_DOCUMENT) { 667 ; 668 } 669 670 if (type != XmlPullParser.START_TAG) { 671 throw new IllegalStateException("no start tag found"); 672 } 673 674 int outerDepth = parser.getDepth(); // Skip the outer <log-files> tag. 675 while ((type = parser.next()) != XmlPullParser.END_DOCUMENT 676 && (type != XmlPullParser.END_TAG || parser.getDepth() > outerDepth)) { 677 if (type == XmlPullParser.END_TAG || type == XmlPullParser.TEXT) { 678 continue; 679 } 680 681 String tagName = parser.getName(); 682 if (tagName.equals("log")) { 683 final String filename = parser.getAttributeValue(null, "filename"); 684 final long timestamp = Long.valueOf(parser.getAttributeValue( 685 null, "timestamp")); 686 timestamps.put(filename, timestamp); 687 } else { 688 Slog.w(TAG, "Unknown tag: " + parser.getName()); 689 XmlUtils.skipCurrentTag(parser); 690 } 691 } 692 success = true; 693 } catch (FileNotFoundException e) { 694 Slog.i(TAG, "No existing last log timestamp file " + sFile.getBaseFile() + 695 "; starting empty"); 696 } catch (IOException e) { 697 Slog.w(TAG, "Failed parsing " + e); 698 } catch (IllegalStateException e) { 699 Slog.w(TAG, "Failed parsing " + e); 700 } catch (NullPointerException e) { 701 Slog.w(TAG, "Failed parsing " + e); 702 } catch (XmlPullParserException e) { 703 Slog.w(TAG, "Failed parsing " + e); 704 } finally { 705 if (!success) { 706 timestamps.clear(); 707 } 708 } 709 return timestamps; 710 } 711 } 712 writeTimestamps(HashMap<String, Long> timestamps)713 private void writeTimestamps(HashMap<String, Long> timestamps) { 714 synchronized (sFile) { 715 final FileOutputStream stream; 716 try { 717 stream = sFile.startWrite(); 718 } catch (IOException e) { 719 Slog.w(TAG, "Failed to write timestamp file: " + e); 720 return; 721 } 722 723 try { 724 XmlSerializer out = new FastXmlSerializer(); 725 out.setOutput(stream, StandardCharsets.UTF_8.name()); 726 out.startDocument(null, true); 727 out.startTag(null, "log-files"); 728 729 Iterator<String> itor = timestamps.keySet().iterator(); 730 while (itor.hasNext()) { 731 String filename = itor.next(); 732 out.startTag(null, "log"); 733 out.attribute(null, "filename", filename); 734 out.attribute(null, "timestamp", timestamps.get(filename).toString()); 735 out.endTag(null, "log"); 736 } 737 738 out.endTag(null, "log-files"); 739 out.endDocument(); 740 741 sFile.finishWrite(stream); 742 } catch (IOException e) { 743 Slog.w(TAG, "Failed to write timestamp file, using the backup: " + e); 744 sFile.failWrite(stream); 745 } 746 } 747 } 748 } 749