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.CREATE) { 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() && file.getName().startsWith("tombstone_")) { 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 if (tag.equals(TAG_TOMBSTONE)) { 311 StatsLog.write(StatsLog.TOMB_STONE_OCCURRED); 312 } 313 addTextToDropBox(db, tag, text, filename, maxSize); 314 } 315 addTextToDropBox(DropBoxManager db, String tag, String text, String filename, int maxSize)316 private static void addTextToDropBox(DropBoxManager db, String tag, String text, 317 String filename, int maxSize) { 318 Slog.i(TAG, "Copying " + filename + " to DropBox (" + tag + ")"); 319 db.addText(tag, text); 320 EventLog.writeEvent(DropboxLogTags.DROPBOX_FILE_COPY, filename, maxSize, tag); 321 } 322 addAuditErrorsToDropBox(DropBoxManager db, HashMap<String, Long> timestamps, String headers, int maxSize, String tag)323 private static void addAuditErrorsToDropBox(DropBoxManager db, 324 HashMap<String, Long> timestamps, String headers, int maxSize, String tag) 325 throws IOException { 326 if (db == null || !db.isTagEnabled(tag)) return; // Logging disabled 327 Slog.i(TAG, "Copying audit failures to DropBox"); 328 329 File file = new File("/proc/last_kmsg"); 330 long fileTime = file.lastModified(); 331 if (fileTime <= 0) { 332 file = new File("/sys/fs/pstore/console-ramoops"); 333 fileTime = file.lastModified(); 334 if (fileTime <= 0) { 335 file = new File("/sys/fs/pstore/console-ramoops-0"); 336 fileTime = file.lastModified(); 337 } 338 } 339 340 if (fileTime <= 0) return; // File does not exist 341 342 if (timestamps.containsKey(tag) && timestamps.get(tag) == fileTime) { 343 return; // Already logged this particular file 344 } 345 346 timestamps.put(tag, fileTime); 347 348 String log = FileUtils.readTextFile(file, maxSize, "[[TRUNCATED]]\n"); 349 StringBuilder sb = new StringBuilder(); 350 for (String line : log.split("\n")) { 351 if (line.contains("audit")) { 352 sb.append(line + "\n"); 353 } 354 } 355 Slog.i(TAG, "Copied " + sb.toString().length() + " worth of audits to DropBox"); 356 db.addText(tag, headers + sb.toString()); 357 } 358 addFsckErrorsToDropBoxAndLogFsStat(DropBoxManager db, HashMap<String, Long> timestamps, String headers, int maxSize, String tag)359 private static void addFsckErrorsToDropBoxAndLogFsStat(DropBoxManager db, 360 HashMap<String, Long> timestamps, String headers, int maxSize, String tag) 361 throws IOException { 362 boolean uploadEnabled = true; 363 if (db == null || !db.isTagEnabled(tag)) { 364 uploadEnabled = false; 365 } 366 boolean uploadNeeded = false; 367 Slog.i(TAG, "Checking for fsck errors"); 368 369 File file = new File("/dev/fscklogs/log"); 370 long fileTime = file.lastModified(); 371 if (fileTime <= 0) return; // File does not exist 372 373 String log = FileUtils.readTextFile(file, maxSize, "[[TRUNCATED]]\n"); 374 Pattern pattern = Pattern.compile(FS_STAT_PATTERN); 375 String lines[] = log.split("\n"); 376 int lineNumber = 0; 377 int lastFsStatLineNumber = 0; 378 for (String line : lines) { // should check all lines 379 if (line.contains(FSCK_FS_MODIFIED)) { 380 uploadNeeded = true; 381 } else if (line.contains("fs_stat")){ 382 Matcher matcher = pattern.matcher(line); 383 if (matcher.find()) { 384 handleFsckFsStat(matcher, lines, lastFsStatLineNumber, lineNumber); 385 lastFsStatLineNumber = lineNumber; 386 } else { 387 Slog.w(TAG, "cannot parse fs_stat:" + line); 388 } 389 } 390 lineNumber++; 391 } 392 393 if (uploadEnabled && uploadNeeded ) { 394 addFileToDropBox(db, timestamps, headers, "/dev/fscklogs/log", maxSize, tag); 395 } 396 397 // Remove the file so we don't re-upload if the runtime restarts. 398 file.delete(); 399 } 400 logFsMountTime()401 private static void logFsMountTime() { 402 for (String propPostfix : MOUNT_DURATION_PROPS_POSTFIX) { 403 int duration = SystemProperties.getInt("ro.boottime.init.mount_all." + propPostfix, 0); 404 if (duration != 0) { 405 MetricsLogger.histogram(null, "boot_mount_all_duration_" + propPostfix, duration); 406 } 407 } 408 } 409 410 // TODO b/64815357 Move to bootstat.cpp and log AbsoluteRebootTime logSystemServerShutdownTimeMetrics()411 private static void logSystemServerShutdownTimeMetrics() { 412 File metricsFile = new File(SHUTDOWN_METRICS_FILE); 413 String metricsStr = null; 414 if (metricsFile.exists()) { 415 try { 416 metricsStr = FileUtils.readTextFile(metricsFile, 0, null); 417 } catch (IOException e) { 418 Slog.e(TAG, "Problem reading " + metricsFile, e); 419 } 420 } 421 if (!TextUtils.isEmpty(metricsStr)) { 422 String reboot = null; 423 String reason = null; 424 String start_time = null; 425 String duration = null; 426 String[] array = metricsStr.split(","); 427 for (String keyValueStr : array) { 428 String[] keyValue = keyValueStr.split(":"); 429 if (keyValue.length != 2) { 430 Slog.e(TAG, "Wrong format of shutdown metrics - " + metricsStr); 431 continue; 432 } 433 // Ignore keys that are not indended for tron 434 if (keyValue[0].startsWith(SHUTDOWN_TRON_METRICS_PREFIX)) { 435 logTronShutdownMetric(keyValue[0], keyValue[1]); 436 if (keyValue[0].equals(METRIC_SYSTEM_SERVER)) { 437 duration = keyValue[1]; 438 } 439 } 440 if (keyValue[0].equals("reboot")) { 441 reboot = keyValue[1]; 442 } else if (keyValue[0].equals("reason")) { 443 reason = keyValue[1]; 444 } else if (keyValue[0].equals(METRIC_SHUTDOWN_TIME_START)) { 445 start_time = keyValue[1]; 446 } 447 } 448 logStatsdShutdownAtom(reboot, reason, start_time, duration); 449 } 450 metricsFile.delete(); 451 } 452 logTronShutdownMetric(String metricName, String valueStr)453 private static void logTronShutdownMetric(String metricName, String valueStr) { 454 int value; 455 try { 456 value = Integer.parseInt(valueStr); 457 } catch (NumberFormatException e) { 458 Slog.e(TAG, "Cannot parse metric " + metricName + " int value - " + valueStr); 459 return; 460 } 461 if (value >= 0) { 462 MetricsLogger.histogram(null, metricName, value); 463 } 464 } 465 logStatsdShutdownAtom( String rebootStr, String reasonStr, String startStr, String durationStr)466 private static void logStatsdShutdownAtom( 467 String rebootStr, String reasonStr, String startStr, String durationStr) { 468 boolean reboot = false; 469 String reason = "<EMPTY>"; 470 long start = 0; 471 long duration = 0; 472 473 if (rebootStr != null) { 474 if (rebootStr.equals("y")) { 475 reboot = true; 476 } else if (!rebootStr.equals("n")) { 477 Slog.e(TAG, "Unexpected value for reboot : " + rebootStr); 478 } 479 } else { 480 Slog.e(TAG, "No value received for reboot"); 481 } 482 483 if (reasonStr != null) { 484 reason = reasonStr; 485 } else { 486 Slog.e(TAG, "No value received for shutdown reason"); 487 } 488 489 if (startStr != null) { 490 try { 491 start = Long.parseLong(startStr); 492 } catch (NumberFormatException e) { 493 Slog.e(TAG, "Cannot parse shutdown start time: " + startStr); 494 } 495 } else { 496 Slog.e(TAG, "No value received for shutdown start time"); 497 } 498 499 if (durationStr != null) { 500 try { 501 duration = Long.parseLong(durationStr); 502 } catch (NumberFormatException e) { 503 Slog.e(TAG, "Cannot parse shutdown duration: " + startStr); 504 } 505 } else { 506 Slog.e(TAG, "No value received for shutdown duration"); 507 } 508 509 StatsLog.write(StatsLog.SHUTDOWN_SEQUENCE_REPORTED, reboot, reason, start, duration); 510 } 511 logFsShutdownTime()512 private static void logFsShutdownTime() { 513 File f = null; 514 for (String fileName : LAST_KMSG_FILES) { 515 File file = new File(fileName); 516 if (!file.exists()) continue; 517 f = file; 518 break; 519 } 520 if (f == null) { // no last_kmsg 521 return; 522 } 523 524 final int maxReadSize = 16*1024; 525 // last_kmsg can be very big, so only parse the last part 526 String lines; 527 try { 528 lines = FileUtils.readTextFile(f, -maxReadSize, null); 529 } catch (IOException e) { 530 Slog.w(TAG, "cannot read last msg", e); 531 return; 532 } 533 Pattern pattern = Pattern.compile(LAST_SHUTDOWN_TIME_PATTERN, Pattern.MULTILINE); 534 Matcher matcher = pattern.matcher(lines); 535 if (matcher.find()) { 536 MetricsLogger.histogram(null, "boot_fs_shutdown_duration", 537 Integer.parseInt(matcher.group(1))); 538 MetricsLogger.histogram(null, "boot_fs_shutdown_umount_stat", 539 Integer.parseInt(matcher.group(2))); 540 Slog.i(TAG, "boot_fs_shutdown," + matcher.group(1) + "," + matcher.group(2)); 541 } else { // not found 542 // This can happen when a device has too much kernel log after file system unmount 543 // ,exceeding maxReadSize. And having that much kernel logging can affect overall 544 // performance as well. So it is better to fix the kernel to reduce the amount of log. 545 MetricsLogger.histogram(null, "boot_fs_shutdown_umount_stat", 546 UMOUNT_STATUS_NOT_AVAILABLE); 547 Slog.w(TAG, "boot_fs_shutdown, string not found"); 548 } 549 } 550 551 /** 552 * Fix fs_stat from e2fsck. 553 * For now, only handle the case of quota warning caused by tree optimization. Clear fs fix 554 * flag (=0x400) caused by that. 555 * 556 * @param partition partition name 557 * @param statOrg original stat reported from e2fsck log 558 * @param lines e2fsck logs broken down into lines 559 * @param startLineNumber start line to parse 560 * @param endLineNumber end line. exclusive. 561 * @return updated fs_stat. For tree optimization, will clear bit 0x400. 562 */ 563 @VisibleForTesting fixFsckFsStat(String partition, int statOrg, String[] lines, int startLineNumber, int endLineNumber)564 public static int fixFsckFsStat(String partition, int statOrg, String[] lines, 565 int startLineNumber, int endLineNumber) { 566 int stat = statOrg; 567 if ((stat & FS_STAT_FS_FIXED) != 0) { 568 // fs was fixed. should check if quota warning was caused by tree optimization. 569 // This is not a real fix but optimization, so should not be counted as a fs fix. 570 Pattern passPattern = Pattern.compile(FSCK_PASS_PATTERN); 571 Pattern treeOptPattern = Pattern.compile(FSCK_TREE_OPTIMIZATION_PATTERN); 572 String currentPass = ""; 573 boolean foundTreeOptimization = false; 574 boolean foundQuotaFix = false; 575 boolean foundTimestampAdjustment = false; 576 boolean foundOtherFix = false; 577 String otherFixLine = null; 578 for (int i = startLineNumber; i < endLineNumber; i++) { 579 String line = lines[i]; 580 if (line.contains(FSCK_FS_MODIFIED)) { // no need to parse above this 581 break; 582 } else if (line.startsWith("Pass ")) { 583 Matcher matcher = passPattern.matcher(line); 584 if (matcher.find()) { 585 currentPass = matcher.group(1); 586 } 587 } else if (line.startsWith("Inode ")) { 588 Matcher matcher = treeOptPattern.matcher(line); 589 if (matcher.find() && currentPass.equals("1")) { 590 foundTreeOptimization = true; 591 Slog.i(TAG, "fs_stat, partition:" + partition + " found tree optimization:" 592 + line); 593 } else { 594 foundOtherFix = true; 595 otherFixLine = line; 596 break; 597 } 598 } else if (line.startsWith("[QUOTA WARNING]") && currentPass.equals("5")) { 599 Slog.i(TAG, "fs_stat, partition:" + partition + " found quota warning:" 600 + line); 601 foundQuotaFix = true; 602 if (!foundTreeOptimization) { // only quota warning, this is real fix. 603 otherFixLine = line; 604 break; 605 } 606 } else if (line.startsWith("Update quota info") && currentPass.equals("5")) { 607 // follows "[QUOTA WARNING]", ignore 608 } else if (line.startsWith("Timestamp(s) on inode") && 609 line.contains("beyond 2310-04-04 are likely pre-1970") && 610 currentPass.equals("1")) { 611 Slog.i(TAG, "fs_stat, partition:" + partition + " found timestamp adjustment:" 612 + line); 613 // followed by next line, "Fix? yes" 614 if (lines[i + 1].contains("Fix? yes")) { 615 i++; 616 } 617 foundTimestampAdjustment = true; 618 } else { 619 line = line.trim(); 620 // ignore empty msg or any msg before Pass 1 621 if (!line.isEmpty() && !currentPass.isEmpty()) { 622 foundOtherFix = true; 623 otherFixLine = line; 624 break; 625 } 626 } 627 } 628 if (foundOtherFix) { 629 if (otherFixLine != null) { 630 Slog.i(TAG, "fs_stat, partition:" + partition + " fix:" + otherFixLine); 631 } 632 } else if (foundQuotaFix && !foundTreeOptimization) { 633 Slog.i(TAG, "fs_stat, got quota fix without tree optimization, partition:" + 634 partition); 635 } else if ((foundTreeOptimization && foundQuotaFix) || foundTimestampAdjustment) { 636 // not a real fix, so clear it. 637 Slog.i(TAG, "fs_stat, partition:" + partition + " fix ignored"); 638 stat &= ~FS_STAT_FS_FIXED; 639 } 640 } 641 return stat; 642 } 643 handleFsckFsStat(Matcher match, String[] lines, int startLineNumber, int endLineNumber)644 private static void handleFsckFsStat(Matcher match, String[] lines, int startLineNumber, 645 int endLineNumber) { 646 String partition = match.group(1); 647 int stat; 648 try { 649 stat = Integer.decode(match.group(2)); 650 } catch (NumberFormatException e) { 651 Slog.w(TAG, "cannot parse fs_stat: partition:" + partition + " stat:" + match.group(2)); 652 return; 653 } 654 stat = fixFsckFsStat(partition, stat, lines, startLineNumber, endLineNumber); 655 MetricsLogger.histogram(null, "boot_fs_stat_" + partition, stat); 656 Slog.i(TAG, "fs_stat, partition:" + partition + " stat:0x" + Integer.toHexString(stat)); 657 } 658 readTimestamps()659 private static HashMap<String, Long> readTimestamps() { 660 synchronized (sFile) { 661 HashMap<String, Long> timestamps = new HashMap<String, Long>(); 662 boolean success = false; 663 try (final FileInputStream stream = sFile.openRead()) { 664 XmlPullParser parser = Xml.newPullParser(); 665 parser.setInput(stream, StandardCharsets.UTF_8.name()); 666 667 int type; 668 while ((type = parser.next()) != XmlPullParser.START_TAG 669 && type != XmlPullParser.END_DOCUMENT) { 670 ; 671 } 672 673 if (type != XmlPullParser.START_TAG) { 674 throw new IllegalStateException("no start tag found"); 675 } 676 677 int outerDepth = parser.getDepth(); // Skip the outer <log-files> tag. 678 while ((type = parser.next()) != XmlPullParser.END_DOCUMENT 679 && (type != XmlPullParser.END_TAG || parser.getDepth() > outerDepth)) { 680 if (type == XmlPullParser.END_TAG || type == XmlPullParser.TEXT) { 681 continue; 682 } 683 684 String tagName = parser.getName(); 685 if (tagName.equals("log")) { 686 final String filename = parser.getAttributeValue(null, "filename"); 687 final long timestamp = Long.valueOf(parser.getAttributeValue( 688 null, "timestamp")); 689 timestamps.put(filename, timestamp); 690 } else { 691 Slog.w(TAG, "Unknown tag: " + parser.getName()); 692 XmlUtils.skipCurrentTag(parser); 693 } 694 } 695 success = true; 696 } catch (FileNotFoundException e) { 697 Slog.i(TAG, "No existing last log timestamp file " + sFile.getBaseFile() + 698 "; starting empty"); 699 } catch (IOException e) { 700 Slog.w(TAG, "Failed parsing " + e); 701 } catch (IllegalStateException e) { 702 Slog.w(TAG, "Failed parsing " + e); 703 } catch (NullPointerException e) { 704 Slog.w(TAG, "Failed parsing " + e); 705 } catch (XmlPullParserException e) { 706 Slog.w(TAG, "Failed parsing " + e); 707 } finally { 708 if (!success) { 709 timestamps.clear(); 710 } 711 } 712 return timestamps; 713 } 714 } 715 writeTimestamps(HashMap<String, Long> timestamps)716 private void writeTimestamps(HashMap<String, Long> timestamps) { 717 synchronized (sFile) { 718 final FileOutputStream stream; 719 try { 720 stream = sFile.startWrite(); 721 } catch (IOException e) { 722 Slog.w(TAG, "Failed to write timestamp file: " + e); 723 return; 724 } 725 726 try { 727 XmlSerializer out = new FastXmlSerializer(); 728 out.setOutput(stream, StandardCharsets.UTF_8.name()); 729 out.startDocument(null, true); 730 out.startTag(null, "log-files"); 731 732 Iterator<String> itor = timestamps.keySet().iterator(); 733 while (itor.hasNext()) { 734 String filename = itor.next(); 735 out.startTag(null, "log"); 736 out.attribute(null, "filename", filename); 737 out.attribute(null, "timestamp", timestamps.get(filename).toString()); 738 out.endTag(null, "log"); 739 } 740 741 out.endTag(null, "log-files"); 742 out.endDocument(); 743 744 sFile.finishWrite(stream); 745 } catch (IOException e) { 746 Slog.w(TAG, "Failed to write timestamp file, using the backup: " + e); 747 sFile.failWrite(stream); 748 } 749 } 750 } 751 } 752