1 /* 2 * Copyright (C) 2011 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 package com.android.loganalysis.parser; 17 18 import com.android.loganalysis.item.LogcatItem; 19 import com.android.loganalysis.item.MiscLogcatItem; 20 import com.android.loganalysis.util.ArrayUtil; 21 import com.android.loganalysis.util.LogPatternUtil; 22 import com.android.loganalysis.util.LogTailUtil; 23 24 import java.io.BufferedReader; 25 import java.io.IOException; 26 import java.text.DateFormat; 27 import java.text.ParseException; 28 import java.text.SimpleDateFormat; 29 import java.util.ArrayList; 30 import java.util.Date; 31 import java.util.HashMap; 32 import java.util.LinkedList; 33 import java.util.List; 34 import java.util.Map; 35 import java.util.regex.Matcher; 36 import java.util.regex.Pattern; 37 38 /** 39 * An {@link IParser} to handle logcat. The parser can handle the time and threadtime logcat 40 * formats. 41 * <p> 42 * Since the timestamps in the logcat do not have a year, the year can be set manually when the 43 * parser is created or through {@link #setYear(String)}. If a year is not set, the current year 44 * will be used. 45 * </p> 46 */ 47 public class LogcatParser implements IParser { 48 public static final String ANR = "ANR"; 49 public static final String JAVA_CRASH = "JAVA_CRASH"; 50 public static final String NATIVE_CRASH = "NATIVE_CRASH"; 51 public static final String HIGH_CPU_USAGE = "HIGH_CPU_USAGE"; 52 public static final String HIGH_MEMORY_USAGE = "HIGH_MEMORY_USAGE"; 53 public static final String RUNTIME_RESTART = "RUNTIME_RESTART"; 54 55 /** 56 * Match a single line of `logcat -v threadtime`, such as: 57 * 58 * <pre>05-26 11:02:36.886 5689 5689 D AndroidRuntime: CheckJNI is OFF.</pre> 59 */ 60 private static final Pattern THREADTIME_LINE = 61 // UID was added to logcat. It could either be a number or a string. 62 Pattern.compile( 63 // timestamp[1] 64 "^(\\d{2}-\\d{2} \\d{2}:\\d{2}:\\d{2}.\\d{3})" 65 // pid/tid and log level [2-4] 66 + "(?:\\s+[0-9A-Za-z]+)?\\s+(\\d+)\\s+(\\d+)\\s+([A-Z])\\s+" 67 // tag and message [5-6] 68 + "(.+?)\\s*: (.*)$"); 69 70 /** 71 * Match a single line of `logcat -v time`, such as: 72 * 06-04 02:32:14.002 D/dalvikvm( 236): GC_CONCURRENT freed 580K, 51% free [...] 73 */ 74 private static final Pattern TIME_LINE = Pattern.compile( 75 "^(\\d{2}-\\d{2} \\d{2}:\\d{2}:\\d{2}.\\d{3})\\s+" + /* timestamp [1] */ 76 "(\\w)/(.+?)\\(\\s*(\\d+)\\): (.*)$"); /* level, tag, pid, msg [2-5] */ 77 78 /** 79 * Match: "*** FATAL EXCEPTION IN SYSTEM PROCESS: message" 80 */ 81 private static final Pattern SYSTEM_SERVER_CRASH = Pattern.compile( 82 "\\*\\*\\* FATAL EXCEPTION IN SYSTEM PROCESS:.*"); 83 /** 84 * Match "Process: com.android.package, PID: 123" or "PID: 123" 85 */ 86 private static final Pattern JAVA_CRASH_PROCESS_PID = Pattern.compile( 87 "^(Process: (\\S+), )?PID: (\\d+)$"); 88 89 90 /** 91 * Match a line thats printed when a non app java process starts. 92 */ 93 private static final Pattern JAVA_PROC_START = Pattern.compile("Calling main entry (.+)"); 94 95 /** 96 * Class for storing logcat meta data for a particular grouped list of lines. 97 */ 98 private class LogcatData { 99 public Integer mPid = null; 100 public Integer mTid = null; 101 public Date mTime = null; 102 public String mLevel = null; 103 public String mTag = null; 104 public String mLastPreamble = null; 105 public String mProcPreamble = null; 106 public List<String> mLines = new LinkedList<String>(); 107 LogcatData(Integer pid, Integer tid, Date time, String level, String tag, String lastPreamble, String procPreamble)108 public LogcatData(Integer pid, Integer tid, Date time, String level, String tag, 109 String lastPreamble, String procPreamble) { 110 mPid = pid; 111 mTid = tid; 112 mTime = time; 113 mLevel = level; 114 mTag = tag; 115 mLastPreamble = lastPreamble; 116 mProcPreamble = procPreamble; 117 } 118 } 119 120 private LogPatternUtil mPatternUtil = new LogPatternUtil(); 121 private LogTailUtil mPreambleUtil = new LogTailUtil(); 122 123 private String mYear = null; 124 125 LogcatItem mLogcat = null; 126 127 Map<String, LogcatData> mDataMap = new HashMap<String, LogcatData>(); 128 List<LogcatData> mDataList = new LinkedList<LogcatData>(); 129 130 private Date mStartTime = null; 131 private Date mStopTime = null; 132 133 private boolean mIsParsing = true; 134 135 private Map<Integer, String> mPids = new HashMap<Integer, String>(); 136 137 private List<CrashTag> mJavaCrashTags = new ArrayList<>(); 138 private List<CrashTag> mNativeCrashTags = new ArrayList<>(); 139 140 /** 141 * Constructor for {@link LogcatParser}. 142 */ LogcatParser()143 public LogcatParser() { 144 // Add default tag for java crash 145 addJavaCrashTag("E", "AndroidRuntime", JAVA_CRASH); 146 addNativeCrashTag("I", "DEBUG"); 147 addNativeCrashTag("F", "DEBUG"); 148 initPatterns(); 149 } 150 151 /** 152 * Constructor for {@link LogcatParser}. 153 * 154 * @param year The year as a string. 155 */ LogcatParser(String year)156 public LogcatParser(String year) { 157 this(); 158 setYear(year); 159 } 160 161 /** 162 * Sets the year for {@link LogcatParser}. 163 * 164 * @param year The year as a string. 165 */ setYear(String year)166 public void setYear(String year) { 167 mYear = year; 168 } 169 170 /** 171 * Parse a logcat from a {@link BufferedReader} into an {@link LogcatItem} object. 172 * 173 * @param input a {@link BufferedReader}. 174 * @return The {@link LogcatItem}. 175 * @see #parse(List) 176 */ parse(BufferedReader input)177 public LogcatItem parse(BufferedReader input) throws IOException { 178 String line; 179 while ((line = input.readLine()) != null) { 180 parseLine(line); 181 } 182 commit(); 183 184 return mLogcat; 185 } 186 187 /** 188 * {@inheritDoc} 189 * 190 * @return The {@link LogcatItem}. 191 */ 192 @Override parse(List<String> lines)193 public LogcatItem parse(List<String> lines) { 194 for (String line : lines) { 195 if (line == null) { 196 continue; 197 } 198 parseLine(line); 199 } 200 commit(); 201 202 return mLogcat; 203 } 204 205 /** 206 * Clear the existing {@link LogcatItem}. The next parse will create a new one. 207 */ clear()208 public void clear() { 209 mLogcat = null; 210 mDataList.clear(); 211 mDataMap.clear(); 212 } 213 214 /** 215 * Parse a line of input. 216 * 217 * @param line The line to parse 218 */ parseLine(String line)219 private void parseLine(String line) { 220 if ("".equals(line.trim())) { 221 return; 222 } 223 if (mLogcat == null) { 224 mLogcat = new LogcatItem(); 225 } 226 Integer pid = null; 227 Integer tid = null; 228 Date time = null; 229 String level = null; 230 String tag = null; 231 String msg = null; 232 233 Matcher m = THREADTIME_LINE.matcher(line); 234 Matcher tm = TIME_LINE.matcher(line); 235 if (m.matches()) { 236 time = parseTime(m.group(1)); 237 pid = Integer.parseInt(m.group(2)); 238 tid = Integer.parseInt(m.group(3)); 239 level = m.group(4); 240 tag = m.group(5); 241 msg = m.group(6); 242 } else if (tm.matches()) { 243 time = parseTime(tm.group(1)); 244 level = tm.group(2); 245 tag = tm.group(3); 246 pid = Integer.parseInt(tm.group(4)); 247 msg = tm.group(5); 248 } 249 250 if (time != null) { 251 if (mStartTime == null) { 252 mStartTime = time; 253 } 254 mStopTime = time; 255 } 256 257 // Don't parse any lines after device begins reboot until a new log is detected. 258 if ("I".equals(level) && "ShutdownThread".equals(tag) && 259 Pattern.matches("Rebooting, reason: .*", msg)) { 260 mIsParsing = false; 261 } 262 if (Pattern.matches(".*--------- beginning of .*", line)) { 263 mIsParsing = true; 264 } 265 266 if (!mIsParsing || !(m.matches() || tm.matches())) { 267 return; 268 } 269 270 271 // When a non app java process starts add its pid to the map 272 Matcher pidMatcher = JAVA_PROC_START.matcher(msg); 273 if (pidMatcher.matches()) { 274 String name = pidMatcher.group(1); 275 mPids.put(pid, name); 276 } 277 278 // ANRs are separated either by different PID/TIDs or when AnrParser.START matches a line. 279 // The newest entry is kept in the dataMap for quick lookup while all entries are added to 280 // the list. 281 if ("E".equals(level) && "ActivityManager".equals(tag)) { 282 String key = encodeLine(pid, tid, level, tag); 283 LogcatData data; 284 if (!mDataMap.containsKey(key) || AnrParser.START.matcher(msg).matches()) { 285 data = new LogcatData(pid, tid, time, level, tag, mPreambleUtil.getLastTail(), 286 mPreambleUtil.getIdTail(pid)); 287 mDataMap.put(key, data); 288 mDataList.add(data); 289 } else { 290 data = mDataMap.get(key); 291 } 292 data.mLines.add(msg); 293 } 294 295 // Native crashes are separated either by different PID/TIDs or when 296 // NativeCrashParser.FINGERPRINT matches a line. The newest entry is kept in the dataMap 297 // for quick lookup while all entries are added to the list. 298 if (anyNativeCrashTagMatches(level, tag)) { 299 String key = encodeLine(pid, tid, level, tag); 300 LogcatData data; 301 if (!mDataMap.containsKey(key) || NativeCrashParser.FINGERPRINT.matcher(msg).matches()) { 302 data = new LogcatData(pid, tid, time, level, tag, mPreambleUtil.getLastTail(), 303 mPreambleUtil.getIdTail(pid)); 304 mDataMap.put(key, data); 305 mDataList.add(data); 306 } else { 307 data = mDataMap.get(key); 308 } 309 data.mLines.add(msg); 310 } 311 312 // PID and TID are enough to separate Java crashes. 313 if (anyJavaCrashTagMatches(level, tag)) { 314 String key = encodeLine(pid, tid, level, tag); 315 LogcatData data; 316 if (!mDataMap.containsKey(key)) { 317 data = new LogcatData(pid, tid, time, level, tag, mPreambleUtil.getLastTail(), 318 mPreambleUtil.getIdTail(pid)); 319 mDataMap.put(key, data); 320 mDataList.add(data); 321 } else { 322 data = mDataMap.get(key); 323 } 324 data.mLines.add(msg); 325 } 326 327 // Check the message here but add it in commit() 328 if (mPatternUtil.checkMessage(msg, new ExtrasPattern(level, tag)) != null) { 329 LogcatData data = new LogcatData(pid, tid, time, level, tag, 330 mPreambleUtil.getLastTail(), mPreambleUtil.getIdTail(pid)); 331 data.mLines.add(msg); 332 mDataList.add(data); 333 } 334 335 // After parsing the line, add it the the buffer for the preambles. 336 mPreambleUtil.addLine(pid, line); 337 } 338 339 /** 340 * Signal that the input has finished. 341 */ commit()342 private void commit() { 343 if (mLogcat == null) { 344 return; 345 } 346 for (LogcatData data : mDataList) { 347 MiscLogcatItem item = null; 348 if ("E".equals(data.mLevel) && "ActivityManager".equals(data.mTag)) { 349 item = new AnrParser().parse(data.mLines); 350 } else if (anyJavaCrashTagMatches(data.mLevel, data.mTag)) { 351 // Get the process name/PID from the Java crash, then pass the rest of the lines to 352 // the parser. 353 Integer pid = null; 354 String app = null; 355 for (int i = 0; i < data.mLines.size(); i++) { 356 String line = data.mLines.get(i); 357 Matcher m = JAVA_CRASH_PROCESS_PID.matcher(line); 358 if (m.matches()) { 359 app = m.group(2); 360 pid = Integer.valueOf(m.group(3)); 361 data.mLines = data.mLines.subList(i + 1, data.mLines.size()); 362 break; 363 } 364 m = SYSTEM_SERVER_CRASH.matcher(line); 365 if (m.matches()) { 366 app = mPids.get(data.mPid); 367 if (app == null) { 368 app = "system_server"; 369 } 370 data.mLines = data.mLines.subList(i + 1, data.mLines.size()); 371 break; 372 } 373 } 374 item = new JavaCrashParser().parse(data.mLines); 375 if (item != null) { 376 item.setApp(app); 377 item.setPid(pid); 378 item.setCategory(getJavaCrashCategory(data.mLevel, data.mTag)); 379 } 380 } else if (anyNativeCrashTagMatches(data.mLevel, data.mTag)) { 381 // CLog.v("Parsing native crash: %s", data.mLines); 382 item = new NativeCrashParser().parse(data.mLines); 383 } else { 384 String msg = ArrayUtil.join("\n", data.mLines); 385 String category = mPatternUtil.checkMessage(msg, new ExtrasPattern( 386 data.mLevel, data.mTag)); 387 if (category != null) { 388 MiscLogcatItem logcatItem = new MiscLogcatItem(); 389 logcatItem.setCategory(category); 390 logcatItem.setStack(msg); 391 item = logcatItem; 392 } 393 } 394 if (item != null) { 395 item.setEventTime(data.mTime); 396 if (item.getPid() == null) { 397 item.setPid(data.mPid); 398 item.setTid(data.mTid); 399 } 400 item.setLastPreamble(data.mLastPreamble); 401 item.setProcessPreamble(data.mProcPreamble); 402 item.setTag(data.mTag); 403 mLogcat.addEvent(item); 404 } 405 } 406 407 mLogcat.setStartTime(mStartTime); 408 mLogcat.setStopTime(mStopTime); 409 } 410 411 /** 412 * Create an identifier that "should" be unique for a given logcat. In practice, we do use it as 413 * a unique identifier. 414 */ encodeLine(Integer pid, Integer tid, String level, String tag)415 private static String encodeLine(Integer pid, Integer tid, String level, String tag) { 416 if (tid == null) { 417 return String.format("%d|%s|%s", pid, level, tag); 418 } 419 return String.format("%d|%d|%s|%s", pid, tid, level, tag); 420 } 421 422 /** 423 * Parse the timestamp and return a {@link Date}. If year is not set, the current year will be 424 * used. 425 * 426 * @param timeStr The timestamp in the format {@code MM-dd HH:mm:ss.SSS}. 427 * @return The {@link Date}. 428 */ parseTime(String timeStr)429 private Date parseTime(String timeStr) { 430 // If year is null, just use the current year. 431 if (mYear == null) { 432 DateFormat yearFormatter = new SimpleDateFormat("yyyy"); 433 mYear = yearFormatter.format(new Date()); 434 } 435 436 DateFormat formatter = new SimpleDateFormat("yyyy-MM-dd HH:mm:ss.SSS"); 437 try { 438 return formatter.parse(String.format("%s-%s", mYear, timeStr)); 439 } catch (ParseException e) { 440 // CLog.e("Could not parse time string %s", timeStr); 441 return null; 442 } 443 } 444 initPatterns()445 private void initPatterns() { 446 // High CPU usage 447 mPatternUtil.addPattern(Pattern.compile(".* timed out \\(is the CPU pegged\\?\\).*"), 448 HIGH_CPU_USAGE); 449 450 // High memory usage 451 mPatternUtil.addPattern(Pattern.compile( 452 "GetBufferLock timed out for thread \\d+ buffer .*"), HIGH_MEMORY_USAGE); 453 454 // Runtime restarts 455 mPatternUtil.addPattern(Pattern.compile("\\*\\*\\* WATCHDOG KILLING SYSTEM PROCESS.*"), 456 RUNTIME_RESTART); 457 } 458 459 /** 460 * Adds a custom, more complex pattern to LogcatParser for parsing out of logcat events. 461 * Any matched events are then assigned to the category name provided, and can be grabbed 462 * via LogcatParser's .getMiscEvents("yourCustomCategoryName") method. 463 * Considers null messages, levels, or tags to be wildcards. 464 * 465 * @param pattern The regex representing the pattern to match for, or null for wildcard. 466 * @param level The name of the level to match for, or null for wildcard. 467 * @param tag The name of the tag to match for, or null for wildcard. 468 * @param category Assign any matching logcat events to this category name, for later retrieval 469 */ addPattern(Pattern pattern, String level, String tag, String category)470 public void addPattern(Pattern pattern, String level, String tag, String category) { 471 /* count null message as wildcard */ 472 if (pattern == null) { 473 pattern = Pattern.compile(".*"); 474 } 475 mPatternUtil.addPattern(pattern, new ExtrasPattern(level, tag), category); 476 } 477 478 /** 479 * Used internally for bundling up extra pattern criteria for more advanced pattern matching. 480 */ 481 private class ExtrasPattern { 482 public String mLevel; 483 public String mTag; 484 ExtrasPattern(String level, String tag)485 public ExtrasPattern(String level, String tag) { 486 mLevel = level; 487 mTag = tag; 488 } 489 490 /** 491 * Override Object.equals to match based on the level & tag patterns, 492 * while also counting null level & tag patterns as wildcards. 493 * 494 * @param otherObj the object we're matching the level & tag patterns to. 495 * @return true if otherObj's extras match, false otherwise 496 */ 497 @Override equals(Object otherObj)498 public boolean equals(Object otherObj) { 499 if (otherObj instanceof ExtrasPattern) { 500 // Treat objects as equal only if the obj's level and tag match. 501 // Treat null as a wildcard. 502 ExtrasPattern other = (ExtrasPattern) otherObj; 503 if ((mLevel == null || other.mLevel == null || mLevel.equals(other.mLevel)) && 504 (mTag == null || other.mTag == null || mTag.equals(other.mTag))) { 505 return true; 506 } 507 } 508 return false; 509 } 510 511 /** {@inheritdoc} */ 512 @Override hashCode()513 public int hashCode() { 514 // Since both mLevel and mTag can be wild cards, we can't actually use them to generate 515 // a hashcode without potentially violating the hashcode contract. That doesn't leave 516 // us with anything to actually use to generate the hashcode, so just return a random 517 // static int. 518 return 145800969; 519 } 520 } 521 522 /** 523 * Allows Java crashes to be parsed from multiple log levels and tags. Normally the crashes 524 * are error level messages from AndroidRuntime, but they could also be from other sources. 525 * Use this method to parse java crashes from those other sources. 526 * 527 * @param level log level on which to look for java crashes 528 * @param tag log tag where to look for java crashes 529 */ addJavaCrashTag(String level, String tag, String category)530 public void addJavaCrashTag(String level, String tag, String category) { 531 mJavaCrashTags.add(new CrashTag(level, tag, category)); 532 } 533 534 /** 535 * Allows native crashes to be parsed from multiple log levels and tags. The default levels 536 * are "I DEBUG" and "F DEBUG". 537 * 538 * @param level log level on which to look for native crashes 539 * @param tag log tag where to look for native crashes 540 */ addNativeCrashTag(String level, String tag)541 private void addNativeCrashTag(String level, String tag) { 542 mNativeCrashTags.add(new CrashTag(level, tag, NATIVE_CRASH)); 543 } 544 545 /** 546 * Determines if any of the Java crash tags is matching a logcat line. 547 * 548 * @param level log level of the logcat line 549 * @param tag tag of the logcat line 550 * @return True if any Java crash tag matches the current level and tag. False otherwise. 551 */ anyJavaCrashTagMatches(String level, String tag)552 private boolean anyJavaCrashTagMatches(String level, String tag) { 553 return findCrashTag(mJavaCrashTags, level, tag) != null; 554 } 555 556 /** 557 * Determines if any of the native crash tags is matching a logcat line. 558 * 559 * @param level log level of the logcat line 560 * @param tag tag of the logcat line 561 * @return True if any native crash tag matches the current level and tag. False otherwise. 562 */ anyNativeCrashTagMatches(String level, String tag)563 private boolean anyNativeCrashTagMatches(String level, String tag) { 564 return findCrashTag(mNativeCrashTags, level, tag) != null; 565 } 566 567 /** 568 * Finds the {@link CrashTag} matching given level and tag. 569 * 570 * @param level level to find 571 * @param tag tag to find 572 * @return the matching {@link CrashTag} or null if no matches exist. 573 */ findCrashTag(List<CrashTag> crashTags, String level, String tag)574 private CrashTag findCrashTag(List<CrashTag> crashTags, String level, String tag) { 575 for (CrashTag t : crashTags) { 576 if (t.matches(level, tag)) { 577 return t; 578 } 579 } 580 return null; 581 } 582 583 /** 584 * Returns category for a given {@link CrashTag}. 585 * 586 * @param level level of the {@link CrashTag} 587 * @param tag tag of the {@link CrashTag} 588 * @return category of the {@link CrashTag}, matching search criteria. If nothing was found 589 * returns {@code JAVA_CRASH}. 590 */ getJavaCrashCategory(String level, String tag)591 private String getJavaCrashCategory(String level, String tag) { 592 CrashTag crashTag = findCrashTag(mJavaCrashTags, level, tag); 593 if (crashTag == null) { 594 return JAVA_CRASH; 595 } 596 return crashTag.getCategory(); 597 } 598 599 /** 600 * Class to encapsulate the tags that indicate which crashes should be parsed. 601 */ 602 private class CrashTag { 603 private String mLevel; 604 private String mTag; 605 private String mCategory; 606 CrashTag(String level, String tag, String category)607 public CrashTag(String level, String tag, String category) { 608 mLevel = level; 609 mTag = tag; 610 mCategory = category; 611 } 612 matches(String level, String tag)613 public boolean matches(String level, String tag) { 614 return mLevel.equals(level) && mTag.equals(tag); 615 } 616 getCategory()617 public String getCategory() { 618 return mCategory; 619 } 620 } 621 } 622